search

thesofproject / linux

Linux kernel source tree
Other
91 stars 134 forks source link

[BUG][CML]There are some WARNING after sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding iDisp1 during system boot up #1587

Closed YvonneYang2 closed 4 years ago

YvonneYang2 commented 4 years ago

Describe the bug There are some warning after sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding iDisp1 during system boot up.

To Reproduce

  1. Run with command "./test-reboot.sh 500", then check the logs in folder named reboot-logs

script: test-reboot.sh.txt

Reproduced rate Run 500 times,failed 1 times.

Expected result System boot up without error

Dmesg ```` [ 4.068028] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding SDW0-Capture [ 4.068040] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding SDW1-Playback [ 4.068044] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4f29 <= 0081 [ 4.068047] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding SDW3-Capture [ 4.068054] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding iDisp1 [ 4.068058] ------------[ cut here ]------------ [ 4.068062] WARNING: CPU: 1 PID: 833 at kernel/workqueue.c:3031 __flush_work+0x18b/0x1a0 [ 4.068062] Modules linked in: snd_soc_sdw_rt711_rt1308_rt715(+) snd_soc_hdac_hdmi snd_soc_rt711 snd_soc_rt700 snd_soc_rt715 snd_soc_rt1308_sdw regmap_sdw snd_soc_dmic snd_sof_pci snd_sof_intel_hda_common snd_soc_hdac_hda soundwire_intel_init soundwire_intel soundwire_generic_allocation soundwire_cadence snd_sof_intel_hda snd_sof_intel_byt snd_soc_acpi_intel_match snd_sof_intel_ipc snd_sof snd_sof_xtensa_dsp snd_soc_acpi snd_hda_ext_core soundwire_bus snd_soc_core snd_intel_dspcfg snd_hda_codec snd_hwdep snd_hda_core snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device snd_timer snd asix usbnet x86_pkg_temp_thermal soundcore intel_powerclamp processor_thermal_device intel_soc_dts_iosf mei_me intel_lpss_pci mei intel_lpss mfd_core int3403_thermal int3400_thermal int340x_thermal_zone acpi_thermal_rel efivarfs i915 i2c_algo_bit drm_kms_helper syscopyarea sysfillrect xhci_pci sysimgblt fb_sys_fops xhci_hcd drm [ 4.068080] CPU: 1 PID: 833 Comm: systemd-udevd Tainted: G W 5.4.0-rc8-sdw-validation-20191127-0-d6078f9 #rc8 [ 4.068081] Hardware name: Dell Inc. Latitude 9510/, BIOS 0.1.3 10/01/2019 [ 4.068083] RIP: 0010:__flush_work+0x18b/0x1a0 [ 4.068084] Code: 5b 8d 8d 00 b8 01 00 00 00 e9 0a ff ff ff 8b 4d 00 48 8b 55 08 83 e1 08 48 0f ba 6d 00 03 80 c9 f0 eb c6 0f 0b e9 ee fe ff ff <0f> 0b 31 c0 e9 e5 fe ff ff e8 a7 30 fe ff 0f 1f 80 00 00 00 00 31 [ 4.068085] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 3501 <= 0003 [ 4.068086] RSP: 0018:ffffa866c0cbb9a8 EFLAGS: 00010246 [ 4.068087] RAX: 0000000000000000 RBX: ffff98e65f827028 RCX: 0000000000000000 [ 4.068088] intel-sdw sdw-master-3: sdw_handle_slave_status: Updating Slave 1 status done [ 4.068089] intel-sdw sdw-master-3: sdw_handle_slave_status: end [ 4.068090] RDX: 0000000000000001 RSI: 0000000000000000 RDI: ffff98e65f827640 [ 4.068091] RBP: ffff98e65f827640 R08: 0000000000000565 R09: 0000000000000004 [ 4.068093] R10: ffffa866c0cbb9d0 R11: 0000000000000001 R12: ffffffffc05bc0c0 [ 4.068093] R13: ffffffffc05bbbd8 R14: ffff98e65f825eb8 R15: 0000000000000003 [ 4.068094] FS: 00007f58737e7680(0000) GS:ffff98e664240000(0000) knlGS:0000000000000000 [ 4.068095] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 4.068096] CR2: 000055f1c2a53c40 CR3: 000000028af8c002 CR4: 00000000003606e0 [ 4.068096] Call Trace: [ 4.068101] ? try_to_del_timer_sync+0x48/0x70 [ 4.068105] soc_free_pcm_runtime.part.41+0x3b/0x50 [snd_soc_core] [ 4.068106] intel-sdw sdw-master-3: Slave status change [ 4.068110] soc_cleanup_card_resources+0x181/0x2d0 [snd_soc_core] [ 4.068113] snd_soc_bind_card+0x1e0/0xb20 [snd_soc_core] [ 4.068114] intel-sdw sdw-master-3: sdw_handle_slave_status: start [ 4.068117] ? devm_snd_soc_register_card+0x2e/0x80 [snd_soc_core] [ 4.068119] ? devm_snd_soc_register_card+0x80/0x80 [snd_soc_core] [ 4.068122] devm_snd_soc_register_card+0x3e/0x80 [snd_soc_core] [ 4.068125] mc_probe+0x18b/0x240 [snd_soc_sdw_rt711_rt1308_rt715] [ 4.068128] platform_drv_probe+0x32/0x90 [ 4.068130] really_probe+0xea/0x420 [ 4.068132] driver_probe_device+0x10b/0x120 [ 4.068133] device_driver_attach+0x4a/0x50 [ 4.068135] __driver_attach+0x95/0x130 [ 4.068136] ? device_driver_attach+0x50/0x50 [ 4.068137] bus_for_each_dev+0x71/0xb0 [ 4.068138] bus_add_driver+0x13f/0x210 [ 4.068140] ? 0xffffffffc0181000 [ 4.068141] driver_register+0x56/0xf0 [ 4.068142] ? 0xffffffffc0181000 [ 4.068143] do_one_initcall+0x41/0x1df [ 4.068146] ? _cond_resched+0x10/0x40 [ 4.068147] ? kmem_cache_alloc_trace+0x36/0x1b0 [ 4.068149] do_init_module+0x56/0x1f4 [ 4.068151] load_module+0x22d6/0x27c0 [ 4.068154] ? vfs_read+0x10e/0x130 [ 4.068156] ? __do_sys_finit_module+0xe9/0x110 [ 4.068157] __do_sys_finit_module+0xe9/0x110 [ 4.068159] do_syscall_64+0x43/0x120 [ 4.068160] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 4.068162] RIP: 0033:0x7f5873303839 [ 4.068163] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 1f f6 2c 00 f7 d8 64 89 01 48 [ 4.068164] RSP: 002b:00007fffd816d358 EFLAGS: 00000246 ORIG_RAX: 0000000000000139 [ 4.068165] RAX: ffffffffffffffda RBX: 000055f1c2a2f200 RCX: 00007f5873303839 [ 4.068165] RDX: 0000000000000000 RSI: 00007f5872fe20e5 RDI: 000000000000000f [ 4.068166] RBP: 00007f5872fe20e5 R08: 0000000000000000 R09: 00007fffd816d470 [ 4.068167] R10: 000000000000000f R11: 0000000000000246 R12: 0000000000000000 [ 4.068168] rt711 sdw:0:25d:711:0: [rt711_sdw_write] 7520 85a0 7420 84a0 <= 006b 5064 [ 4.068168] R13: 000055f1c2a2ce70 R14: 0000000000020000 R15: 000055f1c2a2f200 [ 4.068170] ---[ end trace b037ada1d7b7cf24 ]--- [ 4.068182] ------------[ cut here ]------------ [ 4.068184] WARNING: CPU: 1 PID: 833 at kernel/workqueue.c:3031 __flush_work+0x18b/0x1a0 [ 4.068184] Modules linked in: snd_soc_sdw_rt711_rt1308_rt715(+) snd_soc_hdac_hdmi snd_soc_rt711 snd_soc_rt700 snd_soc_rt715 snd_soc_rt1308_sdw regmap_sdw snd_soc_dmic snd_sof_pci snd_sof_intel_hda_common snd_soc_hdac_hda soundwire_intel_init soundwire_intel soundwire_generic_allocation soundwire_cadence snd_sof_intel_hda snd_sof_intel_byt snd_soc_acpi_intel_match snd_sof_intel_ipc snd_sof snd_sof_xtensa_dsp snd_soc_acpi snd_hda_ext_core soundwire_bus snd_soc_core snd_intel_dspcfg snd_hda_codec snd_hwdep snd_hda_core snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device snd_timer snd asix usbnet x86_pkg_temp_thermal soundcore intel_powerclamp processor_thermal_device intel_soc_dts_iosf mei_me intel_lpss_pci mei intel_lpss mfd_core int3403_thermal int3400_thermal int340x_thermal_zone acpi_thermal_rel efivarfs i915 i2c_algo_bit drm_kms_helper syscopyarea sysfillrect xhci_pci sysimgblt fb_sys_fops xhci_hcd drm [ 4.068198] CPU: 1 PID: 833 Comm: systemd-udevd Tainted: G W 5.4.0-rc8-sdw-validation-20191127-0-d6078f9 #rc8 [ 4.068199] Hardware name: Dell Inc. Latitude 9510/, BIOS 0.1.3 10/01/2019 [ 4.068200] RIP: 0010:__flush_work+0x18b/0x1a0 [ 4.068201] Code: 5b 8d 8d 00 b8 01 00 00 00 e9 0a ff ff ff 8b 4d 00 48 8b 55 08 83 e1 08 48 0f ba 6d 00 03 80 c9 f0 eb c6 0f 0b e9 ee fe ff ff <0f> 0b 31 c0 e9 e5 fe ff ff e8 a7 30 fe ff 0f 1f 80 00 00 00 00 31 [ 4.068202] RSP: 0018:ffffa866c0cbb9a8 EFLAGS: 00010246 [ 4.068203] RAX: 0000000000000000 RBX: ffff98e65f826828 RCX: 0000000000000000 [ 4.068203] RDX: 0000000000000001 RSI: 0000000000000000 RDI: ffff98e65f826e40 [ 4.068204] RBP: ffff98e65f826e40 R08: 0000000000000000 R09: ffffffff84142e01 [ 4.068205] R10: ffff98e662b1b800 R11: 0000000000000001 R12: ffffffffc05bc0c0 [ 4.068205] R13: ffffffffc05bbbd8 R14: ffff98e65f825eb8 R15: 0000000000000003 [ 4.068206] FS: 00007f58737e7680(0000) GS:ffff98e664240000(0000) knlGS:0000000000000000 [ 4.068207] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 4.068207] CR2: 000055f1c2a53c40 CR3: 000000028af8c002 CR4: 00000000003606e0 [ 4.068208] Call Trace: [ 4.068210] ? try_to_del_timer_sync+0x48/0x70 [ 4.068214] soc_free_pcm_runtime.part.41+0x3b/0x50 [snd_soc_core] [ 4.068217] soc_cleanup_card_resources+0x181/0x2d0 [snd_soc_core] [ 4.068220] snd_soc_bind_card+0x1e0/0xb20 [snd_soc_core] [ 4.068223] ? devm_snd_soc_register_card+0x2e/0x80 [snd_soc_core] [ 4.068226] ? devm_snd_soc_register_card+0x80/0x80 [snd_soc_core] [ 4.068242] devm_snd_soc_register_card+0x3e/0x80 [snd_soc_core] [ 4.068244] mc_probe+0x18b/0x240 [snd_soc_sdw_rt711_rt1308_rt715] ````

Test recipe: kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: d6078f9 FW: https://github.com/thesofproject/sof/commits/master commit: d740a3e tplg: Same with FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg platform: CML Laptop with ALC711+ ALC1308+ ALC715 in SDW mode

dmesg_failed_431.log

bardliao commented 4 years ago

The dmesg log is

[    3.956725] ------------[ cut here ]------------
[    3.956730] WARNING: CPU: 5 PID: 733 at kernel/workqueue.c:3031 __flush_work+0x18b/0x1a0
[    3.956731] Modules linked in: snd_soc_sdw_rt711_rt1308_rt715(+) snd_soc_hdac_hdmi snd_soc_rt700 snd_soc_rt715 snd_soc_rt711 snd_soc_rt1308_sdw regmap_sdw snd_soc_dmic snd_sof_pci snd_sof_intel_hda_common snd_soc_hdac_hda soundwire_intel_init soundwire_intel soundwire_generic_allocation soundwire_cadence snd_sof_intel_hda snd_sof_intel_byt snd_soc_acpi_intel_match snd_sof_intel_ipc snd_sof snd_sof_xtensa_dsp snd_soc_acpi snd_hda_ext_core soundwire_bus snd_soc_core snd_intel_dspcfg snd_hda_codec snd_hwdep snd_hda_core snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device snd_timer snd x86_pkg_temp_thermal intel_powerclamp asix soundcore usbnet mei_me mei intel_lpss_pci intel_lpss processor_thermal_device mfd_core intel_soc_dts_iosf int3403_thermal int340x_thermal_zone int3400_thermal acpi_thermal_rel efivarfs i915 i2c_algo_bit drm_kms_helper syscopyarea sysfillrect xhci_pci sysimgblt fb_sys_fops xhci_hcd drm
[    3.956750] CPU: 5 PID: 733 Comm: systemd-udevd Tainted: G        W         5.4.0-rc8-sdw-validation-20191202-clk-v3-0-8b8c534 #rc8
[    3.956751] Hardware name: Dell Inc. Latitude 9510/, BIOS 0.1.3 10/01/2019
[    3.956752] RIP: 0010:__flush_work+0x18b/0x1a0
[    3.956753] Code: 5b 8d 8d 00 b8 01 00 00 00 e9 0a ff ff ff 8b 4d 00 48 8b 55 08 83 e1 08 48 0f ba 6d 00 03 80 c9 f0 eb c6 0f 0b e9 ee fe ff ff <0f> 0b 31 c0 e9 e5 fe ff ff e8 a7 30 fe ff 0f 1f 80 00 00 00 00 31
[    3.956754] RSP: 0018:ffffb046c07c39a8 EFLAGS: 00010246
[    3.956755] RAX: 0000000000000000 RBX: ffff965222132028 RCX: 0000000000000000
[    3.956756] RDX: 0000000000000001 RSI: 0000000000000000 RDI: ffff965222132640
[    3.956757] RBP: ffff965222132640 R08: 0000000000000002 R09: 00000000000271c0
[    3.956757] R10: 0000000000000000 R11: 0000000000000000 R12: ffffffffc03e40c0
[    3.956758] R13: ffffffffc03e3bd8 R14: ffff9652221336b8 R15: 0000000000000003
[    3.956759] FS:  00007f139a53e680(0000) GS:ffff965224340000(0000) knlGS:0000000000000000
[    3.956760] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    3.956761] CR2: 000055dbdd991e40 CR3: 000000029df6c006 CR4: 00000000003606e0
[    3.956761] Call Trace:
[    3.956766]  ? try_to_del_timer_sync+0x48/0x70
[    3.956772]  soc_free_pcm_runtime.part.41+0x3b/0x50 [snd_soc_core]
[    3.956776]  soc_cleanup_card_resources+0x181/0x2d0 [snd_soc_core]
[    3.956779]  snd_soc_bind_card+0x1e0/0xb20 [snd_soc_core]
[    3.956782]  ? devm_snd_soc_register_card+0x2e/0x80 [snd_soc_core]
[    3.956785]  ? devm_snd_soc_register_card+0x80/0x80 [snd_soc_core]
[    3.956788]  devm_snd_soc_register_card+0x3e/0x80 [snd_soc_core]
[    3.956791]  mc_probe+0x18b/0x240 [snd_soc_sdw_rt711_rt1308_rt715]
[    3.956794]  platform_drv_probe+0x32/0x90
[    3.956796]  really_probe+0xea/0x420
[    3.956798]  driver_probe_device+0x10b/0x120
[    3.956800]  device_driver_attach+0x4a/0x50
[    3.956801]  __driver_attach+0x95/0x130
[    3.956803]  ? device_driver_attach+0x50/0x50
[    3.956804]  bus_for_each_dev+0x71/0xb0
[    3.956806]  bus_add_driver+0x13f/0x210
[    3.956807]  ? 0xffffffffc0342000
[    3.956808]  driver_register+0x56/0xf0
[    3.956809]  ? 0xffffffffc0342000
[    3.956811]  do_one_initcall+0x41/0x1df
[    3.956815]  ? _cond_resched+0x10/0x40
[    3.956817]  ? kmem_cache_alloc_trace+0x36/0x1b0
[    3.956819]  do_init_module+0x56/0x1f4
[    3.956821]  load_module+0x22d6/0x27c0
[    3.956824]  ? vfs_read+0x10e/0x130
[    3.956825]  ? __do_sys_finit_module+0xe9/0x110
[    3.956827]  __do_sys_finit_module+0xe9/0x110
[    3.956828]  do_syscall_64+0x43/0x120
[    3.956830]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[    3.956831] RIP: 0033:0x7f139a05a839
[    3.956833] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 1f f6 2c 00 f7 d8 64 89 01 48
[    3.956834] RSP: 002b:00007ffee61ce348 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[    3.956835] RAX: ffffffffffffffda RBX: 000055dbdd96c000 RCX: 00007f139a05a839
[    3.956835] RDX: 0000000000000000 RSI: 00007f1399d390e5 RDI: 000000000000000f
[    3.956836] RBP: 00007f1399d390e5 R08: 0000000000000000 R09: 00007ffee61ce460
[    3.956837] R10: 000000000000000f R11: 0000000000000246 R12: 0000000000000000
[    3.956837] R13: 000055dbdd95ba70 R14: 0000000000020000 R15: 000055dbdd96c000
[    3.956838] ---[ end trace 39582c2426b37b08 ]---

And we can see it whenever sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: snd_soc_register_card failed -517 is seen

plbossart commented 4 years ago

Can you try this patch that was submitted to alsa-devel as well?

diff --git a/sound/soc/soc-core.c b/sound/soc/soc-core.c
index 79a4753..bdae48e 100644
--- a/sound/soc/soc-core.c
+++ b/sound/soc/soc-core.c
@@ -1983,8 +1983,11 @@ static int snd_soc_bind_card(struct snd_soc_card *card)
        goto probe_end;
    }

-   for_each_card_rtds(card, rtd)
-       soc_link_init(card, rtd);
+   for_each_card_rtds(card, rtd) {
+       ret = soc_link_init(card, rtd);
+       if (ret < 0)
+           goto probe_end;
+   }

    snd_soc_dapm_link_dai_widgets(card);
    snd_soc_dapm_connect_dai_link_widgets(card);
-- 
2.7.4
bardliao commented 4 years ago

Can you try this patch that was submitted to alsa-devel as well?

No, it doesn't help, but https://lore.kernel.org/alsa-devel/20191203173007.46504-1-cujomalainey@chromium.org/ does.

YvonneYang2 commented 4 years ago

Tested it 500 times, issue cannot be reproduced with latest soundwire-latest(121c751) and cml-010-drop-stable (5e5f69e). Close it.