Bug#946601: linux-image-4.19.0-6-amd64: High load by kworker, shutdown or reboot hangs

[Olaf Skibbe]

Hi all,

I would like to add a detail:
I checked today: on shutdown, the system hangs for at least 3 hours with 
the message

    watchdog: watchdog0: watchdog did not stop!

This means: the machine did not reboot, I had to switch off the machine 
manually. I would therefore suggest to increase the severity.

I stored the complete dmesg output and can provide if wanted.

Cheers,
Olaf



On Wed, 11 Dec 2019 at 17:57, Olaf Skibbe wrote:

Package: src:linux
Version: 4.19.67-2+deb10u2
Severity: normal
Tags: newcomer

Dear Maintainer,

I experience the following issue:

When the system is running for some time (usually a few days, but sometimes
some hours), the load rises to about 5. The kernel log (dmesg) shows this
message (and repeats it several times):


[196473.819189] INFO: task kworker/u16:0:19009 blocked for more than 120
seconds.
[196473.819196]       Not tainted 4.19.0-6-amd64 #1 Debian 4.19.67-2+deb10u2
[196473.819199] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[196473.819202] kworker/u16:0   D    0 19009      2 0x80000000
[196473.819225] Workqueue: scsi_tmf_6 scmd_eh_abort_handler [scsi_mod]
[196473.819228] Call Trace:
[196473.819239]  ? __schedule+0x2a2/0x870
[196473.819244]  ? __switch_to_asm+0x41/0x70
[196473.819249]  schedule+0x28/0x80
[196473.819253]  schedule_timeout+0x26d/0x390
[196473.819259]  ? __switch_to_asm+0x35/0x70
[196473.819263]  ? __switch_to_asm+0x41/0x70
[196473.819267]  ? __switch_to_asm+0x35/0x70
[196473.819271]  ? __switch_to_asm+0x41/0x70
[196473.819275]  ? __switch_to_asm+0x35/0x70
[196473.819280]  ? __switch_to_asm+0x41/0x70
[196473.819284]  ? __switch_to_asm+0x35/0x70
[196473.819288]  ? __switch_to_asm+0x41/0x70
[196473.819292]  wait_for_completion+0x11f/0x190
[196473.819299]  ? wake_up_q+0x70/0x70
[196473.819306]  command_abort+0x5b/0x90 [usb_storage]
[196473.819320]  scmd_eh_abort_handler+0x85/0x220 [scsi_mod]
[196473.819327]  process_one_work+0x1a7/0x3a0
[196473.819332]  worker_thread+0x30/0x390
[196473.819337]  ? create_worker+0x1a0/0x1a0
[196473.819340]  kthread+0x112/0x130
[196473.819344]  ? kthread_bind+0x30/0x30
[196473.819349]  ret_from_fork+0x35/0x40

The load then stays high until shutdown. It remains fully usable, top looks
like this:

top - 17:52:44 up 2 days,  6:57,  1 user,  load average: 5.43, 5.21, 4.32
Tasks: 217 total,   1 running, 216 sleeping,   0 stopped,   0 zombie
%Cpu0  :  2.3 us,  1.3 sy,  0.0 ni, 96.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu1  :  0.0 us,  0.0 sy,  0.0 ni,100.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu2  :  4.7 us,  2.5 sy,  0.0 ni, 92.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu3  :  1.0 us,  0.3 sy,  0.0 ni,  0.0 id, 98.7 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu4  :  0.0 us,  0.3 sy,  0.0 ni,  0.0 id, 99.7 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu5  :  0.3 us,  0.3 sy,  0.0 ni, 99.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu6  :  0.0 us,  0.3 sy,  0.0 ni, 99.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu7  :  1.0 us,  0.3 sy,  0.0 ni, 98.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :  31998.7 total,  26462.0 free,   1366.2 used,   4170.5 buff/cache
MiB Swap:  32595.0 total,  32595.0 free,      0.0 used.  29682.1 avail Mem

At shutdown, the system hangs for about 20 minutes with the message "watchdog:
watchdog did not stop" (quoted from mind memory) until it finally shuts down.
This is always related to the increased load and the respective dmesg messages.

I experienced this behaviour about 20 times within the last few months. I did
not find any workaround t solve this situation.

Cheers,
Olaf