Seen twice with 4 runs in between, then nothing since CI_DRM_4182_full (1 month / 583 runs ago). Closing now!

Closing, thanks.

And it's back! 

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4545/shard-glk6/igt@drv_module_reload@basic-reload-inject.html

[ 1908.592041] WARNING: CPU: 0 PID: 25958 at sound/hda/hdac_i915.c:92 snd_hdac_display_power+0xdc/0x100 [snd_hda_core]
[ 1908.592064] Modules linked in: vgem snd_hda_intel i915 btusb btrtl btbcm btintel x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul bluetooth ghash_clmulni_intel snd_hda_codec_hdmi ecdh_generic snd_hda_codec_realtek snd_hda_codec_generic r8169 mii i2c_hid snd_hda_codec snd_hwdep snd_hda_core snd_pcm mei_me pinctrl_geminilake mei pinctrl_intel prime_numbers [last unloaded: test_drm_mm]
[ 1908.592154] CPU: 0 PID: 25958 Comm: drv_module_relo Tainted: G     U  W         4.18.0-rc4-CI-CI_DRM_4463+ #1
[ 1908.592170] Hardware name: Intel Corporation NUC7CJYH/NUC7JYB, BIOS JYGLKCPX.86A.0027.2018.0125.1347 01/25/2018
[ 1908.592189] RIP: 0010:snd_hdac_display_power+0xdc/0x100 [snd_hda_core]
[ 1908.592200] Code: 00 48 8b 40 08 e8 54 3e bb e1 be 01 00 00 00 48 89 df e8 a7 fe ff ff 31 f6 48 89 df e8 9d fe ff ff 5b 89 e8 5d 41 5c 41 5d c3 <0f> 0b c7 83 58 05 00 00 ff ff ff ff eb e9 bd ed ff ff ff eb e2 0f 
[ 1908.592293] RSP: 0018:ffffc90000453c68 EFLAGS: 00010246
[ 1908.592304] RAX: 00000000ffffffff RBX: ffff880463c9a2a8 RCX: dead000000000200
[ 1908.592315] RDX: ffff88045c347778 RSI: 0000000000000000 RDI: ffff880463c9a2a8
[ 1908.592327] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
[ 1908.592338] R10: ffffc900004539f0 R11: ffffffff822463e0 R12: 0000000000000000
[ 1908.592349] R13: ffff88045c346198 R14: 0000000000000060 R15: ffff880466948d68
[ 1908.592361] FS:  00007f61a9dd3980(0000) GS:ffff88047fc00000(0000) knlGS:0000000000000000
[ 1908.592374] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1908.592384] CR2: 00007f4c85619cb0 CR3: 000000045af9a000 CR4: 0000000000340ef0
[ 1908.592395] Call Trace:
[ 1908.592411]  snd_hda_codec_dev_free+0x1e/0x30 [snd_hda_codec]
[ 1908.592427]  __snd_device_free+0x4c/0x80
[ 1908.592436]  snd_device_free_all+0x36/0x80
[ 1908.592447]  release_card_device+0x14/0x70
[ 1908.592458]  device_release+0x2b/0x80
[ 1908.592468]  kobject_put+0x85/0x1a0
[ 1908.592477]  snd_card_free+0x60/0x90
[ 1908.592490]  pci_device_remove+0x36/0xb0
[ 1908.592500]  device_release_driver_internal+0x185/0x250
[ 1908.592511]  unbind_store+0xaf/0x180
[ 1908.592522]  kernfs_fop_write+0x104/0x190
[ 1908.592534]  __vfs_write+0x31/0x180
[ 1908.592545]  ? rcu_sync_lockdep_assert+0x9/0x50
[ 1908.592554]  ? __sb_start_write+0x152/0x1f0
[ 1908.592563]  ? __sb_start_write+0x168/0x1f0
[ 1908.592573]  vfs_write+0xbd/0x1a0
[ 1908.592582]  ksys_write+0x50/0xc0
[ 1908.592592]  do_syscall_64+0x55/0x190
[ 1908.592603]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 1908.592613] RIP: 0033:0x7f61a9768281
[ 1908.592619] Code: c3 0f 1f 84 00 00 00 00 00 48 8b 05 59 8d 20 00 c3 0f 1f 84 00 00 00 00 00 8b 05 8a d1 20 00 85 c0 75 16 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 57 f3 c3 0f 1f 44 00 00 41 54 55 49 89 d4 53 
[ 1908.592713] RSP: 002b:00007ffcba509ed8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[ 1908.592726] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f61a9768281
[ 1908.592738] RDX: 000000000000000c RSI: 000055c1c48ec5cb RDI: 0000000000000003
[ 1908.592749] RBP: 00007ffcba50afc0 R08: 000055c1c48ec5cb R09: 000000000000000c
[ 1908.592760] R10: 00000000fffffff4 R11: 0000000000000246 R12: 000055c1c2b2d2f0
[ 1908.592772] R13: 00007ffcba50b180 R14: 0000000000000000 R15: 0000000000000000
[ 1908.592788] irq event stamp: 0
[ 1908.592795] hardirqs last  enabled at (0): [<0000000000000000>]           (null)
[ 1908.592809] hardirqs last disabled at (0): [<ffffffff810821f2>] copy_process.part.7+0x322/0x1db0
[ 1908.592824] softirqs last  enabled at (0): [<ffffffff810821f2>] copy_process.part.7+0x322/0x1db0
[ 1908.592837] softirqs last disabled at (0): [<0000000000000000>]           (null)
[ 1908.592854] WARNING: CPU: 0 PID: 25958 at sound/hda/hdac_i915.c:92 snd_hdac_display_power+0xdc/0x100 [snd_hda_core]
[ 1908.592869] ---[ end trace 6a4649e26d94cfa2 ]---
[ 1908.602549] WARNING: CPU: 0 PID: 25958 at sound/hda/hdac_i915.c:429 snd_hdac_i915_exit+0x54/0x80 [snd_hda_core]
[ 1908.602571] Modules linked in: vgem snd_hda_intel i915 btusb btrtl btbcm btintel x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul bluetooth ghash_clmulni_intel snd_hda_codec_hdmi ecdh_generic snd_hda_codec_realtek snd_hda_codec_generic r8169 mii i2c_hid snd_hda_codec snd_hwdep snd_hda_core snd_pcm mei_me pinctrl_geminilake mei pinctrl_intel prime_numbers [last unloaded: test_drm_mm]
[ 1908.602662] CPU: 0 PID: 25958 Comm: drv_module_relo Tainted: G     U  W         4.18.0-rc4-CI-CI_DRM_4463+ #1
[ 1908.602677] Hardware name: Intel Corporation NUC7CJYH/NUC7JYB, BIOS JYGLKCPX.86A.0027.2018.0125.1347 01/25/2018
[ 1908.602697] RIP: 0010:snd_hdac_i915_exit+0x54/0x80 [snd_hda_core]
[ 1908.602707] Code: e8 91 6e 5d e1 48 89 ef e8 c9 c0 1a e1 48 c7 83 50 05 00 00 00 00 00 00 48 c7 05 93 9b 00 00 00 00 00 00 5b 31 c0 5d 41 5c c3 <0f> 0b 85 c0 7e c6 48 8b 45 20 48 85 c0 74 bd 48 8b 40 10 48 8b 7d 
[ 1908.602799] RSP: 0018:ffffc90000453c68 EFLAGS: 00010286
[ 1908.602810] RAX: 00000000ffffffff RBX: ffff880463c9a2a8 RCX: 00000000ffffffe6
[ 1908.602821] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffff880463c9a2a8
[ 1908.602832] RBP: ffff88045c346198 R08: 0000000000000000 R09: 0000000000000000
[ 1908.602844] R10: 0000000000000000 R11: ffffffff837482c0 R12: ffff88046ce22348
[ 1908.602855] R13: ffff880463c9e7e8 R14: 0000000000000060 R15: ffff880466948d68
[ 1908.602867] FS:  00007f61a9dd3980(0000) GS:ffff88047fc00000(0000) knlGS:0000000000000000
[ 1908.602880] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1908.602890] CR2: 000055ab55e5a35f CR3: 000000045af9a000 CR4: 0000000000340ef0
[ 1908.602901] Call Trace:
[ 1908.602912]  azx_free+0x100/0x170 [snd_hda_intel]
[ 1908.602926]  __snd_device_free+0x4c/0x80
[ 1908.602935]  snd_device_free_all+0x5a/0x80
[ 1908.602946]  release_card_device+0x14/0x70
[ 1908.602956]  device_release+0x2b/0x80
[ 1908.602967]  kobject_put+0x85/0x1a0
[ 1908.602976]  snd_card_free+0x60/0x90
[ 1908.602988]  pci_device_remove+0x36/0xb0
[ 1908.602999]  device_release_driver_internal+0x185/0x250
[ 1908.603010]  unbind_store+0xaf/0x180
[ 1908.603021]  kernfs_fop_write+0x104/0x190
[ 1908.603032]  __vfs_write+0x31/0x180
[ 1908.603043]  ? rcu_sync_lockdep_assert+0x9/0x50
[ 1908.603053]  ? __sb_start_write+0x152/0x1f0
[ 1908.603062]  ? __sb_start_write+0x168/0x1f0
[ 1908.603071]  vfs_write+0xbd/0x1a0
[ 1908.603080]  ksys_write+0x50/0xc0
[ 1908.603091]  do_syscall_64+0x55/0x190
[ 1908.603101]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 1908.603110] RIP: 0033:0x7f61a9768281
[ 1908.603117] Code: c3 0f 1f 84 00 00 00 00 00 48 8b 05 59 8d 20 00 c3 0f 1f 84 00 00 00 00 00 8b 05 8a d1 20 00 85 c0 75 16 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 57 f3 c3 0f 1f 44 00 00 41 54 55 49 89 d4 53 
[ 1908.603210] RSP: 002b:00007ffcba509ed8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[ 1908.603224] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f61a9768281
[ 1908.603235] RDX: 000000000000000c RSI: 000055c1c48ec5cb RDI: 0000000000000003
[ 1908.603247] RBP: 00007ffcba50afc0 R08: 000055c1c48ec5cb R09: 000000000000000c
[ 1908.603258] R10: 00000000fffffff4 R11: 0000000000000246 R12: 000055c1c2b2d2f0
[ 1908.603269] R13: 00007ffcba50b180 R14: 0000000000000000 R15: 0000000000000000
[ 1908.603285] irq event stamp: 0
[ 1908.603293] hardirqs last  enabled at (0): [<0000000000000000>]           (null)
[ 1908.603307] hardirqs last disabled at (0): [<ffffffff810821f2>] copy_process.part.7+0x322/0x1db0
[ 1908.603321] softirqs last  enabled at (0): [<ffffffff810821f2>] copy_process.part.7+0x322/0x1db0
[ 1908.603335] softirqs last disabled at (0): [<0000000000000000>]           (null)
[ 1908.603351] WARNING: CPU: 0 PID: 25958 at sound/hda/hdac_i915.c:429 snd_hdac_i915_exit+0x54/0x80 [snd_hda_core]
[ 1908.603367] ---[ end trace 6a4649e26d94cfa3 ]---

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4640/shard-glk1/igt@pm_rpm@dpms-non-lpsp.html

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4640/shard-glk1/igt@pm_rpm@gem-evict-pwrite.html

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4640/shard-glk1/igt@perf_pmu@rc6-runtime-pm-long.html

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4640/shard-glk1/igt@pm_rpm@gem-pread.html

[  912.357709] WARNING: CPU: 0 PID: 6649 at sound/hda/hdac_component.c:85 snd_hdac_display_power+0xe6/0x100 [snd_hda_core]
[  912.357724] Modules linked in: vgem snd_hda_intel i915 snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic btusb btrtl btbcm x86_pkg_temp_thermal coretemp btintel crct10dif_pclmul crc32_pclmul ghash_clmulni_intel bluetooth ecdh_generic i2c_hid snd_hda_codec snd_hwdep snd_hda_core snd_pcm pinctrl_geminilake pinctrl_intel r8169 mei_me mei prime_numbers [last unloaded: test_drm_mm]
[  912.357830] CPU: 0 PID: 6649 Comm: kworker/0:0 Tainted: G     U  W         4.19.0-rc3-CI-CI_DRM_4807+ #1
[  912.357837] Hardware name: Intel Corporation NUC7CJYH/NUC7JYB, BIOS JYGLKCPX.86A.0027.2018.0125.1347 01/25/2018
[  912.357851] Workqueue: pm pm_runtime_work
[  912.357872] RIP: 0010:snd_hdac_display_power+0xe6/0x100 [snd_hda_core]
[  912.357881] Code: 09 49 8b 7d 00 e8 0a 33 b4 e1 be 01 00 00 00 48 89 df e8 ad fe ff ff 31 f6 48 89 df e8 a3 fe ff ff 5b 89 e8 5d 41 5c 41 5d c3 <0f> 0b c7 83 58 05 00 00 ff ff ff ff eb e9 bd ed ff ff ff eb e2 0f
[  912.357888] RSP: 0018:ffffc9000038bd10 EFLAGS: 00010246
[  912.357898] RAX: 00000000ffffffff RBX: ffff88026cf01158 RCX: ffffc9000059c000
[  912.357904] RDX: ffff88026cf011b8 RSI: 0000000000000000 RDI: ffff88026cf01158
[  912.357911] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
[  912.357917] R10: ffffc9000038bc40 R11: ffff880277e21598 R12: 0000000000000000
[  912.357924] R13: ffff8802653d2da0 R14: ffffffff815072e0 R15: ffff880275dd2350
[  912.357931] FS:  0000000000000000(0000) GS:ffff880277e00000(0000) knlGS:0000000000000000
[  912.357938] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  912.357945] CR2: 00007ff50cb2a210 CR3: 0000000005210000 CR4: 0000000000340ef0
[  912.357951] Call Trace:
[  912.357971]  ? pci_azx_readl+0x10/0x10 [snd_hda_intel]
[  912.357982]  azx_runtime_resume+0x1e7/0x240 [snd_hda_intel]
[  912.357998]  pci_pm_runtime_resume+0x73/0xa0
[  912.358009]  __rpm_callback+0xb3/0x1b0
[  912.358021]  rpm_callback+0x1a/0x70
[  912.358031]  ? pci_restore_standard_config+0x40/0x40
[  912.358040]  rpm_resume+0x533/0x830
[  912.358056]  pm_runtime_work+0x5a/0xb0
[  912.358069]  process_one_work+0x245/0x610
[  912.358087]  worker_thread+0x37/0x380
[  912.358099]  ? process_one_work+0x610/0x610
[  912.358108]  kthread+0x119/0x130
[  912.358117]  ? kthread_park+0x80/0x80
[  912.358131]  ret_from_fork+0x24/0x50
[  912.358152] irq event stamp: 0
[  912.358160] hardirqs last  enabled at (0): [<0000000000000000>]           (null)
[  912.358169] hardirqs last disabled at (0): [<ffffffff81081f59>] copy_process.part.6+0x409/0x2010
[  912.358177] softirqs last  enabled at (0): [<ffffffff81081f59>] copy_process.part.6+0x409/0x2010
[  912.358184] softirqs last disabled at (0): [<0000000000000000>]           (null)
[  912.358200] WARNING: CPU: 0 PID: 6649 at sound/hda/hdac_component.c:85 snd_hdac_display_power+0xe6/0x100 [snd_hda_core]
[  912.358207] ---[ end trace 4d4018d143c2f333 ]---

Looks like a refcounting bug in the HDA driver:
WARN_ON(!bus->drm_power_refcount);

Takashi, is there a bugzilla for the HDA driver we could we move this ticket to?

(In reply to Imre Deak from comment #5)
> Looks like a refcounting bug in the HDA driver:
> WARN_ON(!bus->drm_power_refcount);

Hm, the device free gets called during it being suspended.
A shot in the dark:

--- a/sound/pci/hda/hda_codec.c
+++ b/sound/pci/hda/hda_codec.c
@@ -834,7 +834,8 @@ static int snd_hda_codec_dev_free(struct snd_device *device)
 
        codec->in_freeing = 1;
        snd_hdac_device_unregister(&codec->core);
-       snd_hdac_link_power(&codec->core, false);
+       if (pm_runtime_active(hda_codec_dev(codec)))
+               snd_hdac_link_power(&codec->core, false);
        put_device(hda_codec_dev(codec));
        return 0;
 }


> Takashi, is there a bugzilla for the HDA driver we could we move this ticket
> to?

Feel free to move to bugzilla.kernel.org.  Thanks.

(In reply to Takashi Iwai from comment #6)
> (In reply to Imre Deak from comment #5)
> > Looks like a refcounting bug in the HDA driver:
> > WARN_ON(!bus->drm_power_refcount);
> 
> Hm, the device free gets called during it being suspended.
> A shot in the dark:
> 
> --- a/sound/pci/hda/hda_codec.c
> +++ b/sound/pci/hda/hda_codec.c
> @@ -834,7 +834,8 @@ static int snd_hda_codec_dev_free(struct snd_device
> *device)
>  
>         codec->in_freeing = 1;
>         snd_hdac_device_unregister(&codec->core);
> -       snd_hdac_link_power(&codec->core, false);
> +       if (pm_runtime_active(hda_codec_dev(codec)))
> +               snd_hdac_link_power(&codec->core, false);
>         put_device(hda_codec_dev(codec));
>         return 0;
>  }
> 
> 
> > Takashi, is there a bugzilla for the HDA driver we could we move this ticket
> > to?
> 
> Feel free to move to bugzilla.kernel.org.  Thanks.

Sorry for the delay, too many bugs to track...

Has a bug on bugzilla.kernel.org been written or a patch been made for this issue?

It seems to happen every 1.5 months. Last time it was seen was 1.5 months ago, so I guess we'll soon see if progress has been made!

(In reply to Martin Peres from comment #7)
> Has a bug on bugzilla.kernel.org been written or a patch been made for this
> issue?

Nothing I know of, so far.

> It seems to happen every 1.5 months. Last time it was seen was 1.5 months
> ago, so I guess we'll soon see if progress has been made!

Heh, 6 times per year isn't a bad bet :)

Also seen on BSW, https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5259/fi-bsw-cyan/igt@i915_selftest@live_sanitycheck.html

<4> [478.306426] WARNING: CPU: 3 PID: 3838 at sound/hda/hdac_component.c:85 snd_hdac_display_power+0xe6/0x100 [snd_hda_core]
<4> [478.306488] Modules linked in: snd_hda_intel i915 amdgpu chash gpu_sched ttm vgem snd_hda_codec_hdmi coretemp crct10dif_pclmul btusb crc32_pclmul btrtl btbcm btintel ghash_clmulni_intel cdc_ether usbnet bluetooth r8152 mii ecdh_generic snd_hda_codec snd_hwdep snd_hda_core snd_pcm pinctrl_cherryview lpc_ich prime_numbers [last unloaded: i915]
<4> [478.306538] CPU: 3 PID: 3838 Comm: i915_selftest Tainted: G     U            4.20.0-rc5-CI-CI_DRM_5259+ #1
<4> [478.306544] Hardware name: GOOGLE Cyan/Cyan, BIOS MrChromebox 02/15/2018
<4> [478.306557] RIP: 0010:snd_hdac_display_power+0xe6/0x100 [snd_hda_core]
<4> [478.306564] Code: 09 49 8b 7d 00 e8 2a ca b7 e1 be 01 00 00 00 48 89 df e8 ad fe ff ff 31 f6 48 89 df e8 a3 fe ff ff 5b 89 e8 5d 41 5c 41 5d c3 <0f> 0b c7 83 58 05 00 00 ff ff ff ff eb e9 bd ed ff ff ff eb e2 0f
<4> [478.306570] RSP: 0018:ffffc900005d3c68 EFLAGS: 00010246
<4> [478.306578] RAX: 00000000ffffffff RBX: ffff888076b91158 RCX: 0000000000000000
<4> [478.306584] RDX: 0000000000000006 RSI: 0000000000000000 RDI: ffff888076b91158
<4> [478.306589] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
<4> [478.306594] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
<4> [478.306600] R13: ffff8880744afcd0 R14: 0000000000000060 R15: ffff888075e1a7e8
<4> [478.306607] FS:  00007fd2e27f9980(0000) GS:ffff888079980000(0000) knlGS:0000000000000000
<4> [478.306612] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4> [478.306618] CR2: 00007f33b20ecd29 CR3: 00000000620ee000 CR4: 00000000001006e0
<4> [478.306623] Call Trace:
<4> [478.306652]  snd_hda_codec_dev_free+0x1e/0x30 [snd_hda_codec]
<4> [478.306666]  __snd_device_free+0x4c/0x80
<4> [478.306674]  snd_device_free_all+0x36/0x80
<4> [478.306688]  release_card_device+0x14/0x70
<4> [478.306699]  device_release+0x2b/0x80
<4> [478.306711]  kobject_put+0x85/0x1a0
<4> [478.306722]  snd_card_free+0x60/0x90
<4> [478.306745]  pci_device_remove+0x36/0xb0
<4> [478.306757]  device_release_driver_internal+0x185/0x240
<4> [478.306771]  unbind_store+0xaf/0x180
<4> [478.306784]  kernfs_fop_write+0x104/0x190
<4> [478.306799]  __vfs_write+0x31/0x180
<4> [478.306812]  ? rcu_read_lock_sched_held+0x6f/0x80
<4> [478.306819]  ? rcu_sync_lockdep_assert+0x29/0x50
<4> [478.306827]  ? __sb_start_write+0x152/0x1f0
<4> [478.306833]  ? __sb_start_write+0x163/0x1f0
<4> [478.306846]  vfs_write+0xbd/0x1b0
<4> [478.306858]  ksys_write+0x50/0xc0
<4> [478.306873]  do_syscall_64+0x55/0x190
<4> [478.306884]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [478.306891] RIP: 0033:0x7fd2e20b6154
<4> [478.306898] Code: 89 02 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 8d 05 b1 07 2e 00 8b 00 85 c0 75 13 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 54 f3 c3 66 90 41 54 55 49 89 d4 53 48 89 f5
<4> [478.306904] RSP: 002b:00007fffc158d408 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
<4> [478.306911] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fd2e20b6154
<4> [478.306917] RDX: 000000000000000c RSI: 000055fa56a0532b RDI: 0000000000000005
<4> [478.306922] RBP: 00007fffc158e4f0 R08: 0000000000000000 R09: 0000000000000000
<4> [478.306928] R10: 00007fd2e2112560 R11: 0000000000000246 R12: 000055fa5560b750
<4> [478.306933] R13: 00007fffc158e7d0 R14: 0000000000000000 R15: 0000000000000000
<4> [478.306961] irq event stamp: 76936
<4> [478.306971] hardirqs last  enabled at (76935): [<ffffffff810a59fb>] __flush_work+0x2bb/0x310
<4> [478.306977] hardirqs last disabled at (76936): [<ffffffff810019b0>] trace_hardirqs_off_thunk+0x1a/0x1c
<4> [478.306986] softirqs last  enabled at (76898): [<ffffffff817fab8c>] peernet2id+0x4c/0x70
<4> [478.306992] softirqs last disabled at (76896): [<ffffffff817fab6d>] peernet2id+0x2d/0x70
<4> [478.307006] WARNING: CPU: 3 PID: 3838 at sound/hda/hdac_component.c:85 snd_hdac_display_power+0xe6/0x100 [snd_hda_core]
<4> [478.307012] ---[ end trace 086147dd2631bdcd ]---
<4> [478.340648] WARNING: CPU: 3 PID: 3838 at sound/hda/hdac_component.c:324 snd_hdac_acomp_exit+0x53/0x70 [snd_hda_core]
<4> [478.340658] Modules linked in: snd_hda_intel i915 amdgpu chash gpu_sched ttm vgem snd_hda_codec_hdmi coretemp crct10dif_pclmul btusb crc32_pclmul btrtl btbcm btintel ghash_clmulni_intel cdc_ether usbnet bluetooth r8152 mii ecdh_generic snd_hda_codec snd_hwdep snd_hda_core snd_pcm pinctrl_cherryview lpc_ich prime_numbers [last unloaded: i915]
<4> [478.340707] CPU: 3 PID: 3838 Comm: i915_selftest Tainted: G     U  W         4.20.0-rc5-CI-CI_DRM_5259+ #1
<4> [478.340713] Hardware name: GOOGLE Cyan/Cyan, BIOS MrChromebox 02/15/2018
<4> [478.340725] RIP: 0010:snd_hdac_acomp_exit+0x53/0x70 [snd_hda_core]
<4> [478.340732] Code: d3 c6 5a e1 48 c7 83 50 05 00 00 00 00 00 00 48 89 ef 31 c9 31 d2 48 c7 c6 60 4a 08 a0 e8 b5 73 5b e1 31 c0 5b 5d c3 31 c0 c3 <0f> 0b 85 d2 7e c5 48 8b 50 08 48 85 d2 74 bc 48 8b 52 10 48 8b 38
<4> [478.340738] RSP: 0018:ffffc900005d3c70 EFLAGS: 00010286
<4> [478.340745] RAX: ffff8880744afcd0 RBX: ffff888076b91158 RCX: a77cd00700000000
<4> [478.340751] RDX: 00000000ffffffff RSI: 000000007aabcc49 RDI: ffff888076b91158
<4> [478.340756] RBP: ffff888078055748 R08: 00000000ccaf10e7 R09: 0000000000000001
<4> [478.340762] R10: 0000000000000000 R11: ffffffff82233340 R12: ffff888075e52448
<4> [478.340768] R13: ffff888075e522a8 R14: 0000000000000060 R15: ffff888075e1a7e8
<4> [478.340774] FS:  00007fd2e27f9980(0000) GS:ffff888079980000(0000) knlGS:0000000000000000
<4> [478.340779] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4> [478.340785] CR2: 00007f33b20ecd29 CR3: 00000000620ee000 CR4: 00000000001006e0
<4> [478.340790] Call Trace:
<4> [478.340807]  azx_free+0x107/0x180 [snd_hda_intel]
<4> [478.340820]  __snd_device_free+0x4c/0x80
<4> [478.340828]  snd_device_free_all+0x5a/0x80
<4> [478.340841]  release_card_device+0x14/0x70
<4> [478.340851]  device_release+0x2b/0x80
<4> [478.340864]  kobject_put+0x85/0x1a0
<4> [478.340874]  snd_card_free+0x60/0x90
<4> [478.340897]  pci_device_remove+0x36/0xb0
<4> [478.340908]  device_release_driver_internal+0x185/0x240
<4> [478.340921]  unbind_store+0xaf/0x180
<4> [478.340934]  kernfs_fop_write+0x104/0x190
<4> [478.340949]  __vfs_write+0x31/0x180
<4> [478.340963]  ? rcu_read_lock_sched_held+0x6f/0x80
<4> [478.340969]  ? rcu_sync_lockdep_assert+0x29/0x50
<4> [478.340978]  ? __sb_start_write+0x152/0x1f0
<4> [478.340984]  ? __sb_start_write+0x163/0x1f0
<4> [478.340997]  vfs_write+0xbd/0x1b0
<4> [478.341009]  ksys_write+0x50/0xc0
<4> [478.341024]  do_syscall_64+0x55/0x190
<4> [478.341035]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4> [478.341042] RIP: 0033:0x7fd2e20b6154
<4> [478.341049] Code: 89 02 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 8d 05 b1 07 2e 00 8b 00 85 c0 75 13 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 54 f3 c3 66 90 41 54 55 49 89 d4 53 48 89 f5
<4> [478.341054] RSP: 002b:00007fffc158d408 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
<4> [478.341062] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fd2e20b6154
<4> [478.341067] RDX: 000000000000000c RSI: 000055fa56a0532b RDI: 0000000000000005
<4> [478.341073] RBP: 00007fffc158e4f0 R08: 0000000000000000 R09: 0000000000000000
<4> [478.341078] R10: 00007fd2e2112560 R11: 0000000000000246 R12: 000055fa5560b750
<4> [478.341083] R13: 00007fffc158e7d0 R14: 0000000000000000 R15: 0000000000000000
<4> [478.341111] irq event stamp: 89460
<4> [478.341119] hardirqs last  enabled at (89459): [<ffffffff81200088>] __slab_free+0x3e8/0x510
<4> [478.341126] hardirqs last disabled at (89460): [<ffffffff810019b0>] trace_hardirqs_off_thunk+0x1a/0x1c
<4> [478.341133] softirqs last  enabled at (89074): [<ffffffff81c0033a>] __do_softirq+0x33a/0x4b9
<4> [478.341141] softirqs last disabled at (89067): [<ffffffff8108e6a9>] irq_exit+0xa9/0xc0
<4> [478.341153] WARNING: CPU: 3 PID: 3838 at sound/hda/hdac_component.c:324 snd_hdac_acomp_exit+0x53/0x70 [snd_hda_core]
<4> [478.341159] ---[ end trace 086147dd2631bdce ]---

(In reply to Takashi Iwai from comment #8)
> (In reply to Martin Peres from comment #7)
> > Has a bug on bugzilla.kernel.org been written or a patch been made for this
> > issue?
> 
> Nothing I know of, so far.

ok, thanks! We'll do so :)

> 
> > It seems to happen every 1.5 months. Last time it was seen was 1.5 months
> > ago, so I guess we'll soon see if progress has been made!
> 
> Heh, 6 times per year isn't a bad bet :)

New statistics is indeed once every 2 months... It isn't too bad, but that probably means we should write tests to better catch these sorts of issues.

If all goes well, we should soon reach the point where audio would become the next obvious thing to improve testing for anyway, so let's see what we can do :)

Is the fix mentioned in comment 6 applied to the test tree?

If it's not included, I'll apply it to for-next branch of sound git tree.
It's no urgent bug to be fixed in for-linus branch, as it seems.

(In reply to Takashi Iwai from comment #10)
> Is the fix mentioned in comment 6 applied to the test tree?
> 
> If it's not included, I'll apply it to for-next branch of sound git tree.
> It's no urgent bug to be fixed in for-linus branch, as it seems.
Scratch this, it turned out to be incorrect.

I worked on refactoring / fixes of the whole display PM in the HD-audio side and submitted the fix patchset.  It'll be included in for-next branch later, targeted for 4.21.

This has been seen once every 215 runs in average, now not seen for 3030 runs. Closing!

The CI Bug Log issue associated to this bug has been archived.

New failures matching the above filters will not be associated to this bug anymore.