[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <D98ED975-F617-4885-8D3F-DCFDC524E933@oracle.com>
Date: Mon, 24 Jul 2023 05:27:46 +0000
From: Sherry Yang <sherry.yang@...cle.com>
To: "dianders@...omium.org" <dianders@...omium.org>
CC: Harshit Mogalapalli <harshit.m.mogalapalli@...cle.com>,
George Kennedy <george.kennedy@...cle.com>,
"linux-scsi@...r.kernel.org" <linux-scsi@...r.kernel.org>,
"linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>
Subject: VM Boot Hangs with Commit "Revert "scsi: core: run queue if SCSI
device queue isn't ready and queue is idle"" on linux-5.4.y
Hi Douglas,
We observed linux-stable v5.4 VM boot hangs, but probably only 1 in thousands of boots (less than 10,000 boots). We started 16 VMs on a Bare Metal with loop reboots, I chose 10,000 boots as a threshold, and bisected it. After a painful bisection, I found the culprit commit 578c8f09c04b (“Revert scsi: core: run queue if SCSI device queue isnt ready and queue is idle”). This commit actually was merged to v5.8 the 1st time. It's a series of patch set (https://www.spinics.net/lists/linux-block/msg51866.html). Actually, in the 4-patch series, 2 of them have already been backported to linux-stable v5.4, but not at the same time:
1) ab3cee3762e5 (“blk-mq: In blk_mq_dispatch_rq_list() no budget is a reason to kick”) in tag v5.4.86
2) 578c8f09c04b (“Revert scsi: core: run queue if SCSI device queue isnt ready and queue is idle”) in tag v5.4.235, it’s backported as stable dependency for another commit
Signed-off-by: Douglas Anderson <dianders@...omium.org>
Reviewed-by: Ming Lei <ming.lei@...hat.com>
Acked-by: Martin K. Petersen <martin.petersen@...cle.com>
Signed-off-by: Jens Axboe <axboe@...nel.dk>
Stable-dep-of: c31e76bcc379 ("blk-mq: remove stale comment for blk_mq_sched_mark_restart_hctx”)
Signed-off-by: Sasha Levin <sashal@...nel.org>
And I tried backporting the other 2 patches to v5.4, the issue is still reproducible.
I tested multiple kernels, the issue is not reproducible within 10,000 boots in the following kernels:
1) Linux v5.9
2) Linux v5.4.249 + revert of 578c8f09c04b (“Revert scsi: core: run queue if SCSI device queue isnt ready and queue is idle”)
Not exactly sure how this commit is affecting linux-stable v5.4, but I suspect some prerequisite commits are missing which lead to boot hangs on linux-stable v5.4 but not on higher releases. Could you take a look at this issue and share your insight?
Here is the call trace:
[ 369.850681] INFO: task systemd-udevd:313 blocked for more than 122 seconds.
[ 369.852180] Not tainted 5.4.248-master.20230608.el8.dev.x86_64 #1
[ 369.853631] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 369.855406] systemd-udevd D 0 313 282 0x80004106
[ 369.856662] Call Trace:
[ 369.857276] __schedule+0x213/0x570
[ 369.858017] schedule+0x42/0xb0
[ 369.858699] io_schedule+0x45/0x70
[ 369.859671] wait_on_page_bit_common+0x131/0x380
[ 369.860884] ? find_get_entries+0x1a9/0x260
[ 369.862011] ? __filemap_set_wb_err+0x70/0x70
[ 369.863239] __lock_page+0x44/0x50
[ 369.864122] truncate_inode_pages_range+0x463/0x8a0
[ 369.865516] ? pagevec_lookup_range_tag+0x28/0x40
[ 369.866891] ? free_cpumask_var+0x9/0x10
[ 369.867909] ? mark_buffer_async_write+0x30/0x30
[ 369.869019] ? get_ksm_page+0xf6/0x210
[ 369.869936] ? free_cpumask_var+0x9/0x10
[ 369.871020] ? on_each_cpu_cond_mask+0xb1/0x130
[ 369.872062] truncate_inode_pages+0x15/0x20
[ 369.872739] __blkdev_put+0xa7/0x220
[ 369.873408] ? exit_mmap+0x121/0x1b0
[ 369.874092] blkdev_put+0x4e/0xe0
[ 369.874674] blkdev_close+0x26/0x30
[ 369.875281] __fput+0xcc/0x260
[ 369.875787] ____fput+0xe/0x10
[ 369.876298] task_work_run+0x8b/0xb0
[ 369.876892] do_exit+0x1ff/0x420
[ 369.877414] do_group_exit+0x3b/0xb0
[ 369.877989] get_signal+0x169/0x8b0
[ 369.878549] do_signal+0x2a/0x100
[ 369.879130] ? __vfs_read+0x29/0x40
[ 369.879713] ? vfs_read+0xaa/0x160
[ 369.880281] ? ksys_read+0x67/0xe0
[ 369.880858] prepare_exit_to_usermode+0x12b/0x1a0
[ 369.881614] do_syscall_64+0x8e/0x100
[ 369.882199] entry_SYSCALL_64_after_hwframe+0x5c/0xc1
[ 369.883056] RIP: 0033:0x7f6d466de8c2
[ 369.883664] Code: Bad RIP value.
[ 369.884217] RSP: 002b:00007fffffadb558 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 369.885433] RAX: fffffffffffffffc RBX: 000055b0b3c40ab0 RCX: 00007f6d466de8c2
[ 369.886552] RDX: 0000000000000200 RSI: 000055b0b3c40ad8 RDI: 000000000000000f
[ 369.887692] RBP: 000055b0b3c3dd20 R08: 000055b0b3c40ab0 R09: 0000000000000001
[ 369.888842] R10: 0000000000000001 R11: 0000000000000246 R12: 0000000000004000
[ 369.889963] R13: 0000000000000200 R14: 000055b0b3c3dd70 R15: 000055b0b3c40ac8
[ 369.891529] INFO: task systemd-udevd:315 blocked for more than 122 seconds.
[ 369.893182] Not tainted 5.4.248-master.20230608.el8.dev.x86_64 #1
[ 369.894557] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 369.896318] systemd-udevd D 0 315 282 0x80004106
[ 369.897596] Call Trace:
[ 369.898197] __schedule+0x213/0x570
[ 369.899068] schedule+0x42/0xb0
[ 369.899813] io_schedule+0x45/0x70
[ 369.900640] wait_on_page_bit_common+0x131/0x380
[ 369.901711] ? find_get_entries+0x1a9/0x260
[ 369.902688] ? __filemap_set_wb_err+0x70/0x70
[ 369.903710] __lock_page+0x44/0x50
[ 369.904504] truncate_inode_pages_range+0x463/0x8a0
[ 369.905648] ? find_get_pages_range_tag+0x7e/0x2d0
[ 369.906777] ? pagevec_lookup_range_tag+0x28/0x40
[ 369.907881] ? free_cpumask_var+0x9/0x10
[ 369.908816] ? mark_buffer_async_write+0x30/0x30
[ 369.909836] ? get_ksm_page+0xf0/0x210
[ 369.910738] ? __x64_sys_fsopen+0x160/0x160
[ 369.911743] ? free_cpumask_var+0x9/0x10
[ 369.912694] ? on_each_cpu_cond_mask+0xb1/0x130
[ 369.913763] truncate_inode_pages+0x15/0x20
[ 369.914747] __blkdev_put+0xa7/0x220
[ 369.915565] ? exit_mmap+0x121/0x1b0
[ 369.916407] blkdev_put+0x4e/0xe0
[ 369.917163] blkdev_close+0x26/0x30
[ 369.917960] __fput+0xcc/0x260
[ 369.918669] ____fput+0xe/0x10
[ 369.919362] task_work_run+0x8b/0xb0
[ 369.920185] do_exit+0x1ff/0x420
[ 369.920953] do_group_exit+0x3b/0xb0
[ 369.921776] get_signal+0x169/0x8b0
[ 369.922597] do_signal+0x2a/0x100
[ 369.923466] ? __vfs_read+0x29/0x40
[ 369.924424] ? vfs_read+0xaa/0x160
[ 369.925256] ? ksys_read+0x67/0xe0
[ 369.926085] prepare_exit_to_usermode+0x12b/0x1a0
[ 369.927204] do_syscall_64+0x8e/0x100
[ 369.928063] entry_SYSCALL_64_after_hwframe+0x5c/0xc1
[ 369.929238] RIP: 0033:0x7f6d466de8c2
[ 369.930056] Code: Bad RIP value.
[ 369.930799] RSP: 002b:00007fffffadb518 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 369.932496] RAX: fffffffffffffffc RBX: 000055b0b3c3dd30 RCX: 00007f6d466de8c2
[ 369.934119] RDX: 0000000000000040 RSI: 000055b0b3c3dd58 RDI: 000000000000000e
[ 369.935700] RBP: 000055b0b3c3dbe0 R08: 000055b0b3c3dd30 R09: 0000000000000001
[ 369.937300] R10: 0000000000000001 R11: 0000000000000246 R12: 00000002e6df0000
[ 369.938873] R13: 0000000000000040 R14: 000055b0b3c3dc30 R15: 000055b0b3c3dd48
Thanks,
Sherry
Powered by blists - more mailing lists