From: "Paul E. McKenney" <paulmck@kernel.org>
To: Borislav Petkov <bp@alien8.de>
Cc: x86-ml <x86@kernel.org>, lkml <linux-kernel@vger.kernel.org>
Subject: Re: INFO: task rcu_gp:3 blocked for more than 122 seconds.
Date: Thu, 29 Sep 2022 08:37:22 -0700 [thread overview]
Message-ID: <20220929153722.GG4196@paulmck-ThinkPad-P17-Gen-1> (raw)
In-Reply-To: <YzVkyxSjifFghj8H@zn.tnic>
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
next prev parent reply other threads:[~2022-09-29 15:40 UTC|newest]
Thread overview: 5+ messages / expand[flat|nested] mbox.gz Atom feed top
2022-09-29 9:26 Borislav Petkov
2022-09-29 15:37 ` Paul E. McKenney [this message]
2022-09-30 10:19 ` Borislav Petkov
2022-09-30 16:11 ` Paul E. McKenney
2022-09-30 16:28 ` Borislav Petkov
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20220929153722.GG4196@paulmck-ThinkPad-P17-Gen-1 \
--to=paulmck@kernel.org \
--cc=bp@alien8.de \
--cc=linux-kernel@vger.kernel.org \
--cc=x86@kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox
all inboxes | Powered by JetHome®