* INFO: task rcu_gp:3 blocked for more than 122 seconds.
@ 2022-09-29 9:26 Borislav Petkov
2022-09-29 15:37 ` Paul E. McKenney
0 siblings, 1 reply; 5+ messages in thread
From: Borislav Petkov @ 2022-09-29 9:26 UTC (permalink / raw)
To: Paul E. McKenney; +Cc: x86-ml, lkml
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.
[ 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
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: INFO: task rcu_gp:3 blocked for more than 122 seconds.
2022-09-29 9:26 INFO: task rcu_gp:3 blocked for more than 122 seconds Borislav Petkov
@ 2022-09-29 15:37 ` Paul E. McKenney
2022-09-30 10:19 ` Borislav Petkov
0 siblings, 1 reply; 5+ messages in thread
From: Paul E. McKenney @ 2022-09-29 15:37 UTC (permalink / raw)
To: Borislav Petkov; +Cc: x86-ml, lkml
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
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: INFO: task rcu_gp:3 blocked for more than 122 seconds.
2022-09-29 15:37 ` Paul E. McKenney
@ 2022-09-30 10:19 ` Borislav Petkov
2022-09-30 16:11 ` Paul E. McKenney
0 siblings, 1 reply; 5+ messages in thread
From: Borislav Petkov @ 2022-09-30 10:19 UTC (permalink / raw)
To: Paul E. McKenney, Peter Zijlstra; +Cc: x86-ml, lkml
On Thu, Sep 29, 2022 at 08:37:22AM -0700, Paul E. McKenney wrote:
> 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.
Yeah, it is not that easy to repro - I need to wait a couple of minutes
after it boots. Look at the timestamps:
[ 249.149378] INFO: task rcu_gp:3 blocked for more than 122 seconds.
^^^^^^^^^^^^^^
But it looks like sched/core is the culprit because merging it into
Linus master triggers it.
Lemme bisect that.
Stay tuned.
--
Regards/Gruss,
Boris.
https://people.kernel.org/tglx/notes-about-netiquette
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: INFO: task rcu_gp:3 blocked for more than 122 seconds.
2022-09-30 10:19 ` Borislav Petkov
@ 2022-09-30 16:11 ` Paul E. McKenney
2022-09-30 16:28 ` Borislav Petkov
0 siblings, 1 reply; 5+ messages in thread
From: Paul E. McKenney @ 2022-09-30 16:11 UTC (permalink / raw)
To: Borislav Petkov; +Cc: Peter Zijlstra, x86-ml, lkml
On Fri, Sep 30, 2022 at 12:19:34PM +0200, Borislav Petkov wrote:
> On Thu, Sep 29, 2022 at 08:37:22AM -0700, Paul E. McKenney wrote:
> > 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.
>
> Yeah, it is not that easy to repro - I need to wait a couple of minutes
> after it boots. Look at the timestamps:
>
> [ 249.149378] INFO: task rcu_gp:3 blocked for more than 122 seconds.
> ^^^^^^^^^^^^^^
That can be annoying! I well recall one bisection session where each step
took several hours, and where each step required manual intervention,
and where the bug was urgent. I got the bisection overnight, but was
pretty useless then next day. ;-)
> But it looks like sched/core is the culprit because merging it into
> Linus master triggers it.
It is possible that Peter would want proof of this. ;-)
> Lemme bisect that.
Please, and thank you in advance!
Thanx, Paul
> Stay tuned.
>
> --
> Regards/Gruss,
> Boris.
>
> https://people.kernel.org/tglx/notes-about-netiquette
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: INFO: task rcu_gp:3 blocked for more than 122 seconds.
2022-09-30 16:11 ` Paul E. McKenney
@ 2022-09-30 16:28 ` Borislav Petkov
0 siblings, 0 replies; 5+ messages in thread
From: Borislav Petkov @ 2022-09-30 16:28 UTC (permalink / raw)
To: Paul E. McKenney; +Cc: Peter Zijlstra, x86-ml, lkml
On Fri, Sep 30, 2022 at 09:11:29AM -0700, Paul E. McKenney wrote:
> That can be annoying! I well recall one bisection session where each step
> took several hours, and where each step required manual intervention,
> and where the bug was urgent. I got the bisection overnight, but was
> pretty useless then next day. ;-)
Yikes, I hate those moments.
> It is possible that Peter would want proof of this. ;-)
Yeah, figured it out while we were talking about it on IRC:
https://git.kernel.org/pub/scm/linux/kernel/git/peterz/queue.git/commit/?h=sched/core&id=fdf756f7127185eeffe00e918e66dfee797f3625
Ok, one down, gazillion more to go.
:-)
--
Regards/Gruss,
Boris.
https://people.kernel.org/tglx/notes-about-netiquette
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2022-09-30 16:28 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-09-29 9:26 INFO: task rcu_gp:3 blocked for more than 122 seconds Borislav Petkov
2022-09-29 15:37 ` Paul E. McKenney
2022-09-30 10:19 ` Borislav Petkov
2022-09-30 16:11 ` Paul E. McKenney
2022-09-30 16:28 ` Borislav Petkov
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).