[Bug]check-suspend-resume.sh test failed with non sof issue Call Trace in dmesg

ClarexZhou commented 4 years ago

Description Call Trace in dmesg during system suspend and resume. But not sof related. And sof functions still works. But case still failed. dmesg_calltrace.txt

Environment 1) Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).

Kernel: https://github.com/thesofproject/linux/commits/topic/sof-dev, commit 4b4681e
SOF: https://github.com/thesofproject/sof/releases/tag/v1.5-rc1, commit: 5f7d4e2, using sof-tgl.ri rename to sof-ehl.ri 2) Name of the topology file
Topology: sof-ehl-rt5660.tplg 3) Name of the platform(s) on which the bug is observed.
Platform: EHL RVP with RT5660 in I2S mode

dmesg

[  826.517489] sof-audio-pci 0000:00:1f.3: Current DSP power state: D3
[  832.067224] ------------[ cut here ]------------
[  832.067229] NETDEV WATCHDOG: enx000ec65b8f43 (asix): transmit queue 0 timed out
[  832.067248] WARNING: CPU: 3 PID: 0 at net/sched/sch_generic.c:443 dev_watchdog+0x23c/0x250
[  832.067249] Modules linked in: snd_soc_ehl_rt5660 snd_hda_codec_hdmi snd_soc_rt700 regmap_sdw snd_soc_dmic wmi_bmof snd_sof_pci snd_sof_intel_hda_common snd_soc_hdac_hda snd_sof_intel_hda snd_soc_acpi_intel_match snd_sof snd_sof_xtensa_dsp snd_soc_acpi snd_hda_ext_core snd_intel_dspcfg soundwire_intel soundwire_generic_allocation soundwire_cadence x86_pkg_temp_thermal soundwire_bus intel_powerclamp snd_hda_codec snd_hwdep asix snd_hda_core ledtrig_audio usbnet i915 snd_soc_rt5660 i2c_algo_bit snd_soc_rl6231 regmap_i2c drm_kms_helper snd_soc_core syscopyarea mei_me snd_compress sysfillrect sysimgblt fb_sys_fops mei drm spi_pxa2xx_platform snd_pcm wmi snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device snd_timer snd soundcore efivarfs mmc_block sdhci_pci xhci_pci cqhci sdhci xhci_hcd intel_lpss_pci intel_lpss mfd_core
[  832.067284] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 5.6.0-rc7-default-validation-0407-ehl-1111-e75573a #rc7
[  832.067285] Hardware name: Intel Corporation Elkhart Lake Embedded Platform/ElkhartLake LPDDR4x T3 CRB, BIOS EHLSFWI1.D00.1454.A00.1911070415 11/07/2019
[  832.067287] RIP: 0010:dev_watchdog+0x23c/0x250
[  832.067289] Code: 48 85 c0 75 e4 eb 9b 4c 89 ef c6 05 1e 75 bf 00 01 e8 08 f6 fc ff 89 d9 4c 89 ee 48 c7 c7 e0 1e 27 90 48 89 c2 e8 9a 6b 90 ff <0f> 0b e9 7a ff ff ff 0f 1f 00 66 2e 0f 1f 84 00 00 00 00 00 48 c7
[  832.067290] RSP: 0018:ffff995f00190e98 EFLAGS: 00010282
[  832.067292] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  832.067292] RDX: ffff9477389a7710 RSI: 00000000000000f6 RDI: 0000000000000300
[  832.067293] RBP: ffff947734522440 R08: 0000000000000002 R09: 00000000000296c0
[  832.067294] R10: 000001b4abd8ac7d R11: 0000000000032904 R12: 0000000000000001
[  832.067295] R13: ffff947734522000 R14: 0000000000000000 R15: ffffffff90405100
[  832.067296] FS:  0000000000000000(0000) GS:ffff947738980000(0000) knlGS:0000000000000000
[  832.067297] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  832.067298] CR2: 00007ff09e79dd00 CR3: 0000000247ff6000 CR4: 0000000000340ee0
[  832.067299] Call Trace:
[  832.067303]  <IRQ>
[  832.067306]  ? qdisc_put_unlocked+0x30/0x30
[  832.067309]  call_timer_fn+0x28/0x120
[  832.067312]  run_timer_softirq+0x190/0x3e0
[  832.067314]  ? tick_sched_timer+0x32/0x70
[  832.067316]  ? __hrtimer_run_queues+0x10b/0x280
[  832.067317]  ? ktime_get+0x31/0x90
[  832.067320]  __do_softirq+0xd4/0x2d4
[  832.067323]  irq_exit+0x98/0xa0
[  832.067325]  smp_apic_timer_interrupt+0x67/0x120
[  832.067327]  apic_timer_interrupt+0xf/0x20
[  832.067328]  </IRQ>
[  832.067330] RIP: 0010:mwait_idle+0x8b/0x1b0
[  832.067332] Code: 48 8b 04 25 00 7d 01 00 48 89 d1 0f 01 c8 48 8b 00 a8 08 75 23 e9 07 00 00 00 0f 00 2d 30 48 47 00 31 c0 48 89 c1 fb 0f 01 c9 <65> 8b 2d 7e 19 48 70 0f 1f 44 00 00 eb 83 fb eb ef 65 8b 05 6d 19
[  832.067333] RSP: 0018:ffff995f00107eb8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
[  832.067334] RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000000
[  832.067335] RDX: 0000000000000000 RSI: 0000000000000083 RDI: ffff94773899ee40
[  832.067336] RBP: 0000000000000003 R08: ffff94773899ee40 R09: 0000000000000000
[  832.067337] R10: 000001b4a80b9734 R11: 0000000000000002 R12: ffffffffffffffff
[  832.067337] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[  832.067341]  do_idle+0x1ac/0x220
[  832.067343]  cpu_startup_entry+0x14/0x20
[  832.067346]  start_secondary+0x152/0x1a0
[  832.067349]  secondary_startup_64+0xb6/0xc0
[  832.067351] ---[ end trace c3e730e40b421705 ]---
[  832.147456] usb 1-4: reset full-speed USB device number 3 using xh

Bin-QA commented 4 years ago

call trace refer code: https://github.com/thesofproject/sof-test/blob/master/tools/sof-kernel-log-check.sh#L25

@xiulipan @aiChaoSONG need ignore call trace or it is kernel build problem

aiChaoSONG commented 4 years ago

@Bin-QA how about grep "snd" from error? if call trace is not related to ALSA, we should get nothing.

Bin-QA commented 4 years ago

@Bin-QA how about grep "snd" from error? if call trace is not related to ALSA, we should get nothing.

@aiChaoSONG We just handle 'Call Trace', so your suggestion seems couldn't ignore this error

aiChaoSONG commented 4 years ago

@Bin-QA call trace related to alsa should contain 'snd' keyword, because every alsa function started wtith 'snd'.

Bin-QA commented 4 years ago

@Bin-QA call trace related to alsa should contain 'snd' keyword, because every alsa function started wtith 'snd'.

So like this? eval $cmd|grep 'Call Trace' -A5 -B3|grep snd

aiChaoSONG commented 4 years ago

@Bin-QA See my patch here: https://github.com/thesofproject/sof-test/pull/208. if call trace is not from alsa, we still output error message, but don't fail the test case.

aiChaoSONG commented 4 years ago

@ClarexZhou @Bin-QA This call trace is sure related to sound, see Modules linked in... line.

Modules linked in: snd_soc_ehl_rt5660 snd_hda_codec_hdmi snd_soc_rt700 regmap_sdw snd_soc_dmic wmi_bmof snd_sof_pci snd_sof_intel_hda_common snd_soc_hdac_hda snd_sof_intel_hda snd_soc_acpi_intel_match snd_sof snd_sof_xtensa_dsp snd_soc_acpi snd_hda_ext_core snd_intel_dspcfg soundwire_intel soundwire_generic_allocation soundwire_cadence x86_pkg_temp_thermal soundwire_bus intel_powerclamp snd_hda_codec snd_hwdep asix snd_hda_core ledtrig_audio usbnet i915 snd_soc_rt5660 i2c_algo_bit snd_soc_rl6231 regmap_i2c drm_kms_helper snd_soc_core syscopyarea mei_me snd_compress sysfillrect sysimgblt fb_sys_fops mei drm spi_pxa2xx_platform snd_pcm wmi snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device snd_timer snd soundcore efivarfs mmc_block sdhci_pci xhci_pci cqhci sdhci xhci_hcd intel_lpss_pci intel_lpss mfd_core

close for not valid issue

thesofproject / sof-test

[Bug]check-suspend-resume.sh test failed with non sof issue Call Trace in dmesg #184