Hi Takashi,
Am Di den 10. Dez 2019 um 15:43 schrieb Takashi Iwai:
There is also a issue with a swapper thread in ath9k code but the one with the biggest CPU hook is still alsa.
Do you see the relevant kernel messages, e.g. switch to polling mode?
Nope.
Here is the relevant logs starting from undocking event up to the sleep that I mentioned fixing the issue: Dec 10 15:19:12 chua kernel: [14611.133847] ACPI: _SB_.GDCK: undocking Dec 10 15:19:12 chua kernel: [14611.137923] usb 1-4: USB disconnect, device number 5 Dec 10 15:19:13 chua kernel: [14611.360780] thinkpad_acpi: woke up due to a hot-unplug request... Dec 10 15:19:13 chua kernel: [14611.361034] thinkpad_acpi: undocked Dec 10 15:19:13 chua kernel: [14611.361509] ACPI: _SB_.GDCK: undocking Dec 10 15:19:16 chua kernel: [14614.688138] Monitor-Mwait will be used to enter C-3 state Dec 10 15:19:16 chua kernel: [14614.909277] sd 0:0:0:0: [sda] Synchronizing SCSI cache Dec 10 15:19:16 chua kernel: [14614.910426] sd 0:0:0:0: [sda] Stopping disk Dec 10 15:19:17 chua kernel: [14615.279585] e1000e: eth0 NIC Link is Down Dec 10 15:19:17 chua kernel: [14615.995311] sd 0:0:0:0: [sda] Starting disk Dec 10 15:19:18 chua kernel: [14616.840213] BTRFS warning (device dm-3): excessive commit interval 600 Dec 10 15:19:18 chua kernel: [14616.840217] BTRFS info (device dm-3): disk space caching is enabled [more of the last two lines] Dec 10 15:19:19 chua kernel: [14617.856624] e1000e: eth0 NIC Link is Down Dec 10 15:19:26 chua kernel: [14624.416815] wlan0: authenticate with 1a:e8:29:62:36:fc Dec 10 15:19:26 chua kernel: [14624.422409] wlan0: send auth to 1a:e8:29:62:36:fc (try 1/3) Dec 10 15:19:26 chua kernel: [14624.450142] wlan0: authenticated Dec 10 15:19:26 chua kernel: [14624.450480] wlan0: associate with 1a:e8:29:62:36:fc (try 1/3) Dec 10 15:19:26 chua kernel: [14624.455014] wlan0: RX AssocResp from 1a:e8:29:62:36:fc (capab=0x411 status=0 aid=3) Dec 10 15:19:26 chua kernel: [14624.455363] wlan0: associated Dec 10 15:19:26 chua kernel: [14624.460321] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready Dec 10 15:19:42 chua kernel: [14640.895731] e1000e: eth0 NIC Link is Down Dec 10 15:19:52 chua kernel: [14650.415684] e1000e: eth0 NIC Link is Down Dec 10 15:19:55 chua kernel: [14653.332765] wlan0: authenticate with 1a:e8:29:62:36:fc Dec 10 15:19:55 chua kernel: [14653.337337] wlan0: send auth to 1a:e8:29:62:36:fc (try 1/3) Dec 10 15:19:55 chua kernel: [14653.397026] wlan0: send auth to 1a:e8:29:62:36:fc (try 2/3) Dec 10 15:19:55 chua kernel: [14653.463283] wlan0: send auth to 1a:e8:29:62:36:fc (try 3/3) Dec 10 15:19:55 chua kernel: [14653.522603] wlan0: authentication with 1a:e8:29:62:36:fc timed out Dec 10 15:20:34 chua kernel: [14692.783662] e1000e: eth0 NIC Link is Down Dec 10 15:23:36 chua kernel: [14874.223723] perf: interrupt took too long (2597 > 2500), lowering kernel.perf_event_max_sample_rate to 77000 Dec 10 15:23:36 chua kernel: [14874.227937] perf: interrupt took too long (3335 > 3246), lowering kernel.perf_event_max_sample_rate to 59000 Dec 10 15:23:36 chua kernel: [14874.232928] perf: interrupt took too long (4169 > 4168), lowering kernel.perf_event_max_sample_rate to 47000 Dec 10 15:23:36 chua kernel: [14874.241582] perf: interrupt took too long (5233 > 5211), lowering kernel.perf_event_max_sample_rate to 38000 Dec 10 15:23:36 chua kernel: [14874.252231] perf: interrupt took too long (6548 > 6541), lowering kernel.perf_event_max_sample_rate to 30000 Dec 10 15:23:36 chua kernel: [14874.267034] perf: interrupt took too long (8211 > 8185), lowering kernel.perf_event_max_sample_rate to 24000 Dec 10 15:23:36 chua kernel: [14874.295426] perf: interrupt took too long (10276 > 10263), lowering kernel.perf_event_max_sample_rate to 19000 Dec 10 15:23:37 chua kernel: [14875.392080] perf: interrupt took too long (12851 > 12845), lowering kernel.perf_event_max_sample_rate to 15000 Dec 10 15:24:09 chua kernel: [14907.880874] e1000e: eth0 NIC Link is Down Dec 10 15:24:12 chua kernel: [14910.754897] wlan0: authenticate with 1a:e8:29:e1:1c:4b Dec 10 15:24:12 chua kernel: [14910.759170] wlan0: send auth to 1a:e8:29:e1:1c:4b (try 1/3) Dec 10 15:24:12 chua kernel: [14910.764932] wlan0: authenticated Dec 10 15:24:12 chua kernel: [14910.765477] wlan0: associate with 1a:e8:29:e1:1c:4b (try 1/3) Dec 10 15:24:12 chua kernel: [14910.778257] wlan0: RX AssocResp from 1a:e8:29:e1:1c:4b (capab=0x431 status=0 aid=8) Dec 10 15:24:12 chua kernel: [14910.778651] wlan0: associated Dec 10 15:24:12 chua kernel: [14910.785585] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready Dec 10 15:33:47 chua kernel: [15485.695970] wlan0: deauthenticating from 1a:e8:29:e1:1c:4b by local choice (Reason: 3=DEAUTH_LEAVING) Dec 10 15:33:48 chua kernel: [15486.359726] e1000e: eth0 NIC Link is Down Dec 10 15:33:49 chua kernel: [15487.208769] e1000e: eth0 NIC Link is Down Dec 10 15:33:49 chua kernel: [15487.717376] ath9k: ath9k: Driver unloaded Dec 10 15:33:50 chua kernel: [15488.357624] PM: suspend entry (deep) Dec 10 15:33:55 chua kernel: [15488.381517] Filesystems sync: 0.023 seconds Dec 10 15:33:55 chua kernel: [15488.381942] Freezing user space processes ... (elapsed 0.001 seconds) done. Dec 10 15:33:55 chua kernel: [15488.383328] OOM killer disabled. Dec 10 15:33:55 chua kernel: [15488.383329] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done. Dec 10 15:33:55 chua kernel: [15488.384424] printk: Suspending console(s) (use no_console_suspend to debug) Dec 10 15:33:55 chua kernel: [15488.386563] sd 0:0:0:0: [sda] Synchronizing SCSI cache Dec 10 15:33:55 chua kernel: [15488.387436] sd 0:0:0:0: [sda] Stopping disk Dec 10 15:33:55 chua kernel: [15488.407871] serial 00:05: disabled Dec 10 15:33:55 chua kernel: [15488.409065] e1000e: EEE TX LPI TIMER: 00000000 Dec 10 15:33:55 chua kernel: [15488.497441] snd_hdac_bus_update_rirb: 58 callbacks suppressed Dec 10 15:33:55 chua kernel: [15488.497449] snd_hda_intel 0000:00:1b.0: spurious response 0x0:0x0, last cmd=0x11f0900 Dec 10 15:33:55 chua kernel: [15488.497453] snd_hda_intel 0000:00:1b.0: spurious response 0x7fffffff:0x0, last cmd=0x11f0900 Dec 10 15:33:55 chua kernel: [15488.497457] snd_hda_intel 0000:00:1b.0: spurious response 0x0:0x0, last cmd=0x11f0900 Dec 10 15:33:55 chua kernel: [15488.497461] snd_hda_intel 0000:00:1b.0: spurious response 0x0:0x0, last cmd=0x11f0900 Dec 10 15:33:55 chua kernel: [15488.497464] snd_hda_intel 0000:00:1b.0: spurious response 0x0:0x0, last cmd=0x11f0900 Dec 10 15:33:55 chua kernel: [15488.497468] snd_hda_intel 0000:00:1b.0: spurious response 0x0:0x0, last cmd=0x11f0900 Dec 10 15:33:55 chua kernel: [15488.497471] snd_hda_intel 0000:00:1b.0: spurious response 0x7fffffff:0x0, last cmd=0x11f0900 Dec 10 15:33:55 chua kernel: [15488.497475] snd_hda_intel 0000:00:1b.0: spurious response 0x0:0x0, last cmd=0x11f0900 Dec 10 15:33:55 chua kernel: [15488.497478] snd_hda_intel 0000:00:1b.0: spurious response 0x0:0x0, last cmd=0x11f0900 Dec 10 15:33:55 chua kernel: [15488.497481] snd_hda_intel 0000:00:1b.0: spurious response 0x0:0x0, last cmd=0x11f0900 Dec 10 15:33:55 chua kernel: [15488.554013] ACPI: EC: interrupt blocked Dec 10 15:33:55 chua kernel: [15488.566977] ACPI: Preparing to enter system sleep state S3 Dec 10 15:33:55 chua kernel: [15488.583067] ACPI: EC: event blocked Dec 10 15:33:55 chua kernel: [15488.583069] ACPI: EC: EC stopped Dec 10 15:33:55 chua kernel: [15488.583070] PM: Saving platform NVS memory Dec 10 15:33:55 chua kernel: [15488.583426] Disabling non-boot CPUs ... Dec 10 15:33:55 chua kernel: [15488.584808] smpboot: CPU 1 is now offline
Let me add that this time I encountered the issue after taking the laptop from the docking station.
... this can be the cause: the hardware doesn't react to the pin jack sense request for the dock that isn't present any longer. Or something goes wrong here, repeating, etc.
I think, it might have to do with that as I often use the dock.
However, I think, I even seen the problem after I did a fresh boot far away from the dock.
After sending it to sleep and waking it up again, the problem is gone (as it often can be solved).
So the problem is very likely some flaky hardware response.
Anything you think can be done against that?
Regards Klaus