| Message ID | s5hio0nejv3.wl-tiwai@suse.de (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
On Tue, Mar 15, 2016 at 06:22:56PM +0100, Takashi Iwai wrote: > On Tue, 15 Mar 2016 17:02:07 +0100, > Ville Syrjälä wrote: > > > > We have a few new WARN spews from snd-hda causing some grief in i915 CI. > > > > This one happens on ILK and BYT. Looks like it happens 100% of the time on driver load: > > [ 18.809850] ------------[ cut here ]------------ > > [ 18.809866] WARNING: CPU: 0 PID: 39 at sound/hda/hdac_i915.c:129 pin2port+0x25/0x30 [snd_hda_core]() > > This is bad. Basically we had a naive assumption of the fixed mapping > between the port number and the HD-audio widget, but it doesn't apply > properly to pre-HSW models. > > The patch attached below disables the audio binding for pre-HSW > models. I'm going to queue to for-linus branch. That seems to eliminate the warn on my ILK. Tested-by: Ville Syrjälä <ville.syrjala@linux.intel.com> But now I got a lockdep spew when I enabled the HDMI video output [1] And sure enough mplayer got stuck in the kernel when I tried to use the HDMI audio device [2] [1] [ 1939.476458] ============================================= [ 1939.476460] [ INFO: possible recursive locking detected ] [ 1939.476463] 4.5.0-vga+ #13 Not tainted [ 1939.476464] --------------------------------------------- [ 1939.476466] kworker/2:2/1016 is trying to acquire lock: [ 1939.476469] (&spec->pcm_lock){+.+...}, at: [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] [ 1939.476480] but task is already holding lock: [ 1939.476482] (&spec->pcm_lock){+.+...}, at: [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] [ 1939.476489] other info that might help us debug this: [ 1939.476491] Possible unsafe locking scenario: [ 1939.476493] CPU0 [ 1939.476495] ---- [ 1939.476496] lock(&spec->pcm_lock); [ 1939.476499] lock(&spec->pcm_lock); [ 1939.476502] *** DEADLOCK *** [ 1939.476504] May be due to missing lock nesting notation [ 1939.476507] 3 locks held by kworker/2:2/1016: [ 1939.476509] #0: ("events"){.+.+.+}, at: [<ffffffff81093cc4>] process_one_work+0x154/0x6b0 [ 1939.476519] #1: ((&bus->unsol_work)){+.+...}, at: [<ffffffff81093cc4>] process_one_work+0x154/0x6b0 [ 1939.476525] #2: (&spec->pcm_lock){+.+...}, at: [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] [ 1939.476532] stack backtrace: [ 1939.476537] CPU: 2 PID: 1016 Comm: kworker/2:2 Not tainted 4.5.0-vga+ #13 [ 1939.476539] Hardware name: Dell Inc. Latitude E5410/03VXMC, BIOS A15 07/11/2013 [ 1939.476547] Workqueue: events process_unsol_events [snd_hda_core] [ 1939.476550] 0000000000000000 ffff8800d63a3960 ffffffff812f2265 ffffffff82370e80 [ 1939.476554] ffffffff82370e80 ffff8800d63a3a28 ffffffff810c1dc5 00000000d63a3990 [ 1939.476559] ffff88000001a6f8 ffff8800d6087400 00009b11dc5f82fc ffff88000001adf8 [ 1939.476564] Call Trace: [ 1939.476569] [<ffffffff812f2265>] dump_stack+0x67/0x92 [ 1939.476573] [<ffffffff810c1dc5>] __lock_acquire+0x1c25/0x1c80 [ 1939.476578] [<ffffffff8154435e>] ? mutex_unlock+0xe/0x10 [ 1939.476586] [<ffffffffa01a2fa6>] ? codec_exec_verb+0xa6/0xf0 [snd_hda_codec] [ 1939.476590] [<ffffffff810c26f6>] lock_acquire+0xb6/0x210 [ 1939.476594] [<ffffffffa020b868>] ? hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] [ 1939.476598] [<ffffffffa020b868>] ? hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] [ 1939.476601] [<ffffffff81542bf4>] mutex_lock_nested+0x54/0x3b0 [ 1939.476605] [<ffffffffa020b868>] ? hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] [ 1939.476608] [<ffffffff810bfe3f>] ? trace_hardirqs_on_caller+0x12f/0x1c0 [ 1939.476611] [<ffffffff810bd409>] ? __lock_is_held+0x49/0x70 [ 1939.476618] [<ffffffffa01a5640>] ? hda_call_codec_resume+0x110/0x110 [snd_hda_codec] [ 1939.476622] [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] [ 1939.476627] [<ffffffff810dc4e6>] ? rcu_read_lock_sched_held+0x86/0x90 [ 1939.476631] [<ffffffff813cef46>] ? regcache_sync+0x356/0x400 [ 1939.476638] [<ffffffffa01a5640>] ? hda_call_codec_resume+0x110/0x110 [snd_hda_codec] [ 1939.476642] [<ffffffffa020bd6d>] generic_hdmi_resume+0x4d/0x60 [snd_hda_codec_hdmi] [ 1939.476649] [<ffffffffa01a55ea>] hda_call_codec_resume+0xba/0x110 [snd_hda_codec] [ 1939.476656] [<ffffffffa01a5675>] hda_codec_runtime_resume+0x35/0x50 [snd_hda_codec] [ 1939.476660] [<ffffffff813bc992>] __rpm_callback+0x32/0x70 [ 1939.476667] [<ffffffffa01a5640>] ? hda_call_codec_resume+0x110/0x110 [snd_hda_codec] [ 1939.476670] [<ffffffff813bc9f4>] rpm_callback+0x24/0x80 [ 1939.476677] [<ffffffffa01a5640>] ? hda_call_codec_resume+0x110/0x110 [snd_hda_codec] [ 1939.476681] [<ffffffff813be125>] rpm_resume+0x455/0x820 [ 1939.476684] [<ffffffff813be530>] __pm_runtime_resume+0x40/0x60 [ 1939.476690] [<ffffffffa017de62>] snd_hdac_power_up_pm+0x52/0x60 [snd_hda_core] [ 1939.476694] [<ffffffffa020b9c3>] hdmi_present_sense+0x193/0x300 [snd_hda_codec_hdmi] [ 1939.476699] [<ffffffffa020bba0>] check_presence_and_report+0x70/0x90 [snd_hda_codec_hdmi] [ 1939.476703] [<ffffffffa020bcba>] hdmi_unsol_event+0x9a/0xb0 [snd_hda_codec_hdmi] [ 1939.476705] [<ffffffff810bd409>] ? __lock_is_held+0x49/0x70 [ 1939.476711] [<ffffffffa01a2077>] hda_codec_unsol_event+0x17/0x20 [snd_hda_codec] [ 1939.476716] [<ffffffffa017d178>] process_unsol_events+0x68/0x80 [snd_hda_core] [ 1939.476719] [<ffffffff81093d48>] process_one_work+0x1d8/0x6b0 [ 1939.476722] [<ffffffff81093cc4>] ? process_one_work+0x154/0x6b0 [ 1939.476725] [<ffffffff81094a4e>] worker_thread+0x4e/0x480 [ 1939.476728] [<ffffffff81094a00>] ? cancel_delayed_work_sync+0x20/0x20 [ 1939.476732] [<ffffffff8109a664>] kthread+0xe4/0x100 [ 1939.476736] [<ffffffff8109a580>] ? kthread_create_on_node+0x200/0x200 [ 1939.476740] [<ffffffff81546cbf>] ret_from_fork+0x3f/0x70 [ 1939.476743] [<ffffffff8109a580>] ? kthread_create_on_node+0x200/0x200 [2] [<ffffffff813bde90>] rpm_resume+0x1c0/0x820 [<ffffffff813be530>] __pm_runtime_resume+0x40/0x60 [<ffffffffa017db83>] snd_hdac_power_up+0x13/0x20 [snd_hda_core] [<ffffffffa01abf18>] azx_pcm_open+0x1f8/0x470 [snd_hda_codec] [<ffffffffa00fe17d>] snd_pcm_open_substream+0x4d/0xa0 [snd_pcm] [<ffffffffa00fe27f>] snd_pcm_open+0xaf/0x220 [snd_pcm] [<ffffffffa00fe4a4>] snd_pcm_playback_open+0x44/0x70 [snd_pcm] [<ffffffffa009e453>] snd_open+0xb3/0x180 [snd] [<ffffffff811b90ff>] chrdev_open+0x9f/0x1c0 [<ffffffff811b1e4f>] do_dentry_open+0x1cf/0x2f0 [<ffffffff811b31db>] vfs_open+0x5b/0x60 [<ffffffff811c39a3>] path_openat+0x1d3/0x1530 [<ffffffff811c5dae>] do_filp_open+0x7e/0xe0 [<ffffffff811b3516>] do_sys_open+0x116/0x1f0 [<ffffffff811b360e>] SyS_open+0x1e/0x20 [<ffffffff81546957>] entry_SYSCALL_64_fastpath+0x12/0x6f [<ffffffffffffffff>] 0xffffffffffffffff > > > This other one was seen at least on on SKL: > > [ 124.808525] ------------[ cut here ]------------ > > [ 124.808545] WARNING: CPU: 3 PID: 173 at sound/hda/hdac_i915.c:91 snd_hdac_display_power+0xf1/0x110 [snd_hda_core]() > > This is a different one, and it implies that the unbalanced power > refcount. Might be related with the recent fix for the recursive > regmap deadlock. I'll try later with a SKL machine here, too. > > Didn't you see this before the recent tree, right? Some good/bad > commits would be really helpful... > > > thanks, > > Takashi > > -- 8< -- > From: Takashi Iwai <tiwai@suse.de> > Subject: [PATCH] ALSA: hda - Limit i915 HDMI binding only for HSW and later > MIME-Version: 1.0 > > It turned out that the pre-HSW Intel chips are incompatible with the > naive assumption we had -- the fixed mapping between the port and the > HD-audio widget. This may result in the bad access, as captured by > the recent patch to add a WARN_ON() for the port mapping check. > > As a quick workaround, disable the i915 audio component binding for > all pre-Haswell models. > > Reported-by: Ville Syrjälä <ville.syrjala@linux.intel.com> > Cc: <stable@vger.kernel.org> # v4.5 > Signed-off-by: Takashi Iwai <tiwai@suse.de> > --- > sound/pci/hda/patch_hdmi.c | 5 +++-- > 1 file changed, 3 insertions(+), 2 deletions(-) > > diff --git a/sound/pci/hda/patch_hdmi.c b/sound/pci/hda/patch_hdmi.c > index 3fc259154c0b..cde9746cda8e 100644 > --- a/sound/pci/hda/patch_hdmi.c > +++ b/sound/pci/hda/patch_hdmi.c > @@ -2243,9 +2243,10 @@ static int patch_generic_hdmi(struct hda_codec *codec) > codec->spec = spec; > hdmi_array_init(spec, 4); > > - /* Try to bind with i915 for any Intel codecs (if not done yet) */ > + /* Try to bind with i915 for Intel HSW+ codecs (if not done yet) */ > if (!codec_has_acomp(codec) && > - (codec->core.vendor_id >> 16) == 0x8086) > + (codec->core.vendor_id >> 16) == 0x8086 && > + is_haswell_plus(codec)) > if (!snd_hdac_i915_init(&codec->bus->core)) > spec->i915_bound = true; > > -- > 2.7.3 >
On Wed, 16 Mar 2016 15:04:20 +0100, Ville Syrjälä wrote: > > On Tue, Mar 15, 2016 at 06:22:56PM +0100, Takashi Iwai wrote: > > On Tue, 15 Mar 2016 17:02:07 +0100, > > Ville Syrjälä wrote: > > > > > > We have a few new WARN spews from snd-hda causing some grief in i915 CI. > > > > > > This one happens on ILK and BYT. Looks like it happens 100% of the time on driver load: > > > [ 18.809850] ------------[ cut here ]------------ > > > [ 18.809866] WARNING: CPU: 0 PID: 39 at sound/hda/hdac_i915.c:129 pin2port+0x25/0x30 [snd_hda_core]() > > > > This is bad. Basically we had a naive assumption of the fixed mapping > > between the port number and the HD-audio widget, but it doesn't apply > > properly to pre-HSW models. > > > > The patch attached below disables the audio binding for pre-HSW > > models. I'm going to queue to for-linus branch. > > That seems to eliminate the warn on my ILK. > Tested-by: Ville Syrjälä <ville.syrjala@linux.intel.com> > > But now I got a lockdep spew when I enabled the HDMI video output [1] > > And sure enough mplayer got stuck in the kernel when I tried to use > the HDMI audio device [2] Gah, this must be the side-effect of the recent MST works. Good to catch it before merging to Linus tree. Libin, could you take a look at this quickly? thanks, Takashi > > [1] > [ 1939.476458] ============================================= > [ 1939.476460] [ INFO: possible recursive locking detected ] > [ 1939.476463] 4.5.0-vga+ #13 Not tainted > [ 1939.476464] --------------------------------------------- > [ 1939.476466] kworker/2:2/1016 is trying to acquire lock: > [ 1939.476469] (&spec->pcm_lock){+.+...}, at: [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] > [ 1939.476480] > but task is already holding lock: > [ 1939.476482] (&spec->pcm_lock){+.+...}, at: [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] > [ 1939.476489] > other info that might help us debug this: > [ 1939.476491] Possible unsafe locking scenario: > > [ 1939.476493] CPU0 > [ 1939.476495] ---- > [ 1939.476496] lock(&spec->pcm_lock); > [ 1939.476499] lock(&spec->pcm_lock); > [ 1939.476502] > *** DEADLOCK *** > > [ 1939.476504] May be due to missing lock nesting notation > > [ 1939.476507] 3 locks held by kworker/2:2/1016: > [ 1939.476509] #0: ("events"){.+.+.+}, at: [<ffffffff81093cc4>] process_one_work+0x154/0x6b0 > [ 1939.476519] #1: ((&bus->unsol_work)){+.+...}, at: [<ffffffff81093cc4>] process_one_work+0x154/0x6b0 > [ 1939.476525] #2: (&spec->pcm_lock){+.+...}, at: [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] > [ 1939.476532] > stack backtrace: > [ 1939.476537] CPU: 2 PID: 1016 Comm: kworker/2:2 Not tainted 4.5.0-vga+ #13 > [ 1939.476539] Hardware name: Dell Inc. Latitude E5410/03VXMC, BIOS A15 07/11/2013 > [ 1939.476547] Workqueue: events process_unsol_events [snd_hda_core] > [ 1939.476550] 0000000000000000 ffff8800d63a3960 ffffffff812f2265 ffffffff82370e80 > [ 1939.476554] ffffffff82370e80 ffff8800d63a3a28 ffffffff810c1dc5 00000000d63a3990 > [ 1939.476559] ffff88000001a6f8 ffff8800d6087400 00009b11dc5f82fc ffff88000001adf8 > [ 1939.476564] Call Trace: > [ 1939.476569] [<ffffffff812f2265>] dump_stack+0x67/0x92 > [ 1939.476573] [<ffffffff810c1dc5>] __lock_acquire+0x1c25/0x1c80 > [ 1939.476578] [<ffffffff8154435e>] ? mutex_unlock+0xe/0x10 > [ 1939.476586] [<ffffffffa01a2fa6>] ? codec_exec_verb+0xa6/0xf0 [snd_hda_codec] > [ 1939.476590] [<ffffffff810c26f6>] lock_acquire+0xb6/0x210 > [ 1939.476594] [<ffffffffa020b868>] ? hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] > [ 1939.476598] [<ffffffffa020b868>] ? hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] > [ 1939.476601] [<ffffffff81542bf4>] mutex_lock_nested+0x54/0x3b0 > [ 1939.476605] [<ffffffffa020b868>] ? hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] > [ 1939.476608] [<ffffffff810bfe3f>] ? trace_hardirqs_on_caller+0x12f/0x1c0 > [ 1939.476611] [<ffffffff810bd409>] ? __lock_is_held+0x49/0x70 > [ 1939.476618] [<ffffffffa01a5640>] ? hda_call_codec_resume+0x110/0x110 [snd_hda_codec] > [ 1939.476622] [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] > [ 1939.476627] [<ffffffff810dc4e6>] ? rcu_read_lock_sched_held+0x86/0x90 > [ 1939.476631] [<ffffffff813cef46>] ? regcache_sync+0x356/0x400 > [ 1939.476638] [<ffffffffa01a5640>] ? hda_call_codec_resume+0x110/0x110 [snd_hda_codec] > [ 1939.476642] [<ffffffffa020bd6d>] generic_hdmi_resume+0x4d/0x60 [snd_hda_codec_hdmi] > [ 1939.476649] [<ffffffffa01a55ea>] hda_call_codec_resume+0xba/0x110 [snd_hda_codec] > [ 1939.476656] [<ffffffffa01a5675>] hda_codec_runtime_resume+0x35/0x50 [snd_hda_codec] > [ 1939.476660] [<ffffffff813bc992>] __rpm_callback+0x32/0x70 > [ 1939.476667] [<ffffffffa01a5640>] ? hda_call_codec_resume+0x110/0x110 [snd_hda_codec] > [ 1939.476670] [<ffffffff813bc9f4>] rpm_callback+0x24/0x80 > [ 1939.476677] [<ffffffffa01a5640>] ? hda_call_codec_resume+0x110/0x110 [snd_hda_codec] > [ 1939.476681] [<ffffffff813be125>] rpm_resume+0x455/0x820 > [ 1939.476684] [<ffffffff813be530>] __pm_runtime_resume+0x40/0x60 > [ 1939.476690] [<ffffffffa017de62>] snd_hdac_power_up_pm+0x52/0x60 [snd_hda_core] > [ 1939.476694] [<ffffffffa020b9c3>] hdmi_present_sense+0x193/0x300 [snd_hda_codec_hdmi] > [ 1939.476699] [<ffffffffa020bba0>] check_presence_and_report+0x70/0x90 [snd_hda_codec_hdmi] > [ 1939.476703] [<ffffffffa020bcba>] hdmi_unsol_event+0x9a/0xb0 [snd_hda_codec_hdmi] > [ 1939.476705] [<ffffffff810bd409>] ? __lock_is_held+0x49/0x70 > [ 1939.476711] [<ffffffffa01a2077>] hda_codec_unsol_event+0x17/0x20 [snd_hda_codec] > [ 1939.476716] [<ffffffffa017d178>] process_unsol_events+0x68/0x80 [snd_hda_core] > [ 1939.476719] [<ffffffff81093d48>] process_one_work+0x1d8/0x6b0 > [ 1939.476722] [<ffffffff81093cc4>] ? process_one_work+0x154/0x6b0 > [ 1939.476725] [<ffffffff81094a4e>] worker_thread+0x4e/0x480 > [ 1939.476728] [<ffffffff81094a00>] ? cancel_delayed_work_sync+0x20/0x20 > [ 1939.476732] [<ffffffff8109a664>] kthread+0xe4/0x100 > [ 1939.476736] [<ffffffff8109a580>] ? kthread_create_on_node+0x200/0x200 > [ 1939.476740] [<ffffffff81546cbf>] ret_from_fork+0x3f/0x70 > [ 1939.476743] [<ffffffff8109a580>] ? kthread_create_on_node+0x200/0x200 > > [2] > [<ffffffff813bde90>] rpm_resume+0x1c0/0x820 > [<ffffffff813be530>] __pm_runtime_resume+0x40/0x60 > [<ffffffffa017db83>] snd_hdac_power_up+0x13/0x20 [snd_hda_core] > [<ffffffffa01abf18>] azx_pcm_open+0x1f8/0x470 [snd_hda_codec] > [<ffffffffa00fe17d>] snd_pcm_open_substream+0x4d/0xa0 [snd_pcm] > [<ffffffffa00fe27f>] snd_pcm_open+0xaf/0x220 [snd_pcm] > [<ffffffffa00fe4a4>] snd_pcm_playback_open+0x44/0x70 [snd_pcm] > [<ffffffffa009e453>] snd_open+0xb3/0x180 [snd] > [<ffffffff811b90ff>] chrdev_open+0x9f/0x1c0 > [<ffffffff811b1e4f>] do_dentry_open+0x1cf/0x2f0 > [<ffffffff811b31db>] vfs_open+0x5b/0x60 > [<ffffffff811c39a3>] path_openat+0x1d3/0x1530 > [<ffffffff811c5dae>] do_filp_open+0x7e/0xe0 > [<ffffffff811b3516>] do_sys_open+0x116/0x1f0 > [<ffffffff811b360e>] SyS_open+0x1e/0x20 > [<ffffffff81546957>] entry_SYSCALL_64_fastpath+0x12/0x6f > [<ffffffffffffffff>] 0xffffffffffffffff > > > > > > This other one was seen at least on on SKL: > > > [ 124.808525] ------------[ cut here ]------------ > > > [ 124.808545] WARNING: CPU: 3 PID: 173 at sound/hda/hdac_i915.c:91 snd_hdac_display_power+0xf1/0x110 [snd_hda_core]() > > > > This is a different one, and it implies that the unbalanced power > > refcount. Might be related with the recent fix for the recursive > > regmap deadlock. I'll try later with a SKL machine here, too. > > > > Didn't you see this before the recent tree, right? Some good/bad > > commits would be really helpful... > > > > > > thanks, > > > > Takashi > > > > -- 8< -- > > From: Takashi Iwai <tiwai@suse.de> > > Subject: [PATCH] ALSA: hda - Limit i915 HDMI binding only for HSW and later > > MIME-Version: 1.0 > > > > It turned out that the pre-HSW Intel chips are incompatible with the > > naive assumption we had -- the fixed mapping between the port and the > > HD-audio widget. This may result in the bad access, as captured by > > the recent patch to add a WARN_ON() for the port mapping check. > > > > As a quick workaround, disable the i915 audio component binding for > > all pre-Haswell models. > > > > Reported-by: Ville Syrjälä <ville.syrjala@linux.intel.com> > > Cc: <stable@vger.kernel.org> # v4.5 > > Signed-off-by: Takashi Iwai <tiwai@suse.de> > > --- > > sound/pci/hda/patch_hdmi.c | 5 +++-- > > 1 file changed, 3 insertions(+), 2 deletions(-) > > > > diff --git a/sound/pci/hda/patch_hdmi.c b/sound/pci/hda/patch_hdmi.c > > index 3fc259154c0b..cde9746cda8e 100644 > > --- a/sound/pci/hda/patch_hdmi.c > > +++ b/sound/pci/hda/patch_hdmi.c > > @@ -2243,9 +2243,10 @@ static int patch_generic_hdmi(struct hda_codec *codec) > > codec->spec = spec; > > hdmi_array_init(spec, 4); > > > > - /* Try to bind with i915 for any Intel codecs (if not done yet) */ > > + /* Try to bind with i915 for Intel HSW+ codecs (if not done yet) */ > > if (!codec_has_acomp(codec) && > > - (codec->core.vendor_id >> 16) == 0x8086) > > + (codec->core.vendor_id >> 16) == 0x8086 && > > + is_haswell_plus(codec)) > > if (!snd_hdac_i915_init(&codec->bus->core)) > > spec->i915_bound = true; > > > > -- > > 2.7.3 > > > > -- > Ville Syrjälä > Intel OTC >
Hi Takashi, On 03/16/2016 10:07 PM, Takashi Iwai wrote: > On Wed, 16 Mar 2016 15:04:20 +0100, > Ville Syrjälä wrote: >> >> On Tue, Mar 15, 2016 at 06:22:56PM +0100, Takashi Iwai wrote: >>> On Tue, 15 Mar 2016 17:02:07 +0100, >>> Ville Syrjälä wrote: >>>> >>>> We have a few new WARN spews from snd-hda causing some grief in i915 CI. >>>> >>>> This one happens on ILK and BYT. Looks like it happens 100% of the time on driver load: >>>> [ 18.809850] ------------[ cut here ]------------ >>>> [ 18.809866] WARNING: CPU: 0 PID: 39 at sound/hda/hdac_i915.c:129 pin2port+0x25/0x30 [snd_hda_core]() >>> >>> This is bad. Basically we had a naive assumption of the fixed mapping >>> between the port number and the HD-audio widget, but it doesn't apply >>> properly to pre-HSW models. >>> >>> The patch attached below disables the audio binding for pre-HSW >>> models. I'm going to queue to for-linus branch. >> >> That seems to eliminate the warn on my ILK. >> Tested-by: Ville Syrjälä <ville.syrjala@linux.intel.com> >> >> But now I got a lockdep spew when I enabled the HDMI video output [1] >> >> And sure enough mplayer got stuck in the kernel when I tried to use >> the HDMI audio device [2] > > Gah, this must be the side-effect of the recent MST works. > Good to catch it before merging to Linus tree. > > Libin, could you take a look at this quickly? Sure. I will work on it. Regards, Libin > > > thanks, > > Takashi > >> >> [1] >> [ 1939.476458] ============================================= >> [ 1939.476460] [ INFO: possible recursive locking detected ] >> [ 1939.476463] 4.5.0-vga+ #13 Not tainted >> [ 1939.476464] --------------------------------------------- >> [ 1939.476466] kworker/2:2/1016 is trying to acquire lock: >> [ 1939.476469] (&spec->pcm_lock){+.+...}, at: [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] >> [ 1939.476480] >> but task is already holding lock: >> [ 1939.476482] (&spec->pcm_lock){+.+...}, at: [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] >> [ 1939.476489] >> other info that might help us debug this: >> [ 1939.476491] Possible unsafe locking scenario: >> >> [ 1939.476493] CPU0 >> [ 1939.476495] ---- >> [ 1939.476496] lock(&spec->pcm_lock); >> [ 1939.476499] lock(&spec->pcm_lock); >> [ 1939.476502] >> *** DEADLOCK *** >> >> [ 1939.476504] May be due to missing lock nesting notation >> >> [ 1939.476507] 3 locks held by kworker/2:2/1016: >> [ 1939.476509] #0: ("events"){.+.+.+}, at: [<ffffffff81093cc4>] process_one_work+0x154/0x6b0 >> [ 1939.476519] #1: ((&bus->unsol_work)){+.+...}, at: [<ffffffff81093cc4>] process_one_work+0x154/0x6b0 >> [ 1939.476525] #2: (&spec->pcm_lock){+.+...}, at: [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] >> [ 1939.476532] >> stack backtrace: >> [ 1939.476537] CPU: 2 PID: 1016 Comm: kworker/2:2 Not tainted 4.5.0-vga+ #13 >> [ 1939.476539] Hardware name: Dell Inc. Latitude E5410/03VXMC, BIOS A15 07/11/2013 >> [ 1939.476547] Workqueue: events process_unsol_events [snd_hda_core] >> [ 1939.476550] 0000000000000000 ffff8800d63a3960 ffffffff812f2265 ffffffff82370e80 >> [ 1939.476554] ffffffff82370e80 ffff8800d63a3a28 ffffffff810c1dc5 00000000d63a3990 >> [ 1939.476559] ffff88000001a6f8 ffff8800d6087400 00009b11dc5f82fc ffff88000001adf8 >> [ 1939.476564] Call Trace: >> [ 1939.476569] [<ffffffff812f2265>] dump_stack+0x67/0x92 >> [ 1939.476573] [<ffffffff810c1dc5>] __lock_acquire+0x1c25/0x1c80 >> [ 1939.476578] [<ffffffff8154435e>] ? mutex_unlock+0xe/0x10 >> [ 1939.476586] [<ffffffffa01a2fa6>] ? codec_exec_verb+0xa6/0xf0 [snd_hda_codec] >> [ 1939.476590] [<ffffffff810c26f6>] lock_acquire+0xb6/0x210 >> [ 1939.476594] [<ffffffffa020b868>] ? hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] >> [ 1939.476598] [<ffffffffa020b868>] ? hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] >> [ 1939.476601] [<ffffffff81542bf4>] mutex_lock_nested+0x54/0x3b0 >> [ 1939.476605] [<ffffffffa020b868>] ? hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] >> [ 1939.476608] [<ffffffff810bfe3f>] ? trace_hardirqs_on_caller+0x12f/0x1c0 >> [ 1939.476611] [<ffffffff810bd409>] ? __lock_is_held+0x49/0x70 >> [ 1939.476618] [<ffffffffa01a5640>] ? hda_call_codec_resume+0x110/0x110 [snd_hda_codec] >> [ 1939.476622] [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] >> [ 1939.476627] [<ffffffff810dc4e6>] ? rcu_read_lock_sched_held+0x86/0x90 >> [ 1939.476631] [<ffffffff813cef46>] ? regcache_sync+0x356/0x400 >> [ 1939.476638] [<ffffffffa01a5640>] ? hda_call_codec_resume+0x110/0x110 [snd_hda_codec] >> [ 1939.476642] [<ffffffffa020bd6d>] generic_hdmi_resume+0x4d/0x60 [snd_hda_codec_hdmi] >> [ 1939.476649] [<ffffffffa01a55ea>] hda_call_codec_resume+0xba/0x110 [snd_hda_codec] >> [ 1939.476656] [<ffffffffa01a5675>] hda_codec_runtime_resume+0x35/0x50 [snd_hda_codec] >> [ 1939.476660] [<ffffffff813bc992>] __rpm_callback+0x32/0x70 >> [ 1939.476667] [<ffffffffa01a5640>] ? hda_call_codec_resume+0x110/0x110 [snd_hda_codec] >> [ 1939.476670] [<ffffffff813bc9f4>] rpm_callback+0x24/0x80 >> [ 1939.476677] [<ffffffffa01a5640>] ? hda_call_codec_resume+0x110/0x110 [snd_hda_codec] >> [ 1939.476681] [<ffffffff813be125>] rpm_resume+0x455/0x820 >> [ 1939.476684] [<ffffffff813be530>] __pm_runtime_resume+0x40/0x60 >> [ 1939.476690] [<ffffffffa017de62>] snd_hdac_power_up_pm+0x52/0x60 [snd_hda_core] >> [ 1939.476694] [<ffffffffa020b9c3>] hdmi_present_sense+0x193/0x300 [snd_hda_codec_hdmi] >> [ 1939.476699] [<ffffffffa020bba0>] check_presence_and_report+0x70/0x90 [snd_hda_codec_hdmi] >> [ 1939.476703] [<ffffffffa020bcba>] hdmi_unsol_event+0x9a/0xb0 [snd_hda_codec_hdmi] >> [ 1939.476705] [<ffffffff810bd409>] ? __lock_is_held+0x49/0x70 >> [ 1939.476711] [<ffffffffa01a2077>] hda_codec_unsol_event+0x17/0x20 [snd_hda_codec] >> [ 1939.476716] [<ffffffffa017d178>] process_unsol_events+0x68/0x80 [snd_hda_core] >> [ 1939.476719] [<ffffffff81093d48>] process_one_work+0x1d8/0x6b0 >> [ 1939.476722] [<ffffffff81093cc4>] ? process_one_work+0x154/0x6b0 >> [ 1939.476725] [<ffffffff81094a4e>] worker_thread+0x4e/0x480 >> [ 1939.476728] [<ffffffff81094a00>] ? cancel_delayed_work_sync+0x20/0x20 >> [ 1939.476732] [<ffffffff8109a664>] kthread+0xe4/0x100 >> [ 1939.476736] [<ffffffff8109a580>] ? kthread_create_on_node+0x200/0x200 >> [ 1939.476740] [<ffffffff81546cbf>] ret_from_fork+0x3f/0x70 >> [ 1939.476743] [<ffffffff8109a580>] ? kthread_create_on_node+0x200/0x200 >> >> [2] >> [<ffffffff813bde90>] rpm_resume+0x1c0/0x820 >> [<ffffffff813be530>] __pm_runtime_resume+0x40/0x60 >> [<ffffffffa017db83>] snd_hdac_power_up+0x13/0x20 [snd_hda_core] >> [<ffffffffa01abf18>] azx_pcm_open+0x1f8/0x470 [snd_hda_codec] >> [<ffffffffa00fe17d>] snd_pcm_open_substream+0x4d/0xa0 [snd_pcm] >> [<ffffffffa00fe27f>] snd_pcm_open+0xaf/0x220 [snd_pcm] >> [<ffffffffa00fe4a4>] snd_pcm_playback_open+0x44/0x70 [snd_pcm] >> [<ffffffffa009e453>] snd_open+0xb3/0x180 [snd] >> [<ffffffff811b90ff>] chrdev_open+0x9f/0x1c0 >> [<ffffffff811b1e4f>] do_dentry_open+0x1cf/0x2f0 >> [<ffffffff811b31db>] vfs_open+0x5b/0x60 >> [<ffffffff811c39a3>] path_openat+0x1d3/0x1530 >> [<ffffffff811c5dae>] do_filp_open+0x7e/0xe0 >> [<ffffffff811b3516>] do_sys_open+0x116/0x1f0 >> [<ffffffff811b360e>] SyS_open+0x1e/0x20 >> [<ffffffff81546957>] entry_SYSCALL_64_fastpath+0x12/0x6f >> [<ffffffffffffffff>] 0xffffffffffffffff >> >>> >>>> This other one was seen at least on on SKL: >>>> [ 124.808525] ------------[ cut here ]------------ >>>> [ 124.808545] WARNING: CPU: 3 PID: 173 at sound/hda/hdac_i915.c:91 snd_hdac_display_power+0xf1/0x110 [snd_hda_core]() >>> >>> This is a different one, and it implies that the unbalanced power >>> refcount. Might be related with the recent fix for the recursive >>> regmap deadlock. I'll try later with a SKL machine here, too. >>> >>> Didn't you see this before the recent tree, right? Some good/bad >>> commits would be really helpful... >>> >>> >>> thanks, >>> >>> Takashi >>> >>> -- 8< -- >>> From: Takashi Iwai <tiwai@suse.de> >>> Subject: [PATCH] ALSA: hda - Limit i915 HDMI binding only for HSW and later >>> MIME-Version: 1.0 >>> >>> It turned out that the pre-HSW Intel chips are incompatible with the >>> naive assumption we had -- the fixed mapping between the port and the >>> HD-audio widget. This may result in the bad access, as captured by >>> the recent patch to add a WARN_ON() for the port mapping check. >>> >>> As a quick workaround, disable the i915 audio component binding for >>> all pre-Haswell models. >>> >>> Reported-by: Ville Syrjälä <ville.syrjala@linux.intel.com> >>> Cc: <stable@vger.kernel.org> # v4.5 >>> Signed-off-by: Takashi Iwai <tiwai@suse.de> >>> --- >>> sound/pci/hda/patch_hdmi.c | 5 +++-- >>> 1 file changed, 3 insertions(+), 2 deletions(-) >>> >>> diff --git a/sound/pci/hda/patch_hdmi.c b/sound/pci/hda/patch_hdmi.c >>> index 3fc259154c0b..cde9746cda8e 100644 >>> --- a/sound/pci/hda/patch_hdmi.c >>> +++ b/sound/pci/hda/patch_hdmi.c >>> @@ -2243,9 +2243,10 @@ static int patch_generic_hdmi(struct hda_codec *codec) >>> codec->spec = spec; >>> hdmi_array_init(spec, 4); >>> >>> - /* Try to bind with i915 for any Intel codecs (if not done yet) */ >>> + /* Try to bind with i915 for Intel HSW+ codecs (if not done yet) */ >>> if (!codec_has_acomp(codec) && >>> - (codec->core.vendor_id >> 16) == 0x8086) >>> + (codec->core.vendor_id >> 16) == 0x8086 && >>> + is_haswell_plus(codec)) >>> if (!snd_hdac_i915_init(&codec->bus->core)) >>> spec->i915_bound = true; >>> >>> -- >>> 2.7.3 >>> >> >> -- >> Ville Syrjälä >> Intel OTC >>
On Wed, 16 Mar 2016 15:04:20 +0100, Ville Syrjälä wrote: > > But now I got a lockdep spew when I enabled the HDMI video output [1] > > And sure enough mplayer got stuck in the kernel when I tried to use > the HDMI audio device [2] > > [1] > [ 1939.476458] ============================================= > [ 1939.476460] [ INFO: possible recursive locking detected ] > [ 1939.476463] 4.5.0-vga+ #13 Not tainted > [ 1939.476464] --------------------------------------------- > [ 1939.476466] kworker/2:2/1016 is trying to acquire lock: > [ 1939.476469] (&spec->pcm_lock){+.+...}, at: [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] > [ 1939.476480] > but task is already holding lock: > [ 1939.476482] (&spec->pcm_lock){+.+...}, at: [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] > [ 1939.476489] > other info that might help us debug this: > [ 1939.476491] Possible unsafe locking scenario: > > [ 1939.476493] CPU0 > [ 1939.476495] ---- > [ 1939.476496] lock(&spec->pcm_lock); > [ 1939.476499] lock(&spec->pcm_lock); > [ 1939.476502] > *** DEADLOCK *** > > [ 1939.476504] May be due to missing lock nesting notation Unfortunately, no this is a real deadlock. Let's see below: hdmi_present_sense() gets called twice because the function issues a verb that does self-resume and it invokes hdmi_present_sense() again in runtime resume. > [ 1939.476622] [<ffffffffa020b868>] hdmi_present_sense+0x38/0x300 [snd_hda_codec_hdmi] .... > [ 1939.476642] [<ffffffffa020bd6d>] generic_hdmi_resume+0x4d/0x60 [snd_hda_codec_hdmi] .... > [ 1939.476690] [<ffffffffa017de62>] snd_hdac_power_up_pm+0x52/0x60 [snd_hda_core] > [ 1939.476694] [<ffffffffa020b9c3>] hdmi_present_sense+0x193/0x300 [snd_hda_codec_hdmi] > [ 1939.476699] [<ffffffffa020bba0>] check_presence_and_report+0x70/0x90 [snd_hda_codec_hdmi] > [ 1939.476703] [<ffffffffa020bcba>] hdmi_unsol_event+0x9a/0xb0 [snd_hda_codec_hdmi] This wasn't seen until now because the code path using i915 audio notifier doesn't need to power up the codec. Now we switched to the old method for old chips, and the bug is revealed. It's good to have caught it now, because basically this hits all non-Intel chips. Takashi
On Wed, Mar 16, 2016 at 04:04:20PM +0200, Ville Syrjälä wrote: > On Tue, Mar 15, 2016 at 06:22:56PM +0100, Takashi Iwai wrote: > > On Tue, 15 Mar 2016 17:02:07 +0100, > > Ville Syrjälä wrote: > > > > > > We have a few new WARN spews from snd-hda causing some grief in i915 CI. > > > > > > This one happens on ILK and BYT. Looks like it happens 100% of the time on driver load: > > > [ 18.809850] ------------[ cut here ]------------ > > > [ 18.809866] WARNING: CPU: 0 PID: 39 at sound/hda/hdac_i915.c:129 pin2port+0x25/0x30 [snd_hda_core]() > > > > This is bad. Basically we had a naive assumption of the fixed mapping > > between the port number and the HD-audio widget, but it doesn't apply > > properly to pre-HSW models. > > > > The patch attached below disables the audio binding for pre-HSW > > models. I'm going to queue to for-linus branch. > > That seems to eliminate the warn on my ILK. Apparently it was less effective on BYT. We still get this: [ 14.978872] ------------[ cut here ]------------ [ 14.978890] WARNING: CPU: 1 PID: 288 at sound/hda/hdac_i915.c:129 pin2port+0x25/0x30 [snd_hda_core]() [ 14.978894] Modules linked in: snd_hda_codec_hdmi(+) snd_hda_codec_realtek snd_hda_codec_generic i915 snd_hda_intel snd_hda_codec intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hwdep snd_hda_core snd_pcm lpc_ich i2c_hid i2c_designware_platform i2c_designware_core r8169 mii sdhci_acpi sdhci mmc_core [ 14.978934] CPU: 1 PID: 288 Comm: modprobe Not tainted 4.5.0-gfxbench+ #1 [ 14.978938] Hardware name: \xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff \xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff/DN2820FYK, BIOS FYBYT10H.86A.0038.2014.0717.1455 07/17/2014 [ 14.978941] 0000000000000000 ffff8800732d3a48 ffffffff813fef15 0000000000000000 [ 14.978948] ffffffffa014077c ffff8800732d3a80 ffffffff81078a21 ffff880073201b90 [ 14.978954] ffff880073006878 ffff880073006880 0000000000000100 ffff880073006878 [ 14.978961] Call Trace: [ 14.978969] [<ffffffff813fef15>] dump_stack+0x67/0x92 [ 14.978976] [<ffffffff81078a21>] warn_slowpath_common+0x81/0xc0 [ 14.978980] [<ffffffff81078b15>] warn_slowpath_null+0x15/0x20 [ 14.978988] [<ffffffffa013f2d5>] pin2port+0x25/0x30 [snd_hda_core] [ 14.978997] [<ffffffffa013f378>] snd_hdac_acomp_get_eld+0x38/0x70 [snd_hda_core] [ 14.979009] [<ffffffffa0050a69>] hdmi_present_sense+0xa9/0x3a0 [snd_hda_codec_hdmi] [ 14.979016] [<ffffffffa005112f>] generic_hdmi_build_controls+0x11f/0x200 [snd_hda_codec_hdmi] [ 14.979029] [<ffffffffa018e5b1>] snd_hda_codec_build_controls+0x191/0x1d0 [snd_hda_codec] [ 14.979039] [<ffffffffa018e881>] ? snd_hda_codec_build_pcms+0xe1/0x1a0 [snd_hda_codec] [ 14.979049] [<ffffffffa0189442>] hda_codec_driver_probe+0x82/0x100 [snd_hda_codec] [ 14.979056] [<ffffffff8153d9b9>] driver_probe_device+0x229/0x450 [ 14.979061] [<ffffffff8153dc63>] __driver_attach+0x83/0x90 [ 14.979066] [<ffffffff8153dbe0>] ? driver_probe_device+0x450/0x450 [ 14.979070] [<ffffffff8153b691>] bus_for_each_dev+0x61/0xa0 [ 14.979074] [<ffffffff8153d2a9>] driver_attach+0x19/0x20 [ 14.979078] [<ffffffff8153cd8f>] bus_add_driver+0x1ef/0x290 [ 14.979083] [<ffffffffa0059000>] ? 0xffffffffa0059000 [ 14.979087] [<ffffffff8153e98b>] driver_register+0x5b/0xe0 [ 14.979096] [<ffffffffa01890d5>] __hda_codec_driver_register+0x55/0x60 [snd_hda_codec] [ 14.979103] [<ffffffffa005901e>] hdmi_driver_init+0x1e/0x20 [snd_hda_codec_hdmi] [ 14.979110] [<ffffffff810003de>] do_one_initcall+0xae/0x1d0 [ 14.979115] [<ffffffff810e1091>] ? rcu_read_lock_sched_held+0x81/0x90 [ 14.979121] [<ffffffff811b8863>] ? kmem_cache_alloc_trace+0x293/0x300 [ 14.979126] [<ffffffff8115b3dc>] ? do_init_module+0x22/0x1c6 [ 14.979131] [<ffffffff8115b415>] do_init_module+0x5b/0x1c6 [ 14.979136] [<ffffffff81107d3a>] load_module+0x1c0a/0x24b0 [ 14.979142] [<ffffffff81105410>] ? symbol_put_addr+0x60/0x60 [ 14.979147] [<ffffffff81105706>] ? copy_module_from_fd.isra.63+0xe6/0x140 [ 14.979152] [<ffffffff811087ce>] SyS_finit_module+0x7e/0xa0 [ 14.979160] [<ffffffff817c5f5b>] entry_SYSCALL_64_fastpath+0x16/0x73 [ 14.979271] ---[ end trace 639ed871547f2d0f ]--- <snip> > > > > -- 8< -- > > From: Takashi Iwai <tiwai@suse.de> > > Subject: [PATCH] ALSA: hda - Limit i915 HDMI binding only for HSW and later > > MIME-Version: 1.0 > > > > It turned out that the pre-HSW Intel chips are incompatible with the > > naive assumption we had -- the fixed mapping between the port and the > > HD-audio widget. This may result in the bad access, as captured by > > the recent patch to add a WARN_ON() for the port mapping check. > > > > As a quick workaround, disable the i915 audio component binding for > > all pre-Haswell models. > > > > Reported-by: Ville Syrjälä <ville.syrjala@linux.intel.com> > > Cc: <stable@vger.kernel.org> # v4.5 > > Signed-off-by: Takashi Iwai <tiwai@suse.de> > > --- > > sound/pci/hda/patch_hdmi.c | 5 +++-- > > 1 file changed, 3 insertions(+), 2 deletions(-) > > > > diff --git a/sound/pci/hda/patch_hdmi.c b/sound/pci/hda/patch_hdmi.c > > index 3fc259154c0b..cde9746cda8e 100644 > > --- a/sound/pci/hda/patch_hdmi.c > > +++ b/sound/pci/hda/patch_hdmi.c > > @@ -2243,9 +2243,10 @@ static int patch_generic_hdmi(struct hda_codec *codec) > > codec->spec = spec; > > hdmi_array_init(spec, 4); > > > > - /* Try to bind with i915 for any Intel codecs (if not done yet) */ > > + /* Try to bind with i915 for Intel HSW+ codecs (if not done yet) */ > > if (!codec_has_acomp(codec) && > > - (codec->core.vendor_id >> 16) == 0x8086) > > + (codec->core.vendor_id >> 16) == 0x8086 && > > + is_haswell_plus(codec)) > > if (!snd_hdac_i915_init(&codec->bus->core)) > > spec->i915_bound = true; > > > > -- > > 2.7.3 > > > > -- > Ville Syrjälä > Intel OTC
diff --git a/sound/pci/hda/patch_hdmi.c b/sound/pci/hda/patch_hdmi.c index 3fc259154c0b..cde9746cda8e 100644 --- a/sound/pci/hda/patch_hdmi.c +++ b/sound/pci/hda/patch_hdmi.c @@ -2243,9 +2243,10 @@ static int patch_generic_hdmi(struct hda_codec *codec) codec->spec = spec; hdmi_array_init(spec, 4); - /* Try to bind with i915 for any Intel codecs (if not done yet) */ + /* Try to bind with i915 for Intel HSW+ codecs (if not done yet) */ if (!codec_has_acomp(codec) && - (codec->core.vendor_id >> 16) == 0x8086) + (codec->core.vendor_id >> 16) == 0x8086 && + is_haswell_plus(codec)) if (!snd_hdac_i915_init(&codec->bus->core)) spec->i915_bound = true;