| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <20220929153722.GG4196@paulmck-ThinkPad-P17-Gen-1>
Date: Thu, 29 Sep 2022 08:37:22 -0700
From: "Paul E. McKenney" <paulmck@...nel.org>
To: Borislav Petkov <bp@...en8.de>
Cc: x86-ml <x86@...nel.org>, lkml <linux-kernel@...r.kernel.org>
Subject: Re: INFO: task rcu_gp:3 blocked for more than 122 seconds.
On Thu, Sep 29, 2022 at 11:26:35AM +0200, Borislav Petkov wrote:
> Hi Paul,
>
> Mr. Z says I should show this to you.
>
> It is latest Linus + latest tip/master. Happens at boot on one of my
> test boxes.
As discussed on IRC, I got nuttin' on this one. Looks like an RCU
expedited grace period is stuck waiting for its workqueue kthread, and
that this workqueue kthread is stuck for some reason.
Thanx, Paul
> [ 249.149378] INFO: task rcu_gp:3 blocked for more than 122 seconds.
> [ 249.155726] Not tainted 6.0.0-rc7+ #1
> [ 249.160025] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 249.168000] task:rcu_gp state:I stack:0 pid:3 ppid:2 flags:0x00004000
> [ 249.176483] Call Trace:
> [ 249.178997] <TASK>
> [ 249.181171] __schedule+0x38f/0x1490
> [ 249.184864] schedule+0x5d/0xe0
> [ 249.188086] rescuer_thread+0x2f8/0x390
> [ 249.192044] ? worker_thread+0x3f0/0x3f0
> [ 249.196043] kthread+0xe6/0x110
> [ 249.199282] ? kthread_complete_and_exit+0x20/0x20
> [ 249.204179] ret_from_fork+0x22/0x30
> [ 249.207914] </TASK>
> [ 249.210157] INFO: task rcu_par_gp:4 blocked for more than 122 seconds.
> [ 249.216785] Not tainted 6.0.0-rc7+ #1
> [ 249.221040] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 249.228974] task:rcu_par_gp state:I stack:0 pid:4 ppid:2 flags:0x00004000
> [ 249.237449] Workqueue: 0x0 (rcu_par_gp)
> [ 249.241437] Call Trace:
> [ 249.243944] <TASK>
> [ 249.246099] __schedule+0x38f/0x1490
> [ 249.249743] schedule+0x5d/0xe0
> [ 249.252941] rescuer_thread+0x2f8/0x390
> [ 249.256831] ? worker_thread+0x3f0/0x3f0
> [ 249.260811] kthread+0xe6/0x110
> [ 249.263997] ? kthread_complete_and_exit+0x20/0x20
> [ 249.268836] ret_from_fork+0x22/0x30
> [ 249.272482] </TASK>
> [ 249.274699] INFO: task slub_flushwq:5 blocked for more than 123 seconds.
> [ 249.281463] Not tainted 6.0.0-rc7+ #1
> [ 249.285692] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 249.293596] task:slub_flushwq state:I stack:0 pid:5 ppid:2 flags:0x00004000
> [ 249.302039] Call Trace:
> [ 249.304535] <TASK>
> [ 249.306669] __schedule+0x38f/0x1490
> [ 249.310314] schedule+0x5d/0xe0
> [ 249.313496] rescuer_thread+0x2f8/0x390
> [ 249.317388] ? worker_thread+0x3f0/0x3f0
> [ 249.321355] kthread+0xe6/0x110
> [ 249.324536] ? kthread_complete_and_exit+0x20/0x20
> [ 249.329380] ret_from_fork+0x22/0x30
> [ 249.333019] </TASK>
> [ 249.335236] INFO: task kworker/0:0:6 blocked for more than 123 seconds.
> [ 249.341926] Not tainted 6.0.0-rc7+ #1
> [ 249.346157] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 249.354062] task:kworker/0:0 state:I stack:0 pid:6 ppid:2 flags:0x00004000
> [ 249.362506] Workqueue: 0x0 (rcu_par_gp)
> [ 249.366471] Call Trace:
> [ 249.368953] <TASK>
> [ 249.371087] __schedule+0x38f/0x1490
> [ 249.374724] schedule+0x5d/0xe0
> [ 249.377897] worker_thread+0xbc/0x3f0
> [ 249.381599] ? process_one_work+0x580/0x580
> [ 249.385821] kthread+0xe6/0x110
> [ 249.389009] ? kthread_complete_and_exit+0x20/0x20
> [ 249.393851] ret_from_fork+0x22/0x30
> [ 249.397489] </TASK>
> [ 249.399713] INFO: task kworker/0:0H:7 blocked for more than 123 seconds.
> [ 249.406479] Not tainted 6.0.0-rc7+ #1
> [ 249.410710] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 249.418614] task:kworker/0:0H state:I stack:0 pid:7 ppid:2 flags:0x00004000
> [ 249.427053] Workqueue: 0x0 (events_highpri)
> [ 249.431608] Call Trace:
> [ 249.434336] <TASK>
> [ 249.436697] __schedule+0x38f/0x1490
> [ 249.440554] schedule+0x5d/0xe0
> [ 249.443952] worker_thread+0xbc/0x3f0
> [ 249.447877] ? process_one_work+0x580/0x580
> [ 249.452317] kthread+0xe6/0x110
> [ 249.455716] ? kthread_complete_and_exit+0x20/0x20
> [ 249.460779] ret_from_fork+0x22/0x30
> [ 249.464632] </TASK>
> [ 249.467064] INFO: task kworker/u64:0:8 blocked for more than 123 seconds.
> [ 249.474146] Not tainted 6.0.0-rc7+ #1
> [ 249.478601] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 249.486736] task:kworker/u64:0 state:I stack:0 pid:8 ppid:2 flags:0x00004000
> [ 249.495407] Workqueue: 0x0 (scsi_tmf_1)
> [ 249.499603] Call Trace:
> [ 249.502340] <TASK>
> [ 249.504699] __schedule+0x38f/0x1490
> [ 249.508556] schedule+0x5d/0xe0
> [ 249.511951] worker_thread+0xbc/0x3f0
> [ 249.515876] ? process_one_work+0x580/0x580
> [ 249.520321] kthread+0xe6/0x110
> [ 249.523719] ? kthread_complete_and_exit+0x20/0x20
> [ 249.528781] ret_from_fork+0x22/0x30
> [ 249.532636] </TASK>
> [ 249.535080] INFO: task kworker/0:1H:9 blocked for more than 123 seconds.
> [ 249.542069] Not tainted 6.0.0-rc7+ #1
> [ 249.546527] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 249.554665] task:kworker/0:1H state:I stack:0 pid:9 ppid:2 flags:0x00004000
> [ 249.563331] Workqueue: 0x0 (kblockd)
> [ 249.567268] Call Trace:
> [ 249.569989] <TASK>
> [ 249.572348] __schedule+0x38f/0x1490
> [ 249.576205] schedule+0x5d/0xe0
> [ 249.579607] worker_thread+0xbc/0x3f0
> [ 249.583535] ? process_one_work+0x580/0x580
> [ 249.587975] kthread+0xe6/0x110
> [ 249.591371] ? kthread_complete_and_exit+0x20/0x20
> [ 249.596430] ret_from_fork+0x22/0x30
> [ 249.600289] </TASK>
> [ 249.602726] INFO: task mm_percpu_wq:10 blocked for more than 123 seconds.
> [ 249.609811] Not tainted 6.0.0-rc7+ #1
> [ 249.614262] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 249.622398] task:mm_percpu_wq state:I stack:0 pid:10 ppid:2 flags:0x00004000
> [ 249.631063] Call Trace:
> [ 249.633781] <TASK>
> [ 249.636142] __schedule+0x38f/0x1490
> [ 249.640006] schedule+0x5d/0xe0
> [ 249.643419] rescuer_thread+0x2f8/0x390
> [ 249.647524] ? worker_thread+0x3f0/0x3f0
> [ 249.651703] kthread+0xe6/0x110
> [ 249.655105] ? kthread_complete_and_exit+0x20/0x20
> [ 249.660167] ret_from_fork+0x22/0x30
> [ 249.664033] </TASK>
> [ 249.666489] INFO: task rcu_tasks_kthre:11 blocked for more than 123 seconds.
> [ 249.673828] Not tainted 6.0.0-rc7+ #1
> [ 249.678277] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 249.686413] task:rcu_tasks_kthre state:I stack:0 pid:11 ppid:2 flags:0x00004000
> [ 249.695068] Call Trace:
> [ 249.697802] <TASK>
> [ 249.700161] __schedule+0x38f/0x1490
> [ 249.704020] ? mark_held_locks+0x49/0x80
> [ 249.708229] ? rcu_tasks_one_gp+0x3e0/0x3e0
> [ 249.712728] schedule+0x5d/0xe0
> [ 249.716133] rcu_tasks_one_gp+0x19e/0x3e0
> [ 249.720428] ? rcu_tasks_one_gp+0x3e0/0x3e0
> [ 249.724879] rcu_tasks_kthread+0x31/0x40
> [ 249.729072] kthread+0xe6/0x110
> [ 249.732482] ? kthread_complete_and_exit+0x20/0x20
> [ 249.737565] ret_from_fork+0x22/0x30
> [ 249.741429] </TASK>
> [ 249.743865] INFO: task rcu_tasks_rude_:12 blocked for more than 123 seconds.
> [ 249.751224] Not tainted 6.0.0-rc7+ #1
> [ 249.755698] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 249.763861] task:rcu_tasks_rude_ state:I stack:0 pid:12 ppid:2 flags:0x00004000
> [ 249.772515] Call Trace:
> [ 249.775256] <TASK>
> [ 249.777629] __schedule+0x38f/0x1490
> [ 249.781482] ? mark_held_locks+0x49/0x80
> [ 249.785667] ? rcu_tasks_one_gp+0x3e0/0x3e0
> [ 249.790148] schedule+0x5d/0xe0
> [ 249.793559] rcu_tasks_one_gp+0x19e/0x3e0
> [ 249.797866] ? rcu_tasks_one_gp+0x3e0/0x3e0
> [ 249.802315] rcu_tasks_kthread+0x31/0x40
> [ 249.806515] kthread+0xe6/0x110
> [ 249.809945] ? kthread_complete_and_exit+0x20/0x20
> [ 249.815007] ret_from_fork+0x22/0x30
> [ 249.818904] </TASK>
> [ 249.821366]
> Showing all locks held in the system:
> [ 249.828044] 1 lock held by rcu_tasks_kthre/11:
> [ 249.832767] #0: ffffffff8273bdf0 (rcu_tasks.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x2b/0x3e0
> [ 249.842684] 1 lock held by rcu_tasks_rude_/12:
> [ 249.847389] #0: ffffffff8273bb70 (rcu_tasks_rude.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x2b/0x3e0
> [ 249.857732] 1 lock held by khungtaskd/56:
> [ 249.862000] #0: ffffffff8273c800 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x15/0x16b
> [ 249.871288] 1 lock held by in:imklog/1289:
> [ 249.875633] #0: ffff888100f309a8 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x65/0xb0
>
> [ 249.885886] =============================================
>
>
> --
> Regards/Gruss,
> Boris.
>
> https://people.kernel.org/tglx/notes-about-netiquette
Powered by blists - more mailing lists