Repository navigation
CML : S3 fails in 2nd iteration - noirq suspend failed #1050
Description
On the CML hatch / EVT, I’m seeing an issue with S3.
This happens consistently on the 2nd S3 iteration.
Though the logs do not suggest any audio failures, the issue is seen only when Audio drivers are loaded.
Hence the issue is in Audio bucket.
I tried to debug a bit, I have some data, but would like to get directions / suggestions from y
If we blacklist sof_pci_dev driver, S3 runs smooth for many iterations.
If Audio drivers are present, the 1st iteration S3 works clean. From 2nd iteration System fails enter suspend with below error and resumes immediately:
[125.346991] PM: noirq suspend of devices aborted after 0.486 msecs
[ 125.347480] PM: noirq resume of devices complete after 0.487 msecs
[ 125.347525] PM: noirq suspend of devices failed
I’m attaching the 2 scenario logs ( I’ve enabled SOF debug too)
From the SOF debug logs printed, I see a minor difference in couple of IPC messages.
I just wanted to run through you in case we get some clue
Success suspend case :
[ 88.857381] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf010e0e successful
[ 88.857393] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x6000021 successful
…
[ 89.007905] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
Failure suspend case :
[ 124.399017] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010e0e successful
[ 124.399817] sof-audio-pci 0000:00:1f.3: error: no reply expected, received 0x0
[ 124.467452] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x5000001 successful
…
[ 124.586325] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
Attached is the success and failure logs.
Activity
sathyap-chrome commentedon Jun 19, 2019
Topology & FW used : Cml_drop_004 : Commit: f82d9dad7bd4
Kernel :
HEAD is ASoC: SOF: pci: add module param to disable pm_runtime + ASoC: SOF: Intel: hda: switch to use legacy IRQ mode
full git log attached since we are on chrome kernel and its not 1:1 with sof-dev.
git_log.txt
ranj063 commentedon Jun 19, 2019
@sathyap-chrome why are using the patch to switch to IRQ mode. We have dropped that patch and kept MSI enabled in sof-dev
sathyap-chrome commentedon Jun 20, 2019
@ranj063 the issue is seen without that too. i tried to see if that helps. i can drop it and share logs.
sathyap-chrome commentedon Jun 20, 2019
Attached the fresh logs.
The SOF IPC response difference is seen here too,
dmesg_s3_fail.txt
dmesg_s3_pass.txt
PASSING SCENARIO:
[ 225.092643] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x6000021 successful
FAILURE SCENARIO:
[ 250.870828] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x5000001 successful
ranj063 commentedon Jun 20, 2019
@sathyap-chrome a couple of weeks ago the S3 test was working properly wasnt it? Do you know when things started breaking? have you dont a git bisect to see which commit causes the issue?
sathyap-chrome commentedon Jun 20, 2019
@ranj063 currently on google repo we have cml_drop 002 branch and we had it working across boards around 10 weeks back. Now since we are replacing many of the FROMLIST / CHROMIUM patches and took all upstream patches, git bisect wont be straight forward.
Also this issue is seen consistently on current google stack (with 0002), but debugging there might not help as they are older patches.
Can you help me understand the different SOF Poll status difference we are seeing.
I would try few bisect experiments and update you today
ranj063 commentedon Jun 27, 2019
Some progress with this bug. I see that during the second iteration of suspend/resume, an interrupt from IRQ 14 ends up in suspend aborting prematurely. From the logs attached, IRQ 14 is related to INT34BB:00 and the codec itself.
0: 63 0 0 0 0 0 0 0 IO-APIC 2-edge timer
1: 29 0 0 0 0 0 11 0 IO-APIC 1-edge i8042
8: 0 0 0 0 0 0 0 0 IO-APIC 8-edge rtc0
9: 177 199 0 0 0 0 0 0 IO-APIC 9-fasteoi acpi
14: 2385781 0 2 0 0 0 0 0 IO-APIC 14-fasteoi INT34BB:00
16: 84 0 0 0 143 0 0 0 IO-APIC 16-fasteoi idma64.0, i2c_designware.0, i801_smbus
17: 10 0 0 0 0 477 0 0 IO-APIC 17-fasteoi idma64.1, i2c_designware.1
19: 0 0 0 0 0 0 0 0 IO-APIC 19-fasteoi idma64.2, i2c_designware.2, mmc0
20: 33 0 0 0 0 0 0 0 IO-APIC 20-fasteoi idma64.4, ttyS0
22: 159 16085 0 0 0 0 0 0 IO-APIC 22-fasteoi idma64.5, pxa2xx-spi.5
23: 0 0 0 1430 0 0 0 0 IO-APIC 23-fasteoi idma64.6, pxa2xx-spi.6
32: 116 0 0 0 0 0 0 195 IO-APIC 32-fasteoi i2c_designware.3
85: 141 0 228 0 0 0 0 0 IO-APIC 85-fasteoi chromeos-ec
93: 38 0 3243 0 0 0 0 0 IO-APIC 93-edge cr50_spi
112: 7 0 0 0 0 0 0 0 IO-APIC 112-edge GDIX0000:00
117: 0 0 0 0 0 0 0 0 IO-APIC 117-edge ELAN0000:00
120: 166246 0 0 34372 0 0 0 0 PCI-MSI 32768-edge i915
121: 1326 0 0 0 10799 0 0 0 PCI-MSI 376832-edge ahci[0000:00:17.0]
122: 23748 0 0 0 0 6266 0 0 PCI-MSI 327680-edge xhci_hcd
123: 0 0 0 0 0 0 0 0 intel-gpio 231 0000:00:14.5 cd
124: 0 0 0 0 0 0 0 0 intel-gpio 8 pen_eject
125: 6613 0 0 150 0 0 0 0 PCI-MSI 333824-edge iwlwifi: default queue
126: 0 0 0 0 0 0 0 0 PCI-MSI 333825-edge iwlwifi: queue 1
127: 0 0 0 0 0 0 0 0 PCI-MSI 333826-edge iwlwifi: queue 2
128: 0 0 0 0 0 0 0 0 PCI-MSI 333827-edge iwlwifi: queue 3
129: 0 0 0 0 0 0 0 0 PCI-MSI 333828-edge iwlwifi: queue 4
130: 0 0 0 0 0 0 0 0 PCI-MSI 333829-edge iwlwifi: queue 5
131: 0 0 0 0 0 0 0 0 PCI-MSI 333830-edge iwlwifi: queue 6
132: 0 0 0 0 0 0 0 0 PCI-MSI 333831-edge iwlwifi: queue 7
133: 0 0 0 0 0 0 0 0 PCI-MSI 333832-edge iwlwifi: queue 8
134: 2 0 0 0 2 0 0 0 PCI-MSI 333833-edge iwlwifi: exception
135: 310 493 1317 863 1574 1113 1440 900 sysfstrig0 cros-ec-accel_consumer2
136: 310 493 1317 863 1574 1113 1440 900 sysfstrig0 cros-ec-accel_consumer0
137: 2385781 0 1 0 0 0 0 0 intel-gpio 160 rt5682
138: 303 0 0 0 0 373 0 0 PCI-MSI 514048-edge AudioHDA, AudioDSP
NMI: 0 2 1 1 1 1 1 1 Non-maskable interrupts
LOC: 774262 630660 557019 451529 542886 403796 540095 409648 Local timer interrupts
SPU: 0 0 0 0 0 0 0 0 Spurious interrupts
PMI: 0 2 1 1 1 1 1 1 Performance monitoring interrupts
IWI: 15573 496 1323 3931 1578 1117 1445 902 IRQ work interrupts
RTR: 14 0 0 0 0 0 0 0 APIC ICR read retries
RES: 60854 358867 73780 42925 24167 18660 12290 9398 Rescheduling interrupts
CAL: 14802 4574 4506 4329 4124 5041 4625 5048 Function call interrupts
TLB: 12231 2013 2197 1789 1974 2622 2315 2634 TLB shootdowns
TRM: 0 0 0 0 0 0 0 0 Thermal event interrupts
THR: 0 0 0 0 0 0 0 0 Threshold APIC interrupts
MCE: 0 0 0 0 0 0 0 0 Machine check exceptions
MCP: 5 6 6 6 6 6 6 6 Machine check polls
ERR: 0
MIS: 0
PIN: 0 0 0 0 0 0 0 0 Posted-interrupt notification event
NPI: 0 0 0 0 0 0 0 0 Nested posted-interrupt event
PIW: 0 0 0 0 0 0 0 0 Posted-interrupt wakeup event
ranj063 commentedon Jun 27, 2019
@sathyap-chrome some more update on this bug. I switched to nocodec mode on my board and the suspend stress test failure doesnt occur. So we have to figure out why the rt5682 codec is generating these wakeups. Can you please follow up with the codec folks?
ranj063 commentedon Jun 27, 2019
@sathyap-chrome the commit that breaks the suspend stress test is "UPSTREAM: ASoC: rt5682: Check JD status when system resume". I reverted this commit and the suspend stress test works fine. It looks like the delayed work scheduled for jack detection interferes with the suspend sequence.
Could you please follow up with the realtek folks?
sathyap-chrome commentedon Jun 28, 2019
Thanks a lot @ranj063 . I would contact Realtek on the same.
sathyap-chrome commentedon Jun 28, 2019
@ranj063 I think this patch along with actual interrupt configuration in bios makes the difference. Hence we dont see this on RVP as the JD ISR is not working there ?