* again? - Write I/O queue hangup at random on recent Linus' kernels
@ 2022-10-05 19:43 Jaroslav Pulchart
2022-10-05 21:03 ` Bart Van Assche
0 siblings, 1 reply; 9+ messages in thread
From: Jaroslav Pulchart @ 2022-10-05 19:43 UTC (permalink / raw)
To: linux-block
Hello
I'm investigating a queue hangup issue of our databases running on the
5.19.y kernel.
I found "Write I/O queue hangup at random on recent Linus' kernels"
thread (https://www.spinics.net/lists/linux-bcache/msg10781.html)
already fixed some time. However our symptoms are similar:
[4321126.018688] INFO: task jbd2/vdc-8:57835 blocked for more than 122 seconds.
[4321126.019624] Tainted: G E 5.18.6-2.gdc.el8.x86_64 #1
[4321126.020380] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[4321126.021215] task:jbd2/vdc-8 state:D stack: 0 pid:57835
ppid: 2 flags:0x00004000
[4321126.022082] Call Trace:
[4321126.022437] <TASK>
[4321126.022796] __schedule+0x38c/0x7d0
[4321126.023243] ? wbt_exit+0x30/0x30
[4321126.023681] ? __wbt_done+0x30/0x30
[4321126.024119] schedule+0x41/0xa0
[4321126.024522] io_schedule+0x12/0x40
[4321126.024966] rq_qos_wait+0xb2/0x120
[4321126.025398] ? karma_partition+0x240/0x240
[4321126.025904] ? wbt_exit+0x30/0x30
[4321126.026319] wbt_wait+0x8e/0xc0
[4321126.026731] __rq_qos_throttle+0x20/0x30
[4321126.027196] blk_mq_submit_bio+0x3d2/0x620
[4321126.027682] __submit_bio+0xf1/0x180
[4321126.028118] submit_bio_noacct_nocheck+0x256/0x2a0
[4321126.028657] ? submit_bio_noacct+0x270/0x400
[4321126.029146] submit_bio+0x42/0xd0
[4321126.029553] submit_bh_wbc+0x117/0x140
[4321126.030019] jbd2_journal_commit_transaction+0x5c4/0x1ae0 [jbd2]
[4321126.030668] ? pick_next_task_fair+0x3e/0x3b0
[4321126.031167] ? finish_task_switch+0x8f/0x2c0
[4321126.031667] ? try_to_del_timer_sync+0x4d/0x80
[4321126.032171] kjournald2+0xc0/0x270 [jbd2]
[4321126.032653] ? add_wait_queue+0xa0/0xa0
[4321126.033114] ? commit_timeout+0x10/0x10 [jbd2]
[4321126.033621] kthread+0xd7/0x100
[4321126.034047] ? kthread_complete_and_exit+0x20/0x20
[4321126.034586] ret_from_fork+0x1f/0x30
[4321126.035031] </TASK>
[4321126.035340] INFO: task postmaster:58207 blocked for more than 122 seconds.
[4321126.036050] Tainted: G E 5.18.6-2.gdc.el8.x86_64 #1
[4321126.036734] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[4321126.037513] task:postmaster state:D stack: 0 pid:58207
ppid: 58204 flags:0x00004000
[4321126.038351] Call Trace:
[4321126.038695] <TASK>
[4321126.039003] __schedule+0x38c/0x7d0
[4321126.039417] ? wbt_exit+0x30/0x30
[4321126.039833] ? __wbt_done+0x30/0x30
[4321126.040248] schedule+0x41/0xa0
[4321126.040642] io_schedule+0x12/0x40
[4321126.041062] rq_qos_wait+0xb2/0x120
[4321126.041478] ? karma_partition+0x240/0x240
[4321126.041966] ? wbt_exit+0x30/0x30
[4321126.042369] wbt_wait+0x8e/0xc0
[4321126.042772] __rq_qos_throttle+0x20/0x30
[4321126.043220] blk_mq_submit_bio+0x3d2/0x620
[4321126.043690] ? ext4_put_io_end_defer+0x120/0x120 [ext4]
[4321126.044278] __submit_bio+0xf1/0x180
[4321126.044700] submit_bio_noacct_nocheck+0x256/0x2a0
[4321126.045227] ? submit_bio_noacct+0x270/0x400
[4321126.045709] submit_bio+0x42/0xd0
[4321126.046119] ext4_io_submit+0x20/0x40 [ext4]
[4321126.046616] ext4_bio_write_page+0x174/0x560 [ext4]
[4321126.047177] mpage_submit_page+0x4e/0x70 [ext4]
[4321126.047697] mpage_process_page_bufs+0xf8/0x110 [ext4]
[4321126.048270] mpage_prepare_extent_to_map+0x1e8/0x430 [ext4]
[4321126.048883] ext4_writepages+0x296/0xd30 [ext4]
[4321126.049397] ? find_get_pages_range_tag+0x1b2/0x250
[4321126.049950] ? __filemap_fdatawait_range+0x6c/0x120
[4321126.050476] do_writepages+0xd2/0x1b0
[4321126.050933] ? do_filp_open+0xc8/0x120
[4321126.051373] ? jbd2_complete_transaction+0x41/0x80 [jbd2]
[4321126.051981] filemap_fdatawrite_wbc+0x5b/0x80
[4321126.052470] file_write_and_wait_range+0x9c/0xe0
[4321126.053001] ext4_sync_file+0xf7/0x370 [ext4]
[4321126.053507] do_fsync+0x38/0x70
[4321126.053917] __x64_sys_fsync+0x10/0x20
[4321126.054357] do_syscall_64+0x37/0x80
[4321126.054802] entry_SYSCALL_64_after_hwframe+0x44/0xae
[4321126.055398] RIP: 0033:0x7f4166211ff5
[4321126.055850] RSP: 002b:00007fff08aead78 EFLAGS: 00000246 ORIG_RAX:
000000000000004a
[4321126.056654] RAX: ffffffffffffffda RBX: 0000000000002ebb RCX:
00007f4166211ff5
[4321126.057395] RDX: 00007f41549af0e0 RSI: 00000000028f2048 RDI:
00000000000001c1
[4321126.058135] RBP: 000000000a00000e R08: 00007fff08aeb22f R09:
0000000000000000
[4321126.058873] R10: 00007fff08ba9090 R11: 0000000000000246 R12:
00007fff08aeae30
[4321126.059602] R13: 0000000000000002 R14: 00007fff08aeadf0 R15:
0000000000d47d60
[4321126.060346] </TASK>
[4321126.060670] INFO: task postmaster:58208 blocked for more than 122 seconds.
[4321126.061380] Tainted: G E 5.18.6-2.gdc.el8.x86_64 #1
[4321126.062089] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[4321126.062882] task:postmaster state:D stack: 0 pid:58208
ppid: 58204 flags:0x00000000
[4321126.063717] Call Trace:
[4321126.064068] <TASK>
[4321126.064376] __schedule+0x38c/0x7d0
[4321126.064814] schedule+0x41/0xa0
[4321126.065220] rwsem_down_write_slowpath+0x2a2/0x5a0
[4321126.065770] ext4_buffered_write_iter+0x35/0xf0 [ext4]
[4321126.066355] ext4_file_write_iter+0x71/0x690 [ext4]
[4321126.066927] new_sync_write+0x109/0x190
[4321126.067388] vfs_write+0x1f2/0x270
[4321126.067825] ksys_pwrite64+0x61/0xa0
[4321126.068266] ? syscall_trace_enter.isra.20+0x11e/0x1a0
[4321126.068842] do_syscall_64+0x37/0x80
[4321126.069283] entry_SYSCALL_64_after_hwframe+0x44/0xae
[4321126.069853] RIP: 0033:0x7f4166212438
[4321126.070294] RSP: 002b:00007fff08ae9d98 EFLAGS: 00000246 ORIG_RAX:
0000000000000012
[4321126.071066] RAX: ffffffffffffffda RBX: 000000000004ad00 RCX:
00007f4166212438
[4321126.071805] RDX: 0000000000002000 RSI: 00007f3f882eef80 RDI:
0000000000000141
[4321126.072536] RBP: 0000000000002000 R08: 000000000a000010 R09:
0000000001b41540
[4321126.073275] R10: 000000000330e000 R11: 0000000000000246 R12:
0000000000002000
[4321126.074015] R13: 000000000330e000 R14: 00007f3f882eef80 R15:
00007f416690bd00
[4321126.074757] </TASK>
[4321126.075308] INFO: task kworker/u60:3:23019 blocked for more than
122 seconds.
[4321126.076054] Tainted: G E 5.18.6-2.gdc.el8.x86_64 #1
[4321126.076763] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[4321126.077562] task:kworker/u60:3 state:D stack: 0 pid:23019
ppid: 2 flags:0x00004000
[4321126.078412] Workqueue: writeback wb_workfn (flush-252:32)
[4321126.079026] Call Trace:
[4321126.079385] <TASK>
[4321126.079720] __schedule+0x38c/0x7d0
[4321126.080162] ? wbt_exit+0x30/0x30
[4321126.080584] ? __wbt_done+0x30/0x30
[4321126.081031] schedule+0x41/0xa0
[4321126.081443] io_schedule+0x12/0x40
[4321126.081890] rq_qos_wait+0xb2/0x120
[4321126.082329] ? karma_partition+0x240/0x240
[4321126.082828] ? wbt_exit+0x30/0x30
[4321126.083255] wbt_wait+0x8e/0xc0
[4321126.083669] __rq_qos_throttle+0x20/0x30
[4321126.084139] blk_mq_submit_bio+0x3d2/0x620
[4321126.084619] ? ext4_put_io_end_defer+0x120/0x120 [ext4]
[4321126.085233] __submit_bio+0xf1/0x180
[4321126.085680] submit_bio_noacct_nocheck+0x256/0x2a0
[4321126.086224] ? submit_bio_noacct+0x270/0x400
[4321126.086726] submit_bio+0x42/0xd0
[4321126.087140] ext4_io_submit+0x20/0x40 [ext4]
[4321126.087656] ext4_bio_write_page+0x174/0x560 [ext4]
[4321126.088211] mpage_submit_page+0x4e/0x70 [ext4]
[4321126.088738] mpage_process_page_bufs+0xf8/0x110 [ext4]
[4321126.089309] mpage_prepare_extent_to_map+0x1e8/0x430 [ext4]
[4321126.089927] ext4_writepages+0x296/0xd30 [ext4]
[4321126.090459] ? jbd2_write_access_granted.part.13+0x7f/0x90 [jbd2]
[4321126.091122] do_writepages+0xd2/0x1b0
[4321126.091558] ? __find_get_block+0x9e/0x2e0
[4321126.092044] __writeback_single_inode+0x41/0x350
[4321126.092564] writeback_sb_inodes+0x1ec/0x460
[4321126.093063] __writeback_inodes_wb+0x5f/0xc0
[4321126.093556] wb_writeback+0x231/0x2c0
[4321126.094008] wb_workfn+0x344/0x490
[4321126.094436] ? check_preempt_curr+0x3f/0x70
[4321126.094928] ? ttwu_do_wakeup+0x17/0x180
[4321126.095391] process_one_work+0x1c5/0x390
[4321126.095867] ? process_one_work+0x390/0x390
[4321126.096347] worker_thread+0x30/0x360
[4321126.096792] ? process_one_work+0x390/0x390
[4321126.097272] kthread+0xd7/0x100
[4321126.097669] ? kthread_complete_and_exit+0x20/0x20
[4321126.098193] ret_from_fork+0x1f/0x30
[4321126.098614] </TASK>
[4321126.098938] INFO: task postmaster:29387 blocked for more than 122 seconds.
[4321126.099643] Tainted: G E 5.18.6-2.gdc.el8.x86_64 #1
[4321126.100326] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[4321126.101101] task:postmaster state:D stack: 0 pid:29387
ppid: 58204 flags:0x00000000
[4321126.101936] Call Trace:
[4321126.102263] <TASK>
[4321126.102560] __schedule+0x38c/0x7d0
[4321126.102988] ? bit_wait+0x60/0x60
[4321126.103393] schedule+0x41/0xa0
[4321126.103792] io_schedule+0x12/0x40
[4321126.104197] bit_wait_io+0xd/0x60
[4321126.104600] __wait_on_bit+0x2a/0x90
[4321126.105034] out_of_line_wait_on_bit+0x91/0xb0
[4321126.105531] ? sched_autogroup_detach+0x20/0x20
[4321126.106044] do_get_write_access+0x27a/0x3d0 [jbd2]
[4321126.106587] jbd2_journal_get_write_access+0x4c/0x80 [jbd2]
[4321126.107191] __ext4_journal_get_write_access+0x81/0x190 [ext4]
[4321126.107833] ext4_reserve_inode_write+0x8f/0xc0 [ext4]
[4321126.108411] __ext4_mark_inode_dirty+0x59/0x220 [ext4]
[4321126.108994] ? __ext4_journal_start_sb+0xfd/0x110 [ext4]
[4321126.109576] ext4_dirty_inode+0x59/0x70 [ext4]
[4321126.110100] __mark_inode_dirty+0x137/0x380
[4321126.110579] generic_update_time+0xa0/0xc0
[4321126.111057] file_update_time+0xc8/0x110
[4321126.111516] ? generic_write_checks+0x2d/0x70
[4321126.112019] ext4_write_checks+0x20/0x30 [ext4]
[4321126.112539] ext4_buffered_write_iter+0x40/0xf0 [ext4]
[4321126.113118] ext4_file_write_iter+0x71/0x690 [ext4]
[4321126.113678] ? trigger_load_balance+0x111/0x370
[4321126.114182] ? scheduler_tick+0xbb/0x250
[4321126.114647] ? tick_sched_handle.isra.22+0x60/0x60
[4321126.115171] new_sync_write+0x109/0x190
[4321126.115617] vfs_write+0x1f2/0x270
[4321126.116039] ksys_pwrite64+0x61/0xa0
[4321126.116459] ? syscall_trace_enter.isra.20+0x11e/0x1a0
[4321126.117017] do_syscall_64+0x37/0x80
[4321126.117445] entry_SYSCALL_64_after_hwframe+0x44/0xae
[4321126.118000] RIP: 0033:0x7f4166212438
[4321126.118420] RSP: 002b:00007fff08aeb3c8 EFLAGS: 00000246 ORIG_RAX:
0000000000000012
[4321126.119181] RAX: ffffffffffffffda RBX: 00000000000018b8 RCX:
00007f4166212438
[4321126.119914] RDX: 0000000000002000 RSI: 00007f3f88262f80 RDI:
0000000000000095
[4321126.120644] RBP: 0000000000002000 R08: 000000000a000010 R09:
0000000000d47ce0
[4321126.121360] R10: 0000000004d48000 R11: 0000000000000246 R12:
0000000000002000
[4321126.122090] R13: 0000000004d48000 R14: 00007f3f88262f80 R15:
00007f416690bd00
[4321126.122828] </TASK>
[4321126.123169] INFO: task postmaster:29388 blocked for more than 122 seconds.
[4321126.124552] Tainted: G E 5.18.6-2.gdc.el8.x86_64 #1
[4321126.125333] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[4321126.126128] task:postmaster state:D stack: 0 pid:29388
ppid: 58204 flags:0x00000000
[4321126.126979] Call Trace:
[4321126.127317] <TASK>
[4321126.127645] __schedule+0x38c/0x7d0
[4321126.128070] ? fault_dirty_shared_page+0xce/0x100
[4321126.128594] ? bit_wait+0x60/0x60
[4321126.129016] schedule+0x41/0xa0
[4321126.129408] io_schedule+0x12/0x40
[4321126.129845] bit_wait_io+0xd/0x60
[4321126.130254] __wait_on_bit+0x2a/0x90
[4321126.130701] out_of_line_wait_on_bit+0x91/0xb0
[4321126.131206] ? sched_autogroup_detach+0x20/0x20
[4321126.131728] do_get_write_access+0x27a/0x3d0 [jbd2]
[4321126.132275] jbd2_journal_get_write_access+0x4c/0x80 [jbd2]
[4321126.132901] __ext4_journal_get_write_access+0x81/0x190 [ext4]
[4321126.133525] ext4_reserve_inode_write+0x8f/0xc0 [ext4]
[4321126.134114] __ext4_mark_inode_dirty+0x59/0x220 [ext4]
[4321126.134701] ? __ext4_journal_start_sb+0xfd/0x110 [ext4]
[4321126.135287] ext4_dirty_inode+0x59/0x70 [ext4]
[4321126.135826] __mark_inode_dirty+0x137/0x380
[4321126.136304] generic_update_time+0xa0/0xc0
[4321126.136798] file_update_time+0xc8/0x110
[4321126.137254] ? generic_write_checks+0x2d/0x70
[4321126.137771] ext4_write_checks+0x20/0x30 [ext4]
[4321126.138290] ext4_buffered_write_iter+0x40/0xf0 [ext4]
[4321126.138876] ext4_file_write_iter+0x71/0x690 [ext4]
[4321126.139423] ? __handle_mm_fault+0x791/0x810
[4321126.139931] new_sync_write+0x109/0x190
[4321126.140381] vfs_write+0x1f2/0x270
[4321126.140818] ksys_pwrite64+0x61/0xa0
[4321126.141252] ? syscall_trace_enter.isra.20+0x11e/0x1a0
[4321126.141850] do_syscall_64+0x37/0x80
[4321126.142283] entry_SYSCALL_64_after_hwframe+0x44/0xae
[4321126.142854] RIP: 0033:0x7f4166212438
[4321126.143282] RSP: 002b:00007fff08aeafb8 EFLAGS: 00000246 ORIG_RAX:
0000000000000012
[4321126.144056] RAX: ffffffffffffffda RBX: 0000000000005198 RCX:
00007f4166212438
[4321126.144809] RDX: 0000000000002000 RSI: 00007f3f881c2f80 RDI:
0000000000000181
[4321126.145525] RBP: 0000000000002000 R08: 000000000a000010 R09:
0000000000d47ce0
[4321126.146260] R10: 0000000032ace000 R11: 0000000000000246 R12:
0000000000002000
[4321126.147001] R13: 0000000032ace000 R14: 00007f3f881c2f80 R15:
00007f416690bd00
[4321126.147761] </TASK>
[4321126.148080] INFO: task postmaster:29398 blocked for more than 123 seconds.
[4321126.148815] Tainted: G E 5.18.6-2.gdc.el8.x86_64 #1
[4321126.149500] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[4321126.150304] task:postmaster state:D stack: 0 pid:29398
ppid: 58204 flags:0x00000000
[4321126.151154] Call Trace:
[4321126.151504] <TASK>
[4321126.151843] __schedule+0x38c/0x7d0
[4321126.152266] ? bit_wait+0x60/0x60
[4321126.152680] schedule+0x41/0xa0
[4321126.153075] io_schedule+0x12/0x40
[4321126.153485] bit_wait_io+0xd/0x60
[4321126.153917] __wait_on_bit+0x2a/0x90
[4321126.154341] out_of_line_wait_on_bit+0x91/0xb0
[4321126.154878] ? sched_autogroup_detach+0x20/0x20
[4321126.155381] do_get_write_access+0x27a/0x3d0 [jbd2]
[4321126.155950] jbd2_journal_get_write_access+0x4c/0x80 [jbd2]
[4321126.156546] __ext4_journal_get_write_access+0x81/0x190 [ext4]
[4321126.157197] ext4_reserve_inode_write+0x8f/0xc0 [ext4]
[4321126.157793] __ext4_mark_inode_dirty+0x59/0x220 [ext4]
[4321126.158367] ? __ext4_journal_start_sb+0xfd/0x110 [ext4]
[4321126.158987] ext4_dirty_inode+0x59/0x70 [ext4]
[4321126.159551] __mark_inode_dirty+0x137/0x380
[4321126.160058] generic_update_time+0xa0/0xc0
[4321126.160529] file_update_time+0xc8/0x110
[4321126.161009] ? generic_write_checks+0x2d/0x70
[4321126.161498] ext4_write_checks+0x20/0x30 [ext4]
[4321126.162049] ext4_buffered_write_iter+0x40/0xf0 [ext4]
[4321126.162615] ext4_file_write_iter+0x71/0x690 [ext4]
[4321126.163184] ? __handle_mm_fault+0x791/0x810
[4321126.163681] new_sync_write+0x109/0x190
[4321126.164145] vfs_write+0x1f2/0x270
[4321126.164559] ksys_pwrite64+0x61/0xa0
[4321126.165012] ? syscall_trace_enter.isra.20+0x11e/0x1a0
[4321126.165563] do_syscall_64+0x37/0x80
[4321126.166015] entry_SYSCALL_64_after_hwframe+0x44/0xae
[4321126.166561] RIP: 0033:0x7f4166212438
[4321126.167015] RSP: 002b:00007fff08aeafb8 EFLAGS: 00000246 ORIG_RAX:
0000000000000012
[4321126.167783] RAX: ffffffffffffffda RBX: 0000000000001fb8 RCX:
00007f4166212438
[4321126.168500] RDX: 0000000000002000 RSI: 00007f3f881d4f80 RDI:
0000000000000097
[4321126.169236] RBP: 0000000000002000 R08: 000000000a000010 R09:
0000000000d47ce0
[4321126.169980] R10: 0000000003e54000 R11: 0000000000000246 R12:
0000000000002000
[4321126.170706] R13: 0000000003e54000 R14: 00007f3f881d4f80 R15:
00007f416690bd00
[4321126.171440] </TASK>
[4321126.171774] INFO: task postmaster:29413 blocked for more than 123 seconds.
[4321126.172483] Tainted: G E 5.18.6-2.gdc.el8.x86_64 #1
[4321126.173210] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[4321126.174012] task:postmaster state:D stack: 0 pid:29413
ppid: 58204 flags:0x00000000
[4321126.174847] Call Trace:
[4321126.175187] <TASK>
[4321126.175496] __schedule+0x38c/0x7d0
[4321126.175936] ? fault_dirty_shared_page+0xce/0x100
[4321126.176453] ? bit_wait+0x60/0x60
[4321126.176874] schedule+0x41/0xa0
[4321126.177266] io_schedule+0x12/0x40
[4321126.177690] bit_wait_io+0xd/0x60
[4321126.178112] __wait_on_bit+0x2a/0x90
[4321126.178540] out_of_line_wait_on_bit+0x91/0xb0
[4321126.179066] ? sched_autogroup_detach+0x20/0x20
[4321126.179570] do_get_write_access+0x27a/0x3d0 [jbd2]
[4321126.180135] jbd2_journal_get_write_access+0x4c/0x80 [jbd2]
[4321126.180742] __ext4_journal_get_write_access+0x81/0x190 [ext4]
[4321126.181384] ext4_reserve_inode_write+0x8f/0xc0 [ext4]
[4321126.181983] __ext4_mark_inode_dirty+0x59/0x220 [ext4]
[4321126.182559] ? __ext4_journal_start_sb+0xfd/0x110 [ext4]
[4321126.183167] ext4_dirty_inode+0x59/0x70 [ext4]
[4321126.183697] __mark_inode_dirty+0x137/0x380
[4321126.184187] generic_update_time+0xa0/0xc0
[4321126.184671] file_update_time+0xc8/0x110
[4321126.185142] ? generic_write_checks+0x2d/0x70
[4321126.185648] ext4_write_checks+0x20/0x30 [ext4]
[4321126.186182] ext4_buffered_write_iter+0x40/0xf0 [ext4]
[4321126.186770] ext4_file_write_iter+0x71/0x690 [ext4]
[4321126.187328] ? __handle_mm_fault+0x791/0x810
[4321126.187835] new_sync_write+0x109/0x190
[4321126.188295] vfs_write+0x1f2/0x270
[4321126.188722] ksys_pwrite64+0x61/0xa0
[4321126.189164] ? syscall_trace_enter.isra.20+0x11e/0x1a0
[4321126.189732] do_syscall_64+0x37/0x80
[4321126.190180] entry_SYSCALL_64_after_hwframe+0x44/0xae
[4321126.190743] RIP: 0033:0x7f4166212438
[4321126.191180] RSP: 002b:00007fff08aeb3c8 EFLAGS: 00000246 ORIG_RAX:
0000000000000012
[4321126.191950] RAX: ffffffffffffffda RBX: 0000000000001b90 RCX:
00007f4166212438
[4321126.192679] RDX: 0000000000002000 RSI: 00007f3f88258f80 RDI:
0000000000000092
[4321126.193401] RBP: 0000000000002000 R08: 000000000a000010 R09:
0000000000d47ce0
[4321126.194138] R10: 0000000003398000 R11: 0000000000000246 R12:
0000000000002000
[4321126.194869] R13: 0000000003398000 R14: 00007f3f88258f80 R15:
00007f416690bd00
[4321126.195588] </TASK>
[4321126.195922] INFO: task postmaster:31309 blocked for more than 123 seconds.
[4321126.196646] Tainted: G E 5.18.6-2.gdc.el8.x86_64 #1
[4321126.197348] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[4321126.198151] task:postmaster state:D stack: 0 pid:31309
ppid: 58204 flags:0x00000004
[4321126.198988] Call Trace:
[4321126.199333] <TASK>
[4321126.199653] __schedule+0x38c/0x7d0
[4321126.200080] ? bit_wait+0x60/0x60
[4321126.200482] schedule+0x41/0xa0
[4321126.200891] io_schedule+0x12/0x40
[4321126.201305] bit_wait_io+0xd/0x60
[4321126.201722] __wait_on_bit+0x2a/0x90
[4321126.202162] out_of_line_wait_on_bit+0x91/0xb0
[4321126.202672] ? sched_autogroup_detach+0x20/0x20
[4321126.203188] do_get_write_access+0x27a/0x3d0 [jbd2]
[4321126.203739] jbd2_journal_get_write_access+0x4c/0x80 [jbd2]
[4321126.204349] __ext4_journal_get_write_access+0x81/0x190 [ext4]
[4321126.204997] ext4_reserve_inode_write+0x8f/0xc0 [ext4]
[4321126.205576] __ext4_mark_inode_dirty+0x59/0x220 [ext4]
[4321126.206169] ? __ext4_journal_start_sb+0xfd/0x110 [ext4]
[4321126.206768] ext4_dirty_inode+0x59/0x70 [ext4]
[4321126.207291] __mark_inode_dirty+0x137/0x380
[4321126.207787] generic_update_time+0xa0/0xc0
[4321126.208265] file_update_time+0xc8/0x110
[4321126.208730] ? generic_write_checks+0x2d/0x70
[4321126.209234] ext4_write_checks+0x20/0x30 [ext4]
[4321126.209772] ext4_buffered_write_iter+0x40/0xf0 [ext4]
[4321126.210350] ext4_file_write_iter+0x71/0x690 [ext4]
[4321126.210914] ? __handle_mm_fault+0x791/0x810
[4321126.211409] new_sync_write+0x109/0x190
[4321126.211875] vfs_write+0x1f2/0x270
[4321126.212301] ksys_pwrite64+0x61/0xa0
[4321126.212740] ? syscall_trace_enter.isra.20+0x11e/0x1a0
[4321126.213306] do_syscall_64+0x37/0x80
[4321126.213748] entry_SYSCALL_64_after_hwframe+0x44/0xae
[4321126.214301] RIP: 0033:0x7f4166212438
[4321126.214738] RSP: 002b:00007fff08aeaf28 EFLAGS: 00000246 ORIG_RAX:
0000000000000012
[4321126.215502] RAX: ffffffffffffffda RBX: 0000000000003fa8 RCX:
00007f4166212438
[4321126.216241] RDX: 0000000000002000 RSI: 00007f3f8821ef80 RDI:
000000000000012c
[4321126.216977] RBP: 0000000000002000 R08: 000000000a000010 R09:
0000000000d47ce0
[4321126.217710] R10: 000000001a368000 R11: 0000000000000246 R12:
0000000000002000
[4321126.218435] R13: 000000001a368000 R14: 00007f3f8821ef80 R15:
00007f416690bd00
[4321126.219166] </TASK>
[4321126.219482] INFO: task postmaster:31311 blocked for more than 123 seconds.
[4321126.220197] Tainted: G E 5.18.6-2.gdc.el8.x86_64 #1
[4321126.220899] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[4321126.221691] task:postmaster state:D stack: 0 pid:31311
ppid: 58204 flags:0x00000004
[4321126.222526] Call Trace:
[4321126.222886] <TASK>
[4321126.223198] __schedule+0x38c/0x7d0
[4321126.223620] schedule+0x41/0xa0
[4321126.224027] rwsem_down_write_slowpath+0x2a2/0x5a0
[4321126.224561] ext4_buffered_write_iter+0x35/0xf0 [ext4]
[4321126.225148] ext4_file_write_iter+0x71/0x690 [ext4]
[4321126.225706] ? __handle_mm_fault+0x791/0x810
[4321126.226195] new_sync_write+0x109/0x190
[4321126.226664] vfs_write+0x1f2/0x270
[4321126.227086] ksys_pwrite64+0x61/0xa0
[4321126.227517] ? syscall_trace_enter.isra.20+0x11e/0x1a0
[4321126.228091] do_syscall_64+0x37/0x80
[4321126.228537] entry_SYSCALL_64_after_hwframe+0x44/0xae
[4321126.229105] RIP: 0033:0x7f4166212438
[4321126.229542] RSP: 002b:00007fff08aeaf28 EFLAGS: 00000246 ORIG_RAX:
0000000000000012
[4321126.230319] RAX: ffffffffffffffda RBX: 0000000000002e60 RCX:
00007f4166212438
[4321126.231055] RDX: 0000000000002000 RSI: 00007f3f881b6f80 RDI:
00000000000000de
[4321126.231795] RBP: 0000000000002000 R08: 000000000a000010 R09:
0000000000d47ce0
[4321126.232519] R10: 000000003687a000 R11: 0000000000000246 R12:
0000000000002000
[4321126.233249] R13: 000000003687a000 R14: 00007f3f881b6f80 R15:
00007f416690bd00
[4321126.233984] </TASK>
Can you help to solve our issue?
--
Jaroslav Pulchart
Sr. Principal SW Engineer
GoodData
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: again? - Write I/O queue hangup at random on recent Linus' kernels
2022-10-05 19:43 again? - Write I/O queue hangup at random on recent Linus' kernels Jaroslav Pulchart
@ 2022-10-05 21:03 ` Bart Van Assche
2022-10-06 12:36 ` Jaroslav Pulchart
0 siblings, 1 reply; 9+ messages in thread
From: Bart Van Assche @ 2022-10-05 21:03 UTC (permalink / raw)
To: Jaroslav Pulchart, linux-block
On 10/5/22 12:43, Jaroslav Pulchart wrote:
> I'm investigating a queue hangup issue of our databases running on the
> 5.19.y kernel.
>
> I found "Write I/O queue hangup at random on recent Linus' kernels"
> thread (https://www.spinics.net/lists/linux-bcache/msg10781.html)
> already fixed some time.
That message mentions WBT (write back throttling). Is WBT enabled in
your kernel? If so, does disabling it help?
Thanks,
Bart.
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: again? - Write I/O queue hangup at random on recent Linus' kernels
2022-10-05 21:03 ` Bart Van Assche
@ 2022-10-06 12:36 ` Jaroslav Pulchart
2022-10-06 14:44 ` Ming Lei
2022-10-06 16:57 ` Bart Van Assche
0 siblings, 2 replies; 9+ messages in thread
From: Jaroslav Pulchart @ 2022-10-06 12:36 UTC (permalink / raw)
To: Bart Van Assche; +Cc: linux-block
Hello,
I apply the
echo 0 > /sys/block/vdc/queue/wbt_lat_usec
at the production servers. I expect it will disable wbt. Could you
please confirm that my expectation is correct?
The issue is happening once per ~14-30d after some random higher IOps
(~25-100k) peak so we need to wait....
Best,
st 5. 10. 2022 v 23:03 odesílatel Bart Van Assche <bvanassche@acm.org> napsal:
>
> On 10/5/22 12:43, Jaroslav Pulchart wrote:
> > I'm investigating a queue hangup issue of our databases running on the
> > 5.19.y kernel.
> >
> > I found "Write I/O queue hangup at random on recent Linus' kernels"
> > thread (https://www.spinics.net/lists/linux-bcache/msg10781.html)
> > already fixed some time.
> That message mentions WBT (write back throttling). Is WBT enabled in
> your kernel? If so, does disabling it help?
>
> Thanks,
>
> Bart.
--
Jaroslav Pulchart
Sr. Principal SW Engineer
GoodData
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: again? - Write I/O queue hangup at random on recent Linus' kernels
2022-10-06 12:36 ` Jaroslav Pulchart
@ 2022-10-06 14:44 ` Ming Lei
2022-10-06 16:57 ` Bart Van Assche
1 sibling, 0 replies; 9+ messages in thread
From: Ming Lei @ 2022-10-06 14:44 UTC (permalink / raw)
To: Jaroslav Pulchart; +Cc: Bart Van Assche, linux-block, Ming Lei
On Thu, Oct 6, 2022 at 8:37 PM Jaroslav Pulchart
<jaroslav.pulchart@gooddata.com> wrote:
>
> Hello,
>
> I apply the
> echo 0 > /sys/block/vdc/queue/wbt_lat_usec
> at the production servers. I expect it will disable wbt. Could you
> please confirm that my expectation is correct?
>
> The issue is happening once per ~14-30d after some random higher IOps
> (~25-100k) peak so we need to wait....
Next time when it is triggered, please collect blk-mq debugfs log via
the following
command after the hang is triggered
(cd /sys/kernel/debug/block/vdc && find . -type f -exec grep -aH . {} \;)
Also you can try all kinds of settings, such as reducing the
nr_tags/queue_depth to 4 or
smaller(1), for quick reproduction.
~14-30d is too long to verify any change.
Thanks,
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: again? - Write I/O queue hangup at random on recent Linus' kernels
2022-10-06 12:36 ` Jaroslav Pulchart
2022-10-06 14:44 ` Ming Lei
@ 2022-10-06 16:57 ` Bart Van Assche
2022-10-11 15:15 ` Jaroslav Pulchart
1 sibling, 1 reply; 9+ messages in thread
From: Bart Van Assche @ 2022-10-06 16:57 UTC (permalink / raw)
To: Jaroslav Pulchart; +Cc: linux-block
On 10/6/22 05:36, Jaroslav Pulchart wrote:
> I apply the
> echo 0 > /sys/block/vdc/queue/wbt_lat_usec
> at the production servers. I expect it will disable wbt. Could you
> please confirm that my expectation is correct?
Hi Jaroslav,
I have no experience with WBT. But what I found in the documentation seems
to confirm that the above command is sufficient to disable WBT:
What: /sys/block/<disk>/queue/wbt_lat_usec
Date: November 2016
Contact: linux-block@vger.kernel.org
Description:
[RW] If the device is registered for writeback throttling, then
this file shows the target minimum read latency. If this latency
is exceeded in a given window of time (see wb_window_usec), then
the writeback throttling will start scaling back writes. Writing
a value of '0' to this file disables the feature. Writing a
value of '-1' to this file resets the value to the default
setting.
Best regards,
Bart.
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: again? - Write I/O queue hangup at random on recent Linus' kernels
2022-10-06 16:57 ` Bart Van Assche
@ 2022-10-11 15:15 ` Jaroslav Pulchart
2022-10-11 16:53 ` Bart Van Assche
` (2 more replies)
0 siblings, 3 replies; 9+ messages in thread
From: Jaroslav Pulchart @ 2022-10-11 15:15 UTC (permalink / raw)
To: Bart Van Assche, linux-block; +Cc: Igor Raits, Daniel Secik, David Krupicka
[-- Attachment #1: Type: text/plain, Size: 1483 bytes --]
Hello,
we disabled the wbt, issue is happening much sooner. The logs are attached
1/ "dmesg-20221011.log" form kernel messages
2/ "command.logs" from execution of
(cd /sys/kernel/debug/block/vdc && find . -type f -exec grep -aH . {} \;)
Best regards,
Jaroslav Pulchart
čt 6. 10. 2022 v 18:57 odesílatel Bart Van Assche <bvanassche@acm.org> napsal:
>
> On 10/6/22 05:36, Jaroslav Pulchart wrote:
> > I apply the
> > echo 0 > /sys/block/vdc/queue/wbt_lat_usec
> > at the production servers. I expect it will disable wbt. Could you
> > please confirm that my expectation is correct?
>
> Hi Jaroslav,
>
> I have no experience with WBT. But what I found in the documentation seems
> to confirm that the above command is sufficient to disable WBT:
>
> What: /sys/block/<disk>/queue/wbt_lat_usec
> Date: November 2016
> Contact: linux-block@vger.kernel.org
> Description:
> [RW] If the device is registered for writeback throttling, then
> this file shows the target minimum read latency. If this latency
> is exceeded in a given window of time (see wb_window_usec), then
> the writeback throttling will start scaling back writes. Writing
> a value of '0' to this file disables the feature. Writing a
> value of '-1' to this file resets the value to the default
> setting.
>
>
> Best regards,
>
> Bart.
[-- Attachment #2: dmesg-20221011.log --]
[-- Type: text/x-log, Size: 19081 bytes --]
[27157.363315] INFO: task jbd2/vdc-8:5942 blocked for more than 122 seconds.
[27157.363938] Tainted: G E 5.19.12-1.gdc.el8.x86_64 #1
[27157.364394] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27157.364918] task:jbd2/vdc-8 state:D stack: 0 pid: 5942 ppid: 2 flags:0x00004000
[27157.365483] Call Trace:
[27157.365650] <TASK>
[27157.365800] __schedule+0x392/0x7e0
[27157.366042] ? bit_wait+0x60/0x60
[27157.366275] schedule+0x50/0xc0
[27157.366489] io_schedule+0x12/0x40
[27157.366719] bit_wait_io+0xd/0x60
[27157.366952] __wait_on_bit+0x2a/0x90
[27157.367191] out_of_line_wait_on_bit+0x91/0xb0
[27157.367497] ? sched_autogroup_detach+0x20/0x20
[27157.367804] jbd2_journal_commit_transaction+0x10fe/0x1a00 [jbd2]
[27157.368215] ? finish_task_switch+0x86/0x2c0
[27157.368512] ? try_to_del_timer_sync+0x4d/0x80
[27157.368815] kjournald2+0xc0/0x280 [jbd2]
[27157.369106] ? add_wait_queue_priority+0xa0/0xa0
[27157.369418] ? commit_timeout+0x10/0x10 [jbd2]
[27157.369722] kthread+0xd7/0x100
[27157.369934] ? kthread_complete_and_exit+0x20/0x20
[27157.370257] ret_from_fork+0x1f/0x30
[27157.370498] </TASK>
[27157.370656] INFO: task postmaster:7201 blocked for more than 122 seconds.
[27157.371110] Tainted: G E 5.19.12-1.gdc.el8.x86_64 #1
[27157.371560] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27157.372077] task:postmaster state:D stack: 0 pid: 7201 ppid: 7199 flags:0x00000000
[27157.372625] Call Trace:
[27157.372963] <TASK>
[27157.373240] __schedule+0x392/0x7e0
[27157.373608] schedule+0x50/0xc0
[27157.373944] jbd2_log_wait_commit+0xa3/0x110 [jbd2]
[27157.374409] ? add_wait_queue_priority+0xa0/0xa0
[27157.374830] ext4_fc_commit+0x297/0x860 [ext4]
[27157.375288] ? filemap_fdatawrite_wbc+0x19/0x80
[27157.375701] ? __filemap_fdatawrite_range+0x54/0x80
[27157.376134] ? file_check_and_advance_wb_err+0x2e/0xd0
[27157.376588] ext4_sync_file+0x2ff/0x370 [ext4]
[27157.377015] do_fsync+0x38/0x70
[27157.377342] __x64_sys_fsync+0x10/0x20
[27157.377698] do_syscall_64+0x37/0x90
[27157.378041] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[27157.378486] RIP: 0033:0x7f3e83011ff5
[27157.378831] RSP: 002b:00007fff70b02dc8 EFLAGS: 00000246 ORIG_RAX: 000000000000004a
[27157.379459] RAX: ffffffffffffffda RBX: 000000000000022c RCX: 00007f3e83011ff5
[27157.380031] RDX: 0000000000000002 RSI: 00007fff70b02ed0 RDI: 000000000000022c
[27157.380625] RBP: 00007fff70b02ed0 R08: 0000000000000006 R09: 0000000000000030
[27157.381203] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
[27157.381780] R13: 0000000000000000 R14: 000000000000000f R15: 0000000000000001
[27157.382360] </TASK>
[27157.382612] INFO: task postmaster:7202 blocked for more than 122 seconds.
[27157.383167] Tainted: G E 5.19.12-1.gdc.el8.x86_64 #1
[27157.383722] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27157.384352] task:postmaster state:D stack: 0 pid: 7202 ppid: 7199 flags:0x00000000
[27157.384998] Call Trace:
[27157.385288] <TASK>
[27157.385542] __schedule+0x392/0x7e0
[27157.385887] schedule+0x50/0xc0
[27157.386215] rwsem_down_write_slowpath+0x3f5/0x6f0
[27157.386649] ? pick_next_task+0x4d/0x910
[27157.387022] ext4_buffered_write_iter+0x35/0xf0 [ext4]
[27157.387506] ext4_file_write_iter+0x71/0x690 [ext4]
[27157.387959] new_sync_write+0x106/0x190
[27157.388343] vfs_write+0x1f6/0x280
[27157.388678] ksys_pwrite64+0x65/0xa0
[27157.389027] ? syscall_trace_enter.isra.19+0x126/0x1a0
[27157.389489] do_syscall_64+0x37/0x90
[27157.389840] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[27157.390297] RIP: 0033:0x7f3e83012438
[27157.390641] RSP: 002b:00007fff70b02398 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[27157.391260] RAX: ffffffffffffffda RBX: 000000000001a668 RCX: 00007f3e83012438
[27157.391834] RDX: 0000000000002000 RSI: 00007f3de9daef80 RDI: 0000000000000034
[27157.392419] RBP: 0000000000002000 R08: 000000000a000010 R09: 0000000000d47ce0
[27157.393000] R10: 0000000034b6e000 R11: 0000000000000246 R12: 0000000000002000
[27157.393585] R13: 0000000034b6e000 R14: 00007f3de9daef80 R15: 00007f3e837f0d00
[27157.394156] </TASK>
[27157.394424] INFO: task postmaster:7203 blocked for more than 122 seconds.
[27157.394973] Tainted: G E 5.19.12-1.gdc.el8.x86_64 #1
[27157.395541] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27157.396158] task:postmaster state:D stack: 0 pid: 7203 ppid: 7199 flags:0x00000000
[27157.396819] Call Trace:
[27157.397102] <TASK>
[27157.397376] __schedule+0x392/0x7e0
[27157.397730] ? bit_wait+0x60/0x60
[27157.398067] schedule+0x50/0xc0
[27157.398406] io_schedule+0x12/0x40
[27157.398753] bit_wait_io+0xd/0x60
[27157.399089] __wait_on_bit+0x2a/0x90
[27157.399460] out_of_line_wait_on_bit+0x91/0xb0
[27157.399871] ? sched_autogroup_detach+0x20/0x20
[27157.400296] do_get_write_access+0x27e/0x3d0 [jbd2]
[27157.400739] jbd2_journal_get_write_access+0x4c/0x80 [jbd2]
[27157.401217] __ext4_journal_get_write_access+0x85/0x1a0 [ext4]
[27157.401738] ext4_reserve_inode_write+0x93/0xc0 [ext4]
[27157.402204] __ext4_mark_inode_dirty+0x59/0x220 [ext4]
[27157.402676] ? __ext4_journal_start_sb+0x105/0x120 [ext4]
[27157.403160] ext4_dirty_inode+0x5d/0x80 [ext4]
[27157.403600] __mark_inode_dirty+0x137/0x380
[27157.403992] generic_update_time+0xa0/0xd0
[27157.404392] file_update_time+0xcc/0x120
[27157.404765] ? generic_write_checks+0x2d/0x70
[27157.405158] ext4_write_checks+0x20/0x40 [ext4]
[27157.405607] ext4_buffered_write_iter+0x40/0xf0 [ext4]
[27157.406088] ext4_file_write_iter+0x71/0x690 [ext4]
[27157.406547] new_sync_write+0x106/0x190
[27157.406915] vfs_write+0x1f6/0x280
[27157.407260] ksys_pwrite64+0x65/0xa0
[27157.407602] ? syscall_trace_enter.isra.19+0x126/0x1a0
[27157.408046] do_syscall_64+0x37/0x90
[27157.408403] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[27157.408841] RIP: 0033:0x7f3e83012438
[27157.409182] RSP: 002b:00007fff70b03878 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[27157.409797] RAX: ffffffffffffffda RBX: 0000000000caa000 RCX: 00007f3e83012438
[27157.410384] RDX: 00000000002d4000 RSI: 00007f39d81f8000 RDI: 0000000000000004
[27157.410956] RBP: 00007f39d81f8000 R08: 00000000002d4000 R09: 0000000002f16b64
[27157.411551] R10: 0000000000caa000 R11: 0000000000000246 R12: 00007f3e837f0d00
[27157.412124] R13: 000038d6e7f7e000 R14: 00000000000007be R15: 00000000002d4000
[27157.412717] </TASK>
[27157.413164] INFO: task postmaster:490689 blocked for more than 122 seconds.
[27157.413752] Tainted: G E 5.19.12-1.gdc.el8.x86_64 #1
[27157.414310] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27157.414927] task:postmaster state:D stack: 0 pid:490689 ppid: 7199 flags:0x00000000
[27157.415600] Call Trace:
[27157.415883] <TASK>
[27157.416150] __schedule+0x392/0x7e0
[27157.416513] ? bit_wait+0x60/0x60
[27157.416845] schedule+0x50/0xc0
[27157.417161] io_schedule+0x12/0x40
[27157.417511] bit_wait_io+0xd/0x60
[27157.417840] __wait_on_bit+0x2a/0x90
[27157.418181] out_of_line_wait_on_bit+0x91/0xb0
[27157.418597] ? sched_autogroup_detach+0x20/0x20
[27157.419022] do_get_write_access+0x27e/0x3d0 [jbd2]
[27157.419467] jbd2_journal_get_write_access+0x4c/0x80 [jbd2]
[27157.419943] __ext4_journal_get_write_access+0x85/0x1a0 [ext4]
[27157.420455] ext4_reserve_inode_write+0x93/0xc0 [ext4]
[27157.420921] __ext4_mark_inode_dirty+0x59/0x220 [ext4]
[27157.421391] ? __ext4_journal_start_sb+0x105/0x120 [ext4]
[27157.421867] ext4_dirty_inode+0x5d/0x80 [ext4]
[27157.422297] __mark_inode_dirty+0x137/0x380
[27157.422695] generic_update_time+0xa0/0xd0
[27157.423070] file_update_time+0xcc/0x120
[27157.423446] ? generic_write_checks+0x2d/0x70
[27157.423843] ext4_write_checks+0x20/0x40 [ext4]
[27157.424270] ext4_buffered_write_iter+0x40/0xf0 [ext4]
[27157.424745] ext4_file_write_iter+0x71/0x690 [ext4]
[27157.425186] new_sync_write+0x106/0x190
[27157.425563] vfs_write+0x1f6/0x280
[27157.425899] ksys_pwrite64+0x65/0xa0
[27157.426240] ? syscall_trace_enter.isra.19+0x126/0x1a0
[27157.426703] do_syscall_64+0x37/0x90
[27157.427045] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[27157.427490] RIP: 0033:0x7f3e83012438
[27157.427837] RSP: 002b:00007fff70b02f68 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[27157.428443] RAX: ffffffffffffffda RBX: 0000000000000578 RCX: 00007f3e83012438
[27157.429013] RDX: 0000000000002000 RSI: 00007f3e45876f80 RDI: 0000000000000015
[27157.429597] RBP: 0000000000002000 R08: 000000000a000010 R09: 0000000000d47ce0
[27157.430169] R10: 0000000028ec6000 R11: 0000000000000246 R12: 0000000000002000
[27157.430757] R13: 0000000028ec6000 R14: 00007f3e45876f80 R15: 00007f3e837f0d00
[27157.431337] </TASK>
[27157.431602] INFO: task kworker/u60:1:490807 blocked for more than 122 seconds.
[27157.432177] Tainted: G E 5.19.12-1.gdc.el8.x86_64 #1
[27157.432746] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27157.433370] task:kworker/u60:1 state:D stack: 0 pid:490807 ppid: 2 flags:0x00004000
[27157.434040] Workqueue: writeback wb_workfn (flush-252:32)
[27157.434514] Call Trace:
[27157.434795] <TASK>
[27157.435048] __schedule+0x392/0x7e0
[27157.435398] ? bit_wait+0x60/0x60
[27157.435736] schedule+0x50/0xc0
[27157.436049] io_schedule+0x12/0x40
[27157.436390] bit_wait_io+0xd/0x60
[27157.436729] __wait_on_bit+0x2a/0x90
[27157.437070] ? mb_mark_used+0x29c/0x320 [ext4]
[27157.437496] out_of_line_wait_on_bit+0x91/0xb0
[27157.437898] ? sched_autogroup_detach+0x20/0x20
[27157.438312] do_get_write_access+0x27e/0x3d0 [jbd2]
[27157.438754] jbd2_journal_get_write_access+0x4c/0x80 [jbd2]
[27157.439226] __ext4_journal_get_write_access+0x85/0x1a0 [ext4]
[27157.439751] ext4_mb_mark_diskspace_used+0xa9/0x3b0 [ext4]
[27157.440238] ext4_mb_new_blocks+0x46a/0xf10 [ext4]
[27157.440700] ? ext4_find_extent+0x160/0x370 [ext4]
[27157.441133] ext4_ext_map_blocks+0x7ac/0xc80 [ext4]
[27157.441583] ? __pagevec_release+0x1b/0x30
[27157.441967] ext4_map_blocks+0x165/0x590 [ext4]
[27157.442398] ext4_writepages+0x789/0xd30 [ext4]
[27157.442831] do_writepages+0xd2/0x1b0
[27157.443183] __writeback_single_inode+0x41/0x360
[27157.443601] writeback_sb_inodes+0x1f0/0x460
[27157.443992] __writeback_inodes_wb+0x5f/0xd0
[27157.444388] wb_writeback+0x235/0x2d0
[27157.444748] wb_workfn+0x312/0x4a0
[27157.445077] ? put_prev_task_fair+0x1b/0x40
[27157.445467] ? cpumask_next+0x1f/0x30
[27157.445821] ? __update_idle_core+0x71/0xb0
[27157.446197] process_one_work+0x1c5/0x390
[27157.446575] worker_thread+0x30/0x360
[27157.446925] ? process_one_work+0x390/0x390
[27157.447314] kthread+0xd7/0x100
[27157.447626] ? kthread_complete_and_exit+0x20/0x20
[27157.448044] ret_from_fork+0x1f/0x30
[27157.448393] </TASK>
[27157.448644] INFO: task postmaster:494230 blocked for more than 122 seconds.
[27157.449195] Tainted: G E 5.19.12-1.gdc.el8.x86_64 #1
[27157.449771] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27157.450385] task:postmaster state:D stack: 0 pid:494230 ppid: 7199 flags:0x00000000
[27157.451043] Call Trace:
[27157.451337] <TASK>
[27157.451584] __schedule+0x392/0x7e0
[27157.451922] ? bit_wait+0x60/0x60
[27157.452238] schedule+0x50/0xc0
[27157.452553] io_schedule+0x12/0x40
[27157.452883] bit_wait_io+0xd/0x60
[27157.453194] __wait_on_bit+0x2a/0x90
[27157.453534] out_of_line_wait_on_bit+0x91/0xb0
[27157.453930] ? sched_autogroup_detach+0x20/0x20
[27157.454332] do_get_write_access+0x27e/0x3d0 [jbd2]
[27157.454762] jbd2_journal_get_write_access+0x4c/0x80 [jbd2]
[27157.455220] __ext4_journal_get_write_access+0x85/0x1a0 [ext4]
[27157.455729] ext4_reserve_inode_write+0x93/0xc0 [ext4]
[27157.456184] __ext4_mark_inode_dirty+0x59/0x220 [ext4]
[27157.456643] ? __ext4_journal_start_sb+0x105/0x120 [ext4]
[27157.457108] ext4_dirty_inode+0x5d/0x80 [ext4]
[27157.457524] __mark_inode_dirty+0x137/0x380
[27157.457927] generic_write_end+0xe9/0x120
[27157.458313] generic_perform_write+0x139/0x1d0
[27157.458714] ? generic_write_checks+0x2d/0x70
[27157.459098] ext4_buffered_write_iter+0x6f/0xf0 [ext4]
[27157.459556] ext4_file_write_iter+0x71/0x690 [ext4]
[27157.460003] ? blk_mq_start_stopped_hw_queues+0x7a/0xb0
[27157.460461] new_sync_write+0x106/0x190
[27157.460825] vfs_write+0x1f6/0x280
[27157.461148] ksys_pwrite64+0x65/0xa0
[27157.461492] ? syscall_trace_enter.isra.19+0x126/0x1a0
[27157.461935] do_syscall_64+0x37/0x90
[27157.462277] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[27157.462706] RIP: 0033:0x7f3e83012438
[27157.463039] RSP: 002b:00007fff70b01318 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[27157.463633] RAX: ffffffffffffffda RBX: 0000000000000ee0 RCX: 00007f3e83012438
[27157.464207] RDX: 0000000000002000 RSI: 0000000001263400 RDI: 000000000000002d
[27157.464785] RBP: 0000000000002000 R08: 000000000a000001 R09: 0000000000000001
[27157.465373] R10: 0000000013b12000 R11: 0000000000000246 R12: 0000000000002000
[27157.465943] R13: 0000000013b12000 R14: 0000000001263400 R15: 00007f3e837f0d00
[27157.466512] </TASK>
[27157.466785] INFO: task postmaster:494251 blocked for more than 122 seconds.
[27157.467951] Tainted: G E 5.19.12-1.gdc.el8.x86_64 #1
[27157.468769] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27157.469388] task:postmaster state:D stack: 0 pid:494251 ppid: 7199 flags:0x00000000
[27157.470086] Call Trace:
[27157.470373] <TASK>
[27157.470627] __schedule+0x392/0x7e0
[27157.470979] ? bit_wait+0x60/0x60
[27157.471321] schedule+0x50/0xc0
[27157.471636] io_schedule+0x12/0x40
[27157.471980] bit_wait_io+0xd/0x60
[27157.472317] __wait_on_bit+0x2a/0x90
[27157.472658] out_of_line_wait_on_bit+0x91/0xb0
[27157.473066] ? sched_autogroup_detach+0x20/0x20
[27157.473479] do_get_write_access+0x27e/0x3d0 [jbd2]
[27157.473919] jbd2_journal_get_write_access+0x4c/0x80 [jbd2]
[27157.474403] __ext4_journal_get_write_access+0x85/0x1a0 [ext4]
[27157.474917] ext4_reserve_inode_write+0x93/0xc0 [ext4]
[27157.475386] __ext4_mark_inode_dirty+0x59/0x220 [ext4]
[27157.475851] ? __ext4_journal_start_sb+0x105/0x120 [ext4]
[27157.476337] ext4_dirty_inode+0x5d/0x80 [ext4]
[27157.476760] __mark_inode_dirty+0x137/0x380
[27157.477149] generic_write_end+0xe9/0x120
[27157.477525] generic_perform_write+0x139/0x1d0
[27157.477935] ? generic_write_checks+0x2d/0x70
[27157.478338] ext4_buffered_write_iter+0x6f/0xf0 [ext4]
[27157.478798] ext4_file_write_iter+0x71/0x690 [ext4]
[27157.479243] ? set_next_entity+0xe2/0x180
[27157.479623] new_sync_write+0x106/0x190
[27157.479992] vfs_write+0x1f6/0x280
[27157.480336] ksys_pwrite64+0x65/0xa0
[27157.480677] ? syscall_trace_enter.isra.19+0x126/0x1a0
[27157.481128] do_syscall_64+0x37/0x90
[27157.481480] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[27157.481923] RIP: 0033:0x7f3e83012438
[27157.482273] RSP: 002b:00007fff70b03488 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[27157.482871] RAX: ffffffffffffffda RBX: 00000000000010d8 RCX: 00007f3e83012438
[27157.483449] RDX: 0000000000002000 RSI: 000000000128e828 RDI: 0000000000000008
[27157.484033] RBP: 0000000000002000 R08: 000000000a000009 R09: 0000000000d47ce0
[27157.484611] R10: 000000002be82000 R11: 0000000000000246 R12: 0000000000002000
[27157.485193] R13: 000000002be82000 R14: 000000000128e828 R15: 00007f3e837f0d00
[27157.485778] </TASK>
[27157.486050] INFO: task kworker/u60:6:509050 blocked for more than 123 seconds.
[27157.486633] Tainted: G E 5.19.12-1.gdc.el8.x86_64 #1
[27157.487186] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27157.487809] task:kworker/u60:6 state:D stack: 0 pid:509050 ppid: 2 flags:0x00004000
[27157.488481] Workqueue: ext4-rsv-conversion ext4_end_io_rsv_work [ext4]
[27157.489049] Call Trace:
[27157.489337] <TASK>
[27157.489592] __schedule+0x392/0x7e0
[27157.489934] ? bit_wait+0x60/0x60
[27157.490268] schedule+0x50/0xc0
[27157.490581] io_schedule+0x12/0x40
[27157.490912] bit_wait_io+0xd/0x60
[27157.491235] __wait_on_bit+0x2a/0x90
[27157.491585] out_of_line_wait_on_bit+0x91/0xb0
[27157.491984] ? sched_autogroup_detach+0x20/0x20
[27157.492413] do_get_write_access+0x27e/0x3d0 [jbd2]
[27157.492852] jbd2_journal_get_write_access+0x4c/0x80 [jbd2]
[27157.493345] __ext4_journal_get_write_access+0x85/0x1a0 [ext4]
[27157.493850] ? __find_get_block+0x9e/0x2e0
[27157.494237] ext4_ext_get_access.isra.35+0x30/0x50 [ext4]
[27157.494724] ext4_ext_handle_unwritten_extents+0xca/0xa00 [ext4]
[27157.495246] ? __read_extent_tree_block+0x80/0x170 [ext4]
[27157.495730] ? ext4_find_extent+0x160/0x370 [ext4]
[27157.496172] ext4_ext_map_blocks+0x465/0xc80 [ext4]
[27157.496624] ? __wake_up_common_lock+0x87/0xc0
[27157.497028] ext4_map_blocks+0x165/0x590 [ext4]
[27157.497459] ext4_convert_unwritten_extents+0x12f/0x260 [ext4]
[27157.497964] ext4_convert_unwritten_io_end_vec+0x5f/0xe0 [ext4]
[27157.498482] ext4_end_io_rsv_work+0xe6/0x190 [ext4]
[27157.498933] process_one_work+0x1c5/0x390
[27157.499321] ? process_one_work+0x390/0x390
[27157.499706] worker_thread+0x30/0x360
[27157.500054] ? process_one_work+0x390/0x390
[27157.500446] kthread+0xd7/0x100
[27157.500765] ? kthread_complete_and_exit+0x20/0x20
[27157.501197] ret_from_fork+0x1f/0x30
[27157.501551] </TASK>
[27157.501811] INFO: task postmaster:509340 blocked for more than 123 seconds.
[27157.502382] Tainted: G E 5.19.12-1.gdc.el8.x86_64 #1
[27157.502931] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27157.503558] task:postmaster state:D stack: 0 pid:509340 ppid: 7199 flags:0x00000000
[27157.504221] Call Trace:
[27157.504503] <TASK>
[27157.504762] __schedule+0x392/0x7e0
[27157.505109] ? page_add_file_rmap+0xa6/0x2e0
[27157.505507] schedule+0x50/0xc0
[27157.505833] rwsem_down_write_slowpath+0x3f5/0x6f0
[27157.506269] ext4_buffered_write_iter+0x35/0xf0 [ext4]
[27157.506744] ext4_file_write_iter+0x71/0x690 [ext4]
[27157.507189] ? __handle_mm_fault+0x5f1/0x810
[27157.507587] new_sync_write+0x106/0x190
[27157.507946] vfs_write+0x1f6/0x280
[27157.508292] ksys_pwrite64+0x65/0xa0
[27157.508627] ? syscall_trace_enter.isra.19+0x126/0x1a0
[27157.509064] do_syscall_64+0x37/0x90
[27157.509412] entry_SYSCALL_64_after_hwframe+0x63/0xcd
[27157.509844] RIP: 0033:0x7f3e83012438
[27157.510187] RSP: 002b:00007fff70b01a68 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[27157.510790] RAX: ffffffffffffffda RBX: 00000000000010d8 RCX: 00007f3e83012438
[27157.511369] RDX: 0000000000002000 RSI: 00007f3de9d80f80 RDI: 0000000000000055
[27157.511935] RBP: 0000000000002000 R08: 000000000a000010 R09: 0000000000d47ce0
[27157.512516] R10: 00000000331d6000 R11: 0000000000000246 R12: 0000000000002000
[27157.513085] R13: 00000000331d6000 R14: 00007f3de9d80f80 R15: 00007f3e837f0d00
[27157.513659] </TASK>
[-- Attachment #3: command.logs --]
[-- Type: application/octet-stream, Size: 42345 bytes --]
./rqos/wbt/wb_background:0
./rqos/wbt/wb_normal:0
./rqos/wbt/unknown_cnt:0
./rqos/wbt/min_lat_nsec:0
./rqos/wbt/inflight:0: inflight 0
./rqos/wbt/inflight:1: inflight 0
./rqos/wbt/inflight:2: inflight 0
./rqos/wbt/id:0
./rqos/wbt/enabled:2
./rqos/wbt/curr_win_nsec:0
./hctx29/type:default
./hctx29/dispatch_busy:0
./hctx29/active:0
./hctx29/run:6637
./hctx29/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx29/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx29/tags:nr_tags=256
./hctx29/tags:nr_reserved_tags=0
./hctx29/tags:active_queues=0
./hctx29/tags:bitmap_tags:
./hctx29/tags:depth=256
./hctx29/tags:busy=0
./hctx29/tags:cleared=141
./hctx29/tags:bits_per_word=64
./hctx29/tags:map_nr=4
./hctx29/tags:alloc_hint={58, 93, 164, 34, 54, 35, 112, 49, 132, 149, 165, 60, 54, 5, 148, 200, 174, 139, 53, 29, 213, 85, 150, 62, 72, 124, 57, 235, 128, 41}
./hctx29/tags:wake_batch=8
./hctx29/tags:wake_index=4
./hctx29/tags:ws_active=0
./hctx29/tags:ws={
./hctx29/tags: {.wait_cnt=8, .wait=inactive},
./hctx29/tags: {.wait_cnt=8, .wait=inactive},
./hctx29/tags: {.wait_cnt=8, .wait=inactive},
./hctx29/tags: {.wait_cnt=8, .wait=inactive},
./hctx29/tags: {.wait_cnt=8, .wait=inactive},
./hctx29/tags: {.wait_cnt=8, .wait=inactive},
./hctx29/tags: {.wait_cnt=8, .wait=inactive},
./hctx29/tags: {.wait_cnt=8, .wait=inactive},
./hctx29/tags:}
./hctx29/tags:round_robin=0
./hctx29/tags:min_shallow_depth=4294967295
./hctx29/ctx_map:00000000: 00
./hctx29/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx28/type:default
./hctx28/dispatch_busy:0
./hctx28/active:0
./hctx28/run:5609
./hctx28/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx28/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx28/tags:nr_tags=256
./hctx28/tags:nr_reserved_tags=0
./hctx28/tags:active_queues=0
./hctx28/tags:bitmap_tags:
./hctx28/tags:depth=256
./hctx28/tags:busy=0
./hctx28/tags:cleared=168
./hctx28/tags:bits_per_word=64
./hctx28/tags:map_nr=4
./hctx28/tags:alloc_hint={101, 157, 24, 179, 226, 184, 212, 227, 90, 65, 48, 208, 55, 22, 83, 7, 105, 173, 0, 66, 6, 36, 66, 39, 235, 147, 96, 186, 96, 85}
./hctx28/tags:wake_batch=8
./hctx28/tags:wake_index=3
./hctx28/tags:ws_active=0
./hctx28/tags:ws={
./hctx28/tags: {.wait_cnt=8, .wait=inactive},
./hctx28/tags: {.wait_cnt=8, .wait=inactive},
./hctx28/tags: {.wait_cnt=8, .wait=inactive},
./hctx28/tags: {.wait_cnt=8, .wait=inactive},
./hctx28/tags: {.wait_cnt=8, .wait=inactive},
./hctx28/tags: {.wait_cnt=8, .wait=inactive},
./hctx28/tags: {.wait_cnt=8, .wait=inactive},
./hctx28/tags: {.wait_cnt=8, .wait=inactive},
./hctx28/tags:}
./hctx28/tags:round_robin=0
./hctx28/tags:min_shallow_depth=4294967295
./hctx28/ctx_map:00000000: 00
./hctx28/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx27/type:default
./hctx27/dispatch_busy:0
./hctx27/active:0
./hctx27/run:2412
./hctx27/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx27/tags_bitmap:00000010: 0000 0000 8003 0000 0000 0000 0000 0000
./hctx27/tags:nr_tags=256
./hctx27/tags:nr_reserved_tags=0
./hctx27/tags:active_queues=0
./hctx27/tags:bitmap_tags:
./hctx27/tags:depth=256
./hctx27/tags:busy=3
./hctx27/tags:cleared=229
./hctx27/tags:bits_per_word=64
./hctx27/tags:map_nr=4
./hctx27/tags:alloc_hint={160, 66, 22, 180, 161, 211, 192, 192, 190, 177, 55, 191, 243, 215, 26, 38, 145, 161, 188, 12, 222, 7, 167, 93, 99, 228, 184, 166, 20, 154}
./hctx27/tags:wake_batch=8
./hctx27/tags:wake_index=1
./hctx27/tags:ws_active=0
./hctx27/tags:ws={
./hctx27/tags: {.wait_cnt=8, .wait=inactive},
./hctx27/tags: {.wait_cnt=8, .wait=inactive},
./hctx27/tags: {.wait_cnt=8, .wait=inactive},
./hctx27/tags: {.wait_cnt=8, .wait=inactive},
./hctx27/tags: {.wait_cnt=8, .wait=inactive},
./hctx27/tags: {.wait_cnt=8, .wait=inactive},
./hctx27/tags: {.wait_cnt=8, .wait=inactive},
./hctx27/tags: {.wait_cnt=8, .wait=inactive},
./hctx27/tags:}
./hctx27/tags:round_robin=0
./hctx27/tags:min_shallow_depth=4294967295
./hctx27/ctx_map:00000000: 00
./hctx27/busy:00000000e4e3af26 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=167, .internal_tag=-1}
./hctx27/busy:00000000a9d6975f {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=168, .internal_tag=-1}
./hctx27/busy:00000000474663fc {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=169, .internal_tag=-1}
./hctx27/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx26/type:default
./hctx26/dispatch_busy:0
./hctx26/active:0
./hctx26/run:2706
./hctx26/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0018 0000
./hctx26/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx26/tags:nr_tags=256
./hctx26/tags:nr_reserved_tags=0
./hctx26/tags:active_queues=0
./hctx26/tags:bitmap_tags:
./hctx26/tags:depth=256
./hctx26/tags:busy=2
./hctx26/tags:cleared=119
./hctx26/tags:bits_per_word=64
./hctx26/tags:map_nr=4
./hctx26/tags:alloc_hint={125, 164, 84, 85, 148, 241, 183, 245, 71, 21, 4, 152, 190, 188, 31, 83, 165, 8, 155, 190, 152, 45, 194, 51, 164, 236, 105, 208, 25, 166}
./hctx26/tags:wake_batch=8
./hctx26/tags:wake_index=4
./hctx26/tags:ws_active=0
./hctx26/tags:ws={
./hctx26/tags: {.wait_cnt=8, .wait=inactive},
./hctx26/tags: {.wait_cnt=8, .wait=inactive},
./hctx26/tags: {.wait_cnt=8, .wait=inactive},
./hctx26/tags: {.wait_cnt=8, .wait=inactive},
./hctx26/tags: {.wait_cnt=8, .wait=inactive},
./hctx26/tags: {.wait_cnt=8, .wait=inactive},
./hctx26/tags: {.wait_cnt=8, .wait=inactive},
./hctx26/tags: {.wait_cnt=8, .wait=inactive},
./hctx26/tags:}
./hctx26/tags:round_robin=0
./hctx26/tags:min_shallow_depth=4294967295
./hctx26/ctx_map:00000000: 00
./hctx26/busy:00000000f32dd525 {.op=WRITE, .cmd_flags=SYNC, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=107, .internal_tag=-1}
./hctx26/busy:0000000055297a93 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=108, .internal_tag=-1}
./hctx26/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx25/type:default
./hctx25/dispatch_busy:0
./hctx25/active:0
./hctx25/run:1945
./hctx25/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx25/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx25/tags:nr_tags=256
./hctx25/tags:nr_reserved_tags=0
./hctx25/tags:active_queues=0
./hctx25/tags:bitmap_tags:
./hctx25/tags:depth=256
./hctx25/tags:busy=0
./hctx25/tags:cleared=199
./hctx25/tags:bits_per_word=64
./hctx25/tags:map_nr=4
./hctx25/tags:alloc_hint={144, 92, 106, 222, 27, 11, 20, 133, 9, 236, 62, 249, 81, 123, 168, 212, 114, 146, 181, 222, 21, 246, 195, 208, 21, 226, 2, 155, 99, 97}
./hctx25/tags:wake_batch=8
./hctx25/tags:wake_index=5
./hctx25/tags:ws_active=0
./hctx25/tags:ws={
./hctx25/tags: {.wait_cnt=8, .wait=inactive},
./hctx25/tags: {.wait_cnt=8, .wait=inactive},
./hctx25/tags: {.wait_cnt=8, .wait=inactive},
./hctx25/tags: {.wait_cnt=8, .wait=inactive},
./hctx25/tags: {.wait_cnt=8, .wait=inactive},
./hctx25/tags: {.wait_cnt=8, .wait=inactive},
./hctx25/tags: {.wait_cnt=8, .wait=inactive},
./hctx25/tags: {.wait_cnt=8, .wait=inactive},
./hctx25/tags:}
./hctx25/tags:round_robin=0
./hctx25/tags:min_shallow_depth=4294967295
./hctx25/ctx_map:00000000: 00
./hctx25/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx24/type:default
./hctx24/dispatch_busy:0
./hctx24/active:0
./hctx24/run:1901
./hctx24/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx24/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 00fc 0300
./hctx24/tags:nr_tags=256
./hctx24/tags:nr_reserved_tags=0
./hctx24/tags:active_queues=0
./hctx24/tags:bitmap_tags:
./hctx24/tags:depth=256
./hctx24/tags:busy=8
./hctx24/tags:cleared=225
./hctx24/tags:bits_per_word=64
./hctx24/tags:map_nr=4
./hctx24/tags:alloc_hint={68, 24, 219, 127, 52, 69, 181, 155, 238, 142, 228, 7, 157, 160, 157, 66, 161, 122, 132, 63, 119, 126, 95, 131, 233, 221, 91, 60, 31, 232}
./hctx24/tags:wake_batch=8
./hctx24/tags:wake_index=2
./hctx24/tags:ws_active=0
./hctx24/tags:ws={
./hctx24/tags: {.wait_cnt=8, .wait=inactive},
./hctx24/tags: {.wait_cnt=8, .wait=inactive},
./hctx24/tags: {.wait_cnt=8, .wait=inactive},
./hctx24/tags: {.wait_cnt=8, .wait=inactive},
./hctx24/tags: {.wait_cnt=8, .wait=inactive},
./hctx24/tags: {.wait_cnt=8, .wait=inactive},
./hctx24/tags: {.wait_cnt=8, .wait=inactive},
./hctx24/tags: {.wait_cnt=8, .wait=inactive},
./hctx24/tags:}
./hctx24/tags:round_robin=0
./hctx24/tags:min_shallow_depth=4294967295
./hctx24/ctx_map:00000000: 00
./hctx24/busy:00000000e790f153 {.op=WRITE, .cmd_flags=SYNC|NOMERGE, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=234, .internal_tag=-1}
./hctx24/busy:00000000fdf73c91 {.op=WRITE, .cmd_flags=SYNC, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=235, .internal_tag=-1}
./hctx24/busy:000000007ed75855 {.op=WRITE, .cmd_flags=SYNC|NOMERGE, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=236, .internal_tag=-1}
./hctx24/busy:00000000b6a2cbf7 {.op=WRITE, .cmd_flags=SYNC, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=237, .internal_tag=-1}
./hctx24/busy:0000000003d765e6 {.op=WRITE, .cmd_flags=SYNC|NOMERGE, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=238, .internal_tag=-1}
./hctx24/busy:0000000085f58536 {.op=WRITE, .cmd_flags=SYNC, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=239, .internal_tag=-1}
./hctx24/busy:0000000022a1e710 {.op=WRITE, .cmd_flags=SYNC|NOMERGE, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=240, .internal_tag=-1}
./hctx24/busy:0000000028133c90 {.op=WRITE, .cmd_flags=SYNC, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=241, .internal_tag=-1}
./hctx24/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx23/type:default
./hctx23/dispatch_busy:0
./hctx23/active:0
./hctx23/run:3536
./hctx23/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx23/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx23/tags:nr_tags=256
./hctx23/tags:nr_reserved_tags=0
./hctx23/tags:active_queues=0
./hctx23/tags:bitmap_tags:
./hctx23/tags:depth=256
./hctx23/tags:busy=0
./hctx23/tags:cleared=156
./hctx23/tags:bits_per_word=64
./hctx23/tags:map_nr=4
./hctx23/tags:alloc_hint={36, 118, 43, 99, 73, 235, 99, 10, 196, 220, 63, 203, 210, 144, 231, 91, 115, 54, 119, 173, 41, 134, 155, 131, 92, 197, 176, 104, 154, 60}
./hctx23/tags:wake_batch=8
./hctx23/tags:wake_index=1
./hctx23/tags:ws_active=0
./hctx23/tags:ws={
./hctx23/tags: {.wait_cnt=8, .wait=inactive},
./hctx23/tags: {.wait_cnt=8, .wait=inactive},
./hctx23/tags: {.wait_cnt=8, .wait=inactive},
./hctx23/tags: {.wait_cnt=8, .wait=inactive},
./hctx23/tags: {.wait_cnt=8, .wait=inactive},
./hctx23/tags: {.wait_cnt=8, .wait=inactive},
./hctx23/tags: {.wait_cnt=8, .wait=inactive},
./hctx23/tags: {.wait_cnt=8, .wait=inactive},
./hctx23/tags:}
./hctx23/tags:round_robin=0
./hctx23/tags:min_shallow_depth=4294967295
./hctx23/ctx_map:00000000: 00
./hctx23/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx22/type:default
./hctx22/dispatch_busy:0
./hctx22/active:0
./hctx22/run:4056
./hctx22/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx22/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx22/tags:nr_tags=256
./hctx22/tags:nr_reserved_tags=0
./hctx22/tags:active_queues=0
./hctx22/tags:bitmap_tags:
./hctx22/tags:depth=256
./hctx22/tags:busy=0
./hctx22/tags:cleared=140
./hctx22/tags:bits_per_word=64
./hctx22/tags:map_nr=4
./hctx22/tags:alloc_hint={69, 1, 214, 103, 48, 122, 103, 87, 37, 27, 241, 45, 71, 27, 231, 183, 71, 181, 150, 207, 239, 146, 195, 209, 115, 176, 177, 255, 55, 73}
./hctx22/tags:wake_batch=8
./hctx22/tags:wake_index=2
./hctx22/tags:ws_active=0
./hctx22/tags:ws={
./hctx22/tags: {.wait_cnt=8, .wait=inactive},
./hctx22/tags: {.wait_cnt=8, .wait=inactive},
./hctx22/tags: {.wait_cnt=8, .wait=inactive},
./hctx22/tags: {.wait_cnt=8, .wait=inactive},
./hctx22/tags: {.wait_cnt=8, .wait=inactive},
./hctx22/tags: {.wait_cnt=8, .wait=inactive},
./hctx22/tags: {.wait_cnt=8, .wait=inactive},
./hctx22/tags: {.wait_cnt=8, .wait=inactive},
./hctx22/tags:}
./hctx22/tags:round_robin=0
./hctx22/tags:min_shallow_depth=4294967295
./hctx22/ctx_map:00000000: 00
./hctx22/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx21/type:default
./hctx21/dispatch_busy:0
./hctx21/active:0
./hctx21/run:2828
./hctx21/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx21/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx21/tags:nr_tags=256
./hctx21/tags:nr_reserved_tags=0
./hctx21/tags:active_queues=0
./hctx21/tags:bitmap_tags:
./hctx21/tags:depth=256
./hctx21/tags:busy=0
./hctx21/tags:cleared=204
./hctx21/tags:bits_per_word=64
./hctx21/tags:map_nr=4
./hctx21/tags:alloc_hint={119, 103, 159, 82, 2, 31, 6, 212, 19, 118, 183, 184, 156, 86, 241, 11, 166, 249, 89, 141, 117, 76, 63, 10, 110, 48, 236, 212, 205, 211}
./hctx21/tags:wake_batch=8
./hctx21/tags:wake_index=6
./hctx21/tags:ws_active=0
./hctx21/tags:ws={
./hctx21/tags: {.wait_cnt=8, .wait=inactive},
./hctx21/tags: {.wait_cnt=8, .wait=inactive},
./hctx21/tags: {.wait_cnt=8, .wait=inactive},
./hctx21/tags: {.wait_cnt=8, .wait=inactive},
./hctx21/tags: {.wait_cnt=8, .wait=inactive},
./hctx21/tags: {.wait_cnt=8, .wait=inactive},
./hctx21/tags: {.wait_cnt=8, .wait=inactive},
./hctx21/tags: {.wait_cnt=8, .wait=inactive},
./hctx21/tags:}
./hctx21/tags:round_robin=0
./hctx21/tags:min_shallow_depth=4294967295
./hctx21/ctx_map:00000000: 00
./hctx21/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx20/type:default
./hctx20/dispatch_busy:0
./hctx20/active:0
./hctx20/run:5531
./hctx20/tags_bitmap:00000000: 0007 0000 0000 0000 0000 0000 0000 0000
./hctx20/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx20/tags:nr_tags=256
./hctx20/tags:nr_reserved_tags=0
./hctx20/tags:active_queues=0
./hctx20/tags:bitmap_tags:
./hctx20/tags:depth=256
./hctx20/tags:busy=3
./hctx20/tags:cleared=163
./hctx20/tags:bits_per_word=64
./hctx20/tags:map_nr=4
./hctx20/tags:alloc_hint={2, 110, 18, 137, 182, 72, 166, 9, 253, 218, 124, 158, 219, 65, 140, 78, 116, 20, 135, 99, 6, 196, 164, 91, 223, 247, 104, 161, 176, 163}
./hctx20/tags:wake_batch=8
./hctx20/tags:wake_index=7
./hctx20/tags:ws_active=0
./hctx20/tags:ws={
./hctx20/tags: {.wait_cnt=8, .wait=inactive},
./hctx20/tags: {.wait_cnt=8, .wait=inactive},
./hctx20/tags: {.wait_cnt=8, .wait=inactive},
./hctx20/tags: {.wait_cnt=8, .wait=inactive},
./hctx20/tags: {.wait_cnt=8, .wait=inactive},
./hctx20/tags: {.wait_cnt=8, .wait=inactive},
./hctx20/tags: {.wait_cnt=8, .wait=inactive},
./hctx20/tags: {.wait_cnt=8, .wait=inactive},
./hctx20/tags:}
./hctx20/tags:round_robin=0
./hctx20/tags:min_shallow_depth=4294967295
./hctx20/ctx_map:00000000: 00
./hctx20/busy:00000000dbbe8e10 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=8, .internal_tag=-1}
./hctx20/busy:00000000b2c7b152 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=9, .internal_tag=-1}
./hctx20/busy:000000006b2e3a67 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=10, .internal_tag=-1}
./hctx20/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx19/type:default
./hctx19/dispatch_busy:0
./hctx19/active:0
./hctx19/run:4397
./hctx19/tags_bitmap:00000000: 0000 0000 0000 0000 0000 2000 0000 0000
./hctx19/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx19/tags:nr_tags=256
./hctx19/tags:nr_reserved_tags=0
./hctx19/tags:active_queues=0
./hctx19/tags:bitmap_tags:
./hctx19/tags:depth=256
./hctx19/tags:busy=1
./hctx19/tags:cleared=161
./hctx19/tags:bits_per_word=64
./hctx19/tags:map_nr=4
./hctx19/tags:alloc_hint={114, 98, 59, 177, 72, 108, 146, 185, 245, 64, 33, 150, 85, 108, 118, 155, 213, 89, 83, 84, 254, 31, 74, 66, 43, 100, 188, 164, 209, 114}
./hctx19/tags:wake_batch=8
./hctx19/tags:wake_index=2
./hctx19/tags:ws_active=0
./hctx19/tags:ws={
./hctx19/tags: {.wait_cnt=8, .wait=inactive},
./hctx19/tags: {.wait_cnt=8, .wait=inactive},
./hctx19/tags: {.wait_cnt=8, .wait=inactive},
./hctx19/tags: {.wait_cnt=8, .wait=inactive},
./hctx19/tags: {.wait_cnt=8, .wait=inactive},
./hctx19/tags: {.wait_cnt=8, .wait=inactive},
./hctx19/tags: {.wait_cnt=8, .wait=inactive},
./hctx19/tags: {.wait_cnt=8, .wait=inactive},
./hctx19/tags:}
./hctx19/tags:round_robin=0
./hctx19/tags:min_shallow_depth=4294967295
./hctx19/ctx_map:00000000: 00
./hctx19/busy:00000000ba534341 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=85, .internal_tag=-1}
./hctx19/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx18/type:default
./hctx18/dispatch_busy:0
./hctx18/active:0
./hctx18/run:11144
./hctx18/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx18/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx18/tags:nr_tags=256
./hctx18/tags:nr_reserved_tags=0
./hctx18/tags:active_queues=0
./hctx18/tags:bitmap_tags:
./hctx18/tags:depth=256
./hctx18/tags:busy=0
./hctx18/tags:cleared=191
./hctx18/tags:bits_per_word=64
./hctx18/tags:map_nr=4
./hctx18/tags:alloc_hint={247, 241, 34, 57, 105, 137, 156, 0, 102, 44, 127, 157, 175, 241, 29, 11, 39, 34, 53, 140, 231, 167, 6, 28, 165, 211, 114, 255, 203, 204}
./hctx18/tags:wake_batch=8
./hctx18/tags:wake_index=5
./hctx18/tags:ws_active=0
./hctx18/tags:ws={
./hctx18/tags: {.wait_cnt=8, .wait=inactive},
./hctx18/tags: {.wait_cnt=8, .wait=inactive},
./hctx18/tags: {.wait_cnt=8, .wait=inactive},
./hctx18/tags: {.wait_cnt=8, .wait=inactive},
./hctx18/tags: {.wait_cnt=8, .wait=inactive},
./hctx18/tags: {.wait_cnt=8, .wait=inactive},
./hctx18/tags: {.wait_cnt=8, .wait=inactive},
./hctx18/tags: {.wait_cnt=8, .wait=inactive},
./hctx18/tags:}
./hctx18/tags:round_robin=0
./hctx18/tags:min_shallow_depth=4294967295
./hctx18/ctx_map:00000000: 00
./hctx18/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx17/type:default
./hctx17/dispatch_busy:0
./hctx17/active:0
./hctx17/run:5438
./hctx17/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx17/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx17/tags:nr_tags=256
./hctx17/tags:nr_reserved_tags=0
./hctx17/tags:active_queues=0
./hctx17/tags:bitmap_tags:
./hctx17/tags:depth=256
./hctx17/tags:busy=0
./hctx17/tags:cleared=143
./hctx17/tags:bits_per_word=64
./hctx17/tags:map_nr=4
./hctx17/tags:alloc_hint={218, 38, 159, 130, 2, 161, 230, 66, 218, 26, 195, 43, 50, 102, 2, 189, 122, 162, 148, 237, 195, 23, 253, 230, 185, 181, 141, 42, 15, 35}
./hctx17/tags:wake_batch=8
./hctx17/tags:wake_index=6
./hctx17/tags:ws_active=0
./hctx17/tags:ws={
./hctx17/tags: {.wait_cnt=8, .wait=inactive},
./hctx17/tags: {.wait_cnt=8, .wait=inactive},
./hctx17/tags: {.wait_cnt=8, .wait=inactive},
./hctx17/tags: {.wait_cnt=8, .wait=inactive},
./hctx17/tags: {.wait_cnt=8, .wait=inactive},
./hctx17/tags: {.wait_cnt=8, .wait=inactive},
./hctx17/tags: {.wait_cnt=8, .wait=inactive},
./hctx17/tags: {.wait_cnt=8, .wait=inactive},
./hctx17/tags:}
./hctx17/tags:round_robin=0
./hctx17/tags:min_shallow_depth=4294967295
./hctx17/ctx_map:00000000: 00
./hctx17/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx16/type:default
./hctx16/dispatch_busy:0
./hctx16/active:0
./hctx16/run:2263
./hctx16/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx16/tags_bitmap:00000010: 0008 0000 0000 0000 0000 0000 0000 0000
./hctx16/tags:nr_tags=256
./hctx16/tags:nr_reserved_tags=0
./hctx16/tags:active_queues=0
./hctx16/tags:bitmap_tags:
./hctx16/tags:depth=256
./hctx16/tags:busy=1
./hctx16/tags:cleared=163
./hctx16/tags:bits_per_word=64
./hctx16/tags:map_nr=4
./hctx16/tags:alloc_hint={251, 199, 87, 165, 43, 98, 184, 5, 81, 221, 222, 118, 160, 124, 136, 202, 138, 116, 14, 216, 113, 203, 63, 51, 86, 113, 180, 162, 228, 135}
./hctx16/tags:wake_batch=8
./hctx16/tags:wake_index=6
./hctx16/tags:ws_active=0
./hctx16/tags:ws={
./hctx16/tags: {.wait_cnt=8, .wait=inactive},
./hctx16/tags: {.wait_cnt=8, .wait=inactive},
./hctx16/tags: {.wait_cnt=8, .wait=inactive},
./hctx16/tags: {.wait_cnt=8, .wait=inactive},
./hctx16/tags: {.wait_cnt=8, .wait=inactive},
./hctx16/tags: {.wait_cnt=8, .wait=inactive},
./hctx16/tags: {.wait_cnt=8, .wait=inactive},
./hctx16/tags: {.wait_cnt=8, .wait=inactive},
./hctx16/tags:}
./hctx16/tags:round_robin=0
./hctx16/tags:min_shallow_depth=4294967295
./hctx16/ctx_map:00000000: 00
./hctx16/busy:000000004afd6f8d {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=139, .internal_tag=-1}
./hctx16/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx15/type:default
./hctx15/dispatch_busy:0
./hctx15/active:0
./hctx15/run:3111
./hctx15/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx15/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx15/tags:nr_tags=256
./hctx15/tags:nr_reserved_tags=0
./hctx15/tags:active_queues=0
./hctx15/tags:bitmap_tags:
./hctx15/tags:depth=256
./hctx15/tags:busy=0
./hctx15/tags:cleared=176
./hctx15/tags:bits_per_word=64
./hctx15/tags:map_nr=4
./hctx15/tags:alloc_hint={236, 151, 45, 140, 243, 147, 40, 180, 12, 206, 27, 99, 45, 55, 233, 48, 167, 70, 72, 48, 194, 96, 104, 159, 103, 66, 163, 41, 233, 234}
./hctx15/tags:wake_batch=8
./hctx15/tags:wake_index=5
./hctx15/tags:ws_active=0
./hctx15/tags:ws={
./hctx15/tags: {.wait_cnt=8, .wait=inactive},
./hctx15/tags: {.wait_cnt=8, .wait=inactive},
./hctx15/tags: {.wait_cnt=8, .wait=inactive},
./hctx15/tags: {.wait_cnt=8, .wait=inactive},
./hctx15/tags: {.wait_cnt=8, .wait=inactive},
./hctx15/tags: {.wait_cnt=8, .wait=inactive},
./hctx15/tags: {.wait_cnt=8, .wait=inactive},
./hctx15/tags: {.wait_cnt=8, .wait=inactive},
./hctx15/tags:}
./hctx15/tags:round_robin=0
./hctx15/tags:min_shallow_depth=4294967295
./hctx15/ctx_map:00000000: 00
./hctx15/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx14/type:default
./hctx14/dispatch_busy:0
./hctx14/active:0
./hctx14/run:3264
./hctx14/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx14/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0c00 0000
./hctx14/tags:nr_tags=256
./hctx14/tags:nr_reserved_tags=0
./hctx14/tags:active_queues=0
./hctx14/tags:bitmap_tags:
./hctx14/tags:depth=256
./hctx14/tags:busy=2
./hctx14/tags:cleared=186
./hctx14/tags:bits_per_word=64
./hctx14/tags:map_nr=4
./hctx14/tags:alloc_hint={225, 119, 205, 189, 131, 64, 181, 199, 91, 205, 190, 68, 144, 116, 225, 54, 102, 203, 223, 110, 148, 86, 111, 216, 5, 198, 170, 81, 107, 148}
./hctx14/tags:wake_batch=8
./hctx14/tags:wake_index=7
./hctx14/tags:ws_active=0
./hctx14/tags:ws={
./hctx14/tags: {.wait_cnt=8, .wait=inactive},
./hctx14/tags: {.wait_cnt=8, .wait=inactive},
./hctx14/tags: {.wait_cnt=8, .wait=inactive},
./hctx14/tags: {.wait_cnt=8, .wait=inactive},
./hctx14/tags: {.wait_cnt=8, .wait=inactive},
./hctx14/tags: {.wait_cnt=8, .wait=inactive},
./hctx14/tags: {.wait_cnt=8, .wait=inactive},
./hctx14/tags: {.wait_cnt=8, .wait=inactive},
./hctx14/tags:}
./hctx14/tags:round_robin=0
./hctx14/tags:min_shallow_depth=4294967295
./hctx14/ctx_map:00000000: 00
./hctx14/busy:000000006297825b {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=226, .internal_tag=-1}
./hctx14/busy:000000006dab2a37 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=227, .internal_tag=-1}
./hctx14/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx13/type:default
./hctx13/dispatch_busy:0
./hctx13/active:0
./hctx13/run:2301
./hctx13/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx13/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx13/tags:nr_tags=256
./hctx13/tags:nr_reserved_tags=0
./hctx13/tags:active_queues=0
./hctx13/tags:bitmap_tags:
./hctx13/tags:depth=256
./hctx13/tags:busy=0
./hctx13/tags:cleared=141
./hctx13/tags:bits_per_word=64
./hctx13/tags:map_nr=4
./hctx13/tags:alloc_hint={101, 244, 86, 25, 204, 193, 187, 212, 100, 185, 75, 165, 172, 27, 232, 227, 176, 216, 40, 254, 142, 12, 148, 164, 162, 142, 207, 202, 24, 68}
./hctx13/tags:wake_batch=8
./hctx13/tags:wake_index=7
./hctx13/tags:ws_active=0
./hctx13/tags:ws={
./hctx13/tags: {.wait_cnt=8, .wait=inactive},
./hctx13/tags: {.wait_cnt=8, .wait=inactive},
./hctx13/tags: {.wait_cnt=8, .wait=inactive},
./hctx13/tags: {.wait_cnt=8, .wait=inactive},
./hctx13/tags: {.wait_cnt=8, .wait=inactive},
./hctx13/tags: {.wait_cnt=8, .wait=inactive},
./hctx13/tags: {.wait_cnt=8, .wait=inactive},
./hctx13/tags: {.wait_cnt=8, .wait=inactive},
./hctx13/tags:}
./hctx13/tags:round_robin=0
./hctx13/tags:min_shallow_depth=4294967295
./hctx13/ctx_map:00000000: 00
./hctx13/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx12/type:default
./hctx12/dispatch_busy:0
./hctx12/active:0
./hctx12/run:2207
./hctx12/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0030 0000
./hctx12/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx12/tags:nr_tags=256
./hctx12/tags:nr_reserved_tags=0
./hctx12/tags:active_queues=0
./hctx12/tags:bitmap_tags:
./hctx12/tags:depth=256
./hctx12/tags:busy=2
./hctx12/tags:cleared=141
./hctx12/tags:bits_per_word=64
./hctx12/tags:map_nr=4
./hctx12/tags:alloc_hint={48, 98, 222, 240, 45, 107, 209, 187, 51, 238, 78, 40, 107, 251, 215, 90, 237, 99, 50, 131, 218, 190, 167, 47, 175, 56, 94, 140, 47, 42}
./hctx12/tags:wake_batch=8
./hctx12/tags:wake_index=1
./hctx12/tags:ws_active=0
./hctx12/tags:ws={
./hctx12/tags: {.wait_cnt=8, .wait=inactive},
./hctx12/tags: {.wait_cnt=8, .wait=inactive},
./hctx12/tags: {.wait_cnt=8, .wait=inactive},
./hctx12/tags: {.wait_cnt=8, .wait=inactive},
./hctx12/tags: {.wait_cnt=8, .wait=inactive},
./hctx12/tags: {.wait_cnt=8, .wait=inactive},
./hctx12/tags: {.wait_cnt=8, .wait=inactive},
./hctx12/tags: {.wait_cnt=8, .wait=inactive},
./hctx12/tags:}
./hctx12/tags:round_robin=0
./hctx12/tags:min_shallow_depth=4294967295
./hctx12/ctx_map:00000000: 00
./hctx12/busy:000000003b2ead58 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=108, .internal_tag=-1}
./hctx12/busy:000000006db40d28 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=109, .internal_tag=-1}
./hctx12/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx11/type:default
./hctx11/dispatch_busy:0
./hctx11/active:0
./hctx11/run:4804
./hctx11/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx11/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx11/tags:nr_tags=256
./hctx11/tags:nr_reserved_tags=0
./hctx11/tags:active_queues=0
./hctx11/tags:bitmap_tags:
./hctx11/tags:depth=256
./hctx11/tags:busy=0
./hctx11/tags:cleared=218
./hctx11/tags:bits_per_word=64
./hctx11/tags:map_nr=4
./hctx11/tags:alloc_hint={150, 81, 100, 105, 5, 94, 194, 126, 83, 240, 252, 84, 115, 165, 203, 189, 99, 178, 254, 43, 172, 180, 118, 179, 60, 29, 129, 61, 20, 21}
./hctx11/tags:wake_batch=8
./hctx11/tags:wake_index=4
./hctx11/tags:ws_active=0
./hctx11/tags:ws={
./hctx11/tags: {.wait_cnt=8, .wait=inactive},
./hctx11/tags: {.wait_cnt=8, .wait=inactive},
./hctx11/tags: {.wait_cnt=8, .wait=inactive},
./hctx11/tags: {.wait_cnt=8, .wait=inactive},
./hctx11/tags: {.wait_cnt=8, .wait=inactive},
./hctx11/tags: {.wait_cnt=8, .wait=inactive},
./hctx11/tags: {.wait_cnt=8, .wait=inactive},
./hctx11/tags: {.wait_cnt=8, .wait=inactive},
./hctx11/tags:}
./hctx11/tags:round_robin=0
./hctx11/tags:min_shallow_depth=4294967295
./hctx11/ctx_map:00000000: 00
./hctx11/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx10/type:default
./hctx10/dispatch_busy:0
./hctx10/active:0
./hctx10/run:5162
./hctx10/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx10/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx10/tags:nr_tags=256
./hctx10/tags:nr_reserved_tags=0
./hctx10/tags:active_queues=0
./hctx10/tags:bitmap_tags:
./hctx10/tags:depth=256
./hctx10/tags:busy=0
./hctx10/tags:cleared=125
./hctx10/tags:bits_per_word=64
./hctx10/tags:map_nr=4
./hctx10/tags:alloc_hint={120, 76, 152, 212, 233, 230, 52, 24, 107, 150, 212, 156, 217, 16, 25, 245, 46, 56, 174, 187, 228, 109, 198, 44, 216, 188, 99, 119, 123, 182}
./hctx10/tags:wake_batch=8
./hctx10/tags:wake_index=7
./hctx10/tags:ws_active=0
./hctx10/tags:ws={
./hctx10/tags: {.wait_cnt=8, .wait=inactive},
./hctx10/tags: {.wait_cnt=8, .wait=inactive},
./hctx10/tags: {.wait_cnt=8, .wait=inactive},
./hctx10/tags: {.wait_cnt=8, .wait=inactive},
./hctx10/tags: {.wait_cnt=8, .wait=inactive},
./hctx10/tags: {.wait_cnt=8, .wait=inactive},
./hctx10/tags: {.wait_cnt=8, .wait=inactive},
./hctx10/tags: {.wait_cnt=8, .wait=inactive},
./hctx10/tags:}
./hctx10/tags:round_robin=0
./hctx10/tags:min_shallow_depth=4294967295
./hctx10/ctx_map:00000000: 00
./hctx10/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx9/type:default
./hctx9/dispatch_busy:0
./hctx9/active:0
./hctx9/run:6686
./hctx9/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx9/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx9/tags:nr_tags=256
./hctx9/tags:nr_reserved_tags=0
./hctx9/tags:active_queues=0
./hctx9/tags:bitmap_tags:
./hctx9/tags:depth=256
./hctx9/tags:busy=0
./hctx9/tags:cleared=237
./hctx9/tags:bits_per_word=64
./hctx9/tags:map_nr=4
./hctx9/tags:alloc_hint={110, 175, 48, 252, 162, 124, 145, 52, 8, 122, 233, 207, 239, 168, 114, 237, 113, 139, 142, 211, 18, 199, 161, 239, 163, 171, 97, 51, 52, 17}
./hctx9/tags:wake_batch=8
./hctx9/tags:wake_index=2
./hctx9/tags:ws_active=0
./hctx9/tags:ws={
./hctx9/tags: {.wait_cnt=8, .wait=inactive},
./hctx9/tags: {.wait_cnt=8, .wait=inactive},
./hctx9/tags: {.wait_cnt=8, .wait=inactive},
./hctx9/tags: {.wait_cnt=8, .wait=inactive},
./hctx9/tags: {.wait_cnt=8, .wait=inactive},
./hctx9/tags: {.wait_cnt=8, .wait=inactive},
./hctx9/tags: {.wait_cnt=8, .wait=inactive},
./hctx9/tags: {.wait_cnt=8, .wait=inactive},
./hctx9/tags:}
./hctx9/tags:round_robin=0
./hctx9/tags:min_shallow_depth=4294967295
./hctx9/ctx_map:00000000: 00
./hctx9/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx8/type:default
./hctx8/dispatch_busy:0
./hctx8/active:0
./hctx8/run:6128
./hctx8/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx8/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx8/tags:nr_tags=256
./hctx8/tags:nr_reserved_tags=0
./hctx8/tags:active_queues=0
./hctx8/tags:bitmap_tags:
./hctx8/tags:depth=256
./hctx8/tags:busy=0
./hctx8/tags:cleared=166
./hctx8/tags:bits_per_word=64
./hctx8/tags:map_nr=4
./hctx8/tags:alloc_hint={123, 239, 249, 30, 240, 217, 21, 62, 138, 227, 118, 193, 200, 97, 98, 247, 146, 52, 131, 99, 248, 104, 119, 30, 35, 129, 62, 66, 179, 75}
./hctx8/tags:wake_batch=8
./hctx8/tags:wake_index=5
./hctx8/tags:ws_active=0
./hctx8/tags:ws={
./hctx8/tags: {.wait_cnt=8, .wait=inactive},
./hctx8/tags: {.wait_cnt=8, .wait=inactive},
./hctx8/tags: {.wait_cnt=8, .wait=inactive},
./hctx8/tags: {.wait_cnt=8, .wait=inactive},
./hctx8/tags: {.wait_cnt=8, .wait=inactive},
./hctx8/tags: {.wait_cnt=8, .wait=inactive},
./hctx8/tags: {.wait_cnt=8, .wait=inactive},
./hctx8/tags: {.wait_cnt=8, .wait=inactive},
./hctx8/tags:}
./hctx8/tags:round_robin=0
./hctx8/tags:min_shallow_depth=4294967295
./hctx8/ctx_map:00000000: 00
./hctx8/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx7/type:default
./hctx7/dispatch_busy:0
./hctx7/active:0
./hctx7/run:3140
./hctx7/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx7/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx7/tags:nr_tags=256
./hctx7/tags:nr_reserved_tags=0
./hctx7/tags:active_queues=0
./hctx7/tags:bitmap_tags:
./hctx7/tags:depth=256
./hctx7/tags:busy=0
./hctx7/tags:cleared=131
./hctx7/tags:bits_per_word=64
./hctx7/tags:map_nr=4
./hctx7/tags:alloc_hint={200, 103, 15, 111, 101, 194, 67, 141, 9, 167, 29, 5, 154, 128, 143, 85, 26, 254, 242, 213, 98, 187, 117, 187, 36, 255, 225, 3, 46, 25}
./hctx7/tags:wake_batch=8
./hctx7/tags:wake_index=4
./hctx7/tags:ws_active=0
./hctx7/tags:ws={
./hctx7/tags: {.wait_cnt=8, .wait=inactive},
./hctx7/tags: {.wait_cnt=8, .wait=inactive},
./hctx7/tags: {.wait_cnt=8, .wait=inactive},
./hctx7/tags: {.wait_cnt=8, .wait=inactive},
./hctx7/tags: {.wait_cnt=8, .wait=inactive},
./hctx7/tags: {.wait_cnt=8, .wait=inactive},
./hctx7/tags: {.wait_cnt=8, .wait=inactive},
./hctx7/tags: {.wait_cnt=8, .wait=inactive},
./hctx7/tags:}
./hctx7/tags:round_robin=0
./hctx7/tags:min_shallow_depth=4294967295
./hctx7/ctx_map:00000000: 00
./hctx7/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx6/type:default
./hctx6/dispatch_busy:0
./hctx6/active:0
./hctx6/run:7713
./hctx6/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx6/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx6/tags:nr_tags=256
./hctx6/tags:nr_reserved_tags=0
./hctx6/tags:active_queues=0
./hctx6/tags:bitmap_tags:
./hctx6/tags:depth=256
./hctx6/tags:busy=0
./hctx6/tags:cleared=132
./hctx6/tags:bits_per_word=64
./hctx6/tags:map_nr=4
./hctx6/tags:alloc_hint={89, 64, 36, 241, 207, 56, 77, 30, 125, 31, 241, 194, 53, 119, 245, 107, 84, 7, 44, 177, 217, 149, 180, 138, 207, 92, 213, 150, 113, 32}
./hctx6/tags:wake_batch=8
./hctx6/tags:wake_index=4
./hctx6/tags:ws_active=0
./hctx6/tags:ws={
./hctx6/tags: {.wait_cnt=8, .wait=inactive},
./hctx6/tags: {.wait_cnt=8, .wait=inactive},
./hctx6/tags: {.wait_cnt=8, .wait=inactive},
./hctx6/tags: {.wait_cnt=8, .wait=inactive},
./hctx6/tags: {.wait_cnt=8, .wait=inactive},
./hctx6/tags: {.wait_cnt=8, .wait=inactive},
./hctx6/tags: {.wait_cnt=8, .wait=inactive},
./hctx6/tags: {.wait_cnt=8, .wait=inactive},
./hctx6/tags:}
./hctx6/tags:round_robin=0
./hctx6/tags:min_shallow_depth=4294967295
./hctx6/ctx_map:00000000: 00
./hctx6/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx5/type:default
./hctx5/dispatch_busy:0
./hctx5/active:0
./hctx5/run:3166
./hctx5/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0001 0000 0000
./hctx5/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx5/tags:nr_tags=256
./hctx5/tags:nr_reserved_tags=0
./hctx5/tags:active_queues=0
./hctx5/tags:bitmap_tags:
./hctx5/tags:depth=256
./hctx5/tags:busy=1
./hctx5/tags:cleared=187
./hctx5/tags:bits_per_word=64
./hctx5/tags:map_nr=4
./hctx5/tags:alloc_hint={103, 123, 198, 107, 222, 87, 150, 127, 88, 0, 118, 10, 248, 237, 89, 42, 114, 11, 99, 17, 210, 16, 25, 185, 179, 71, 223, 245, 55, 153}
./hctx5/tags:wake_batch=8
./hctx5/tags:wake_index=6
./hctx5/tags:ws_active=0
./hctx5/tags:ws={
./hctx5/tags: {.wait_cnt=8, .wait=inactive},
./hctx5/tags: {.wait_cnt=8, .wait=inactive},
./hctx5/tags: {.wait_cnt=8, .wait=inactive},
./hctx5/tags: {.wait_cnt=8, .wait=inactive},
./hctx5/tags: {.wait_cnt=8, .wait=inactive},
./hctx5/tags: {.wait_cnt=8, .wait=inactive},
./hctx5/tags: {.wait_cnt=8, .wait=inactive},
./hctx5/tags: {.wait_cnt=8, .wait=inactive},
./hctx5/tags:}
./hctx5/tags:round_robin=0
./hctx5/tags:min_shallow_depth=4294967295
./hctx5/ctx_map:00000000: 00
./hctx5/busy:000000001ad8b915 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=88, .internal_tag=-1}
./hctx5/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx4/type:default
./hctx4/dispatch_busy:0
./hctx4/active:0
./hctx4/run:6121
./hctx4/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx4/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx4/tags:nr_tags=256
./hctx4/tags:nr_reserved_tags=0
./hctx4/tags:active_queues=0
./hctx4/tags:bitmap_tags:
./hctx4/tags:depth=256
./hctx4/tags:busy=0
./hctx4/tags:cleared=206
./hctx4/tags:bits_per_word=64
./hctx4/tags:map_nr=4
./hctx4/tags:alloc_hint={120, 232, 72, 213, 235, 138, 134, 52, 116, 213, 45, 149, 236, 59, 198, 98, 90, 44, 9, 51, 22, 177, 102, 246, 31, 135, 107, 194, 168, 4}
./hctx4/tags:wake_batch=8
./hctx4/tags:wake_index=7
./hctx4/tags:ws_active=0
./hctx4/tags:ws={
./hctx4/tags: {.wait_cnt=8, .wait=inactive},
./hctx4/tags: {.wait_cnt=8, .wait=inactive},
./hctx4/tags: {.wait_cnt=8, .wait=inactive},
./hctx4/tags: {.wait_cnt=8, .wait=inactive},
./hctx4/tags: {.wait_cnt=8, .wait=inactive},
./hctx4/tags: {.wait_cnt=8, .wait=inactive},
./hctx4/tags: {.wait_cnt=8, .wait=inactive},
./hctx4/tags: {.wait_cnt=8, .wait=inactive},
./hctx4/tags:}
./hctx4/tags:round_robin=0
./hctx4/tags:min_shallow_depth=4294967295
./hctx4/ctx_map:00000000: 00
./hctx4/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx3/type:default
./hctx3/dispatch_busy:0
./hctx3/active:0
./hctx3/run:9067
./hctx3/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx3/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx3/tags:nr_tags=256
./hctx3/tags:nr_reserved_tags=0
./hctx3/tags:active_queues=0
./hctx3/tags:bitmap_tags:
./hctx3/tags:depth=256
./hctx3/tags:busy=0
./hctx3/tags:cleared=176
./hctx3/tags:bits_per_word=64
./hctx3/tags:map_nr=4
./hctx3/tags:alloc_hint={46, 100, 72, 177, 46, 99, 66, 206, 254, 224, 139, 205, 120, 18, 223, 204, 16, 188, 113, 79, 0, 218, 91, 123, 180, 57, 47, 128, 230, 92}
./hctx3/tags:wake_batch=8
./hctx3/tags:wake_index=6
./hctx3/tags:ws_active=0
./hctx3/tags:ws={
./hctx3/tags: {.wait_cnt=8, .wait=inactive},
./hctx3/tags: {.wait_cnt=8, .wait=inactive},
./hctx3/tags: {.wait_cnt=8, .wait=inactive},
./hctx3/tags: {.wait_cnt=8, .wait=inactive},
./hctx3/tags: {.wait_cnt=8, .wait=inactive},
./hctx3/tags: {.wait_cnt=8, .wait=inactive},
./hctx3/tags: {.wait_cnt=8, .wait=inactive},
./hctx3/tags: {.wait_cnt=8, .wait=inactive},
./hctx3/tags:}
./hctx3/tags:round_robin=0
./hctx3/tags:min_shallow_depth=4294967295
./hctx3/ctx_map:00000000: 00
./hctx3/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx2/type:default
./hctx2/dispatch_busy:0
./hctx2/active:0
./hctx2/run:12968
./hctx2/tags_bitmap:00000000: 0000 0000 0000 0004 0000 0000 0000 0000
./hctx2/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx2/tags:nr_tags=256
./hctx2/tags:nr_reserved_tags=0
./hctx2/tags:active_queues=0
./hctx2/tags:bitmap_tags:
./hctx2/tags:depth=256
./hctx2/tags:busy=1
./hctx2/tags:cleared=183
./hctx2/tags:bits_per_word=64
./hctx2/tags:map_nr=4
./hctx2/tags:alloc_hint={222, 150, 57, 191, 75, 15, 187, 88, 76, 161, 205, 22, 243, 193, 234, 139, 109, 38, 96, 96, 182, 52, 192, 91, 239, 100, 120, 126, 86, 106}
./hctx2/tags:wake_batch=8
./hctx2/tags:wake_index=2
./hctx2/tags:ws_active=0
./hctx2/tags:ws={
./hctx2/tags: {.wait_cnt=8, .wait=inactive},
./hctx2/tags: {.wait_cnt=8, .wait=inactive},
./hctx2/tags: {.wait_cnt=8, .wait=inactive},
./hctx2/tags: {.wait_cnt=8, .wait=inactive},
./hctx2/tags: {.wait_cnt=8, .wait=inactive},
./hctx2/tags: {.wait_cnt=8, .wait=inactive},
./hctx2/tags: {.wait_cnt=8, .wait=inactive},
./hctx2/tags: {.wait_cnt=8, .wait=inactive},
./hctx2/tags:}
./hctx2/tags:round_robin=0
./hctx2/tags:min_shallow_depth=4294967295
./hctx2/ctx_map:00000000: 00
./hctx2/busy:000000004ba67441 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=58, .internal_tag=-1}
./hctx2/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx1/type:default
./hctx1/dispatch_busy:0
./hctx1/active:0
./hctx1/run:7325
./hctx1/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx1/tags_bitmap:00000010: 0000 0000 0000 0000 0000 0000 0e00 0000
./hctx1/tags:nr_tags=256
./hctx1/tags:nr_reserved_tags=0
./hctx1/tags:active_queues=0
./hctx1/tags:bitmap_tags:
./hctx1/tags:depth=256
./hctx1/tags:busy=3
./hctx1/tags:cleared=192
./hctx1/tags:bits_per_word=64
./hctx1/tags:map_nr=4
./hctx1/tags:alloc_hint={8, 224, 14, 196, 133, 5, 254, 196, 81, 218, 89, 125, 181, 155, 34, 253, 123, 226, 21, 68, 57, 49, 62, 40, 177, 125, 72, 94, 55, 25}
./hctx1/tags:wake_batch=8
./hctx1/tags:wake_index=0
./hctx1/tags:ws_active=0
./hctx1/tags:ws={
./hctx1/tags: {.wait_cnt=8, .wait=inactive},
./hctx1/tags: {.wait_cnt=8, .wait=inactive},
./hctx1/tags: {.wait_cnt=8, .wait=inactive},
./hctx1/tags: {.wait_cnt=8, .wait=inactive},
./hctx1/tags: {.wait_cnt=8, .wait=inactive},
./hctx1/tags: {.wait_cnt=8, .wait=inactive},
./hctx1/tags: {.wait_cnt=8, .wait=inactive},
./hctx1/tags: {.wait_cnt=8, .wait=inactive},
./hctx1/tags:}
./hctx1/tags:round_robin=0
./hctx1/tags:min_shallow_depth=4294967295
./hctx1/ctx_map:00000000: 00
./hctx1/busy:000000007bfd9802 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=225, .internal_tag=-1}
./hctx1/busy:00000000e8167fa4 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=226, .internal_tag=-1}
./hctx1/busy:00000000e80e2f09 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=227, .internal_tag=-1}
./hctx1/flags:alloc_policy=FIFO SHOULD_MERGE
./hctx0/type:default
./hctx0/dispatch_busy:0
./hctx0/active:0
./hctx0/run:14508
./hctx0/tags_bitmap:00000000: 0000 0000 0000 0000 0000 0000 0000 0000
./hctx0/tags_bitmap:00000010: 0000 1000 0000 0000 0000 0000 0000 0000
./hctx0/tags:nr_tags=256
./hctx0/tags:nr_reserved_tags=0
./hctx0/tags:active_queues=0
./hctx0/tags:bitmap_tags:
./hctx0/tags:depth=256
./hctx0/tags:busy=1
./hctx0/tags:cleared=204
./hctx0/tags:bits_per_word=64
./hctx0/tags:map_nr=4
./hctx0/tags:alloc_hint={146, 15, 187, 210, 166, 130, 170, 139, 19, 26, 5, 33, 71, 30, 147, 73, 8, 155, 107, 166, 55, 59, 235, 186, 8, 231, 78, 88, 221, 58}
./hctx0/tags:wake_batch=8
./hctx0/tags:wake_index=7
./hctx0/tags:ws_active=0
./hctx0/tags:ws={
./hctx0/tags: {.wait_cnt=8, .wait=inactive},
./hctx0/tags: {.wait_cnt=8, .wait=inactive},
./hctx0/tags: {.wait_cnt=8, .wait=inactive},
./hctx0/tags: {.wait_cnt=8, .wait=inactive},
./hctx0/tags: {.wait_cnt=8, .wait=inactive},
./hctx0/tags: {.wait_cnt=8, .wait=inactive},
./hctx0/tags: {.wait_cnt=8, .wait=inactive},
./hctx0/tags: {.wait_cnt=8, .wait=inactive},
./hctx0/tags:}
./hctx0/tags:round_robin=0
./hctx0/tags:min_shallow_depth=4294967295
./hctx0/ctx_map:00000000: 00
./hctx0/busy:00000000ec394ebd {.op=READ, .cmd_flags=, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=148, .internal_tag=-1}
./hctx0/flags:alloc_policy=FIFO SHOULD_MERGE
./state:SAME_COMP|IO_STAT|INIT_DONE|WC|STATS|REGISTERED|NOWAIT
./pm_only:0
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: again? - Write I/O queue hangup at random on recent Linus' kernels
2022-10-11 15:15 ` Jaroslav Pulchart
@ 2022-10-11 16:53 ` Bart Van Assche
2022-10-12 2:05 ` Yu Kuai
2022-10-12 13:07 ` Ming Lei
2 siblings, 0 replies; 9+ messages in thread
From: Bart Van Assche @ 2022-10-11 16:53 UTC (permalink / raw)
To: Theodore Ts'o
Cc: linux-block, Jaroslav Pulchart, Igor Raits, Daniel Secik, David Krupicka
On 10/11/22 08:15, Jaroslav Pulchart wrote:
> čt 6. 10. 2022 v 18:57 odesílatel Bart Van Assche <bvanassche@acm.org> napsal:
>>
>> On 10/6/22 05:36, Jaroslav Pulchart wrote:
>>> I apply the
>>> echo 0 > /sys/block/vdc/queue/wbt_lat_usec
>>> at the production servers. I expect it will disable wbt. Could you
>>> please confirm that my expectation is correct?
>>
>> Hi Jaroslav,
>>
>> I have no experience with WBT. But what I found in the documentation seems
>> to confirm that the above command is sufficient to disable WBT:
>>
>> What: /sys/block/<disk>/queue/wbt_lat_usec
>> Date: November 2016
>> Contact: linux-block@vger.kernel.org
>> Description:
>> [RW] If the device is registered for writeback throttling, then
>> this file shows the target minimum read latency. If this latency
>> is exceeded in a given window of time (see wb_window_usec), then
>> the writeback throttling will start scaling back writes. Writing
>> a value of '0' to this file disables the feature. Writing a
>> value of '-1' to this file resets the value to the default
>> setting.
>
> we disabled the wbt, issue is happening much sooner. The logs are attached
> 1/ "dmesg-20221011.log" form kernel messages
> 2/ "command.logs" from execution of
> (cd /sys/kernel/debug/block/vdc && find . -type f -exec grep -aH . {} \;)
>
> Best regards,
> Jaroslav Pulchart
(+Ted)
Hi Jaroslav,
Please reply at the bottom of an email when posting on a Linux kernel mailing
list (see also https://en.wikipedia.org/wiki/Posting_style#Bottom-posting).
Hi Ted,
In the dmesg fragment provided by Jaroslav I only see references to ext4. Are
you perhaps aware of any recently introduced issues in the layers between ext4
and the block layer? For the attachment provided by Jaroslav, see also
https://lore.kernel.org/linux-block/CAK8fFZ6ruxHsXuGT4qarNxdLLQtAoLsSvV0buFQhdc+TKo3Tag@mail.gmail.com/T/#m97ece301ca9a47ee8a4976f6c35ffcf55669b248
Thank you,
Bart.
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: again? - Write I/O queue hangup at random on recent Linus' kernels
2022-10-11 15:15 ` Jaroslav Pulchart
2022-10-11 16:53 ` Bart Van Assche
@ 2022-10-12 2:05 ` Yu Kuai
2022-10-12 13:07 ` Ming Lei
2 siblings, 0 replies; 9+ messages in thread
From: Yu Kuai @ 2022-10-12 2:05 UTC (permalink / raw)
To: Jaroslav Pulchart, Bart Van Assche, linux-block
Cc: Igor Raits, Daniel Secik, David Krupicka, yukuai (C)
Hi,
在 2022/10/11 23:15, Jaroslav Pulchart 写道:
> Hello,
>
> we disabled the wbt, issue is happening much sooner. The logs are attached
> 1/ "dmesg-20221011.log" form kernel messages
> 2/ "command.logs" from execution of
> (cd /sys/kernel/debug/block/vdc && find . -type f -exec grep -aH . {} \;)
>
In the log, I found that many requests are stuck in the driver, for
example:
./hctx24/busy:00000000e790f153 {.op=WRITE, .cmd_flags=SYNC|NOMERGE,
.rq_flags=IO_STAT|STATS, .state=in_flight, .tag=234, .internal_tag=-1}
state=in_flight means the rq is issued to driver, and in_flight is set
in blk_mq_start_request().
Can you have a check when the problem triggered, the log in 'hctx*/busy'
stays the same so that we can be sure io is stuck in driver?
Thanks,
Kuai
> Best regards,
> Jaroslav Pulchart
>
> čt 6. 10. 2022 v 18:57 odesílatel Bart Van Assche <bvanassche@acm.org> napsal:
>>
>> On 10/6/22 05:36, Jaroslav Pulchart wrote:
>>> I apply the
>>> echo 0 > /sys/block/vdc/queue/wbt_lat_usec
>>> at the production servers. I expect it will disable wbt. Could you
>>> please confirm that my expectation is correct?
>>
>> Hi Jaroslav,
>>
>> I have no experience with WBT. But what I found in the documentation seems
>> to confirm that the above command is sufficient to disable WBT:
>>
>> What: /sys/block/<disk>/queue/wbt_lat_usec
>> Date: November 2016
>> Contact: linux-block@vger.kernel.org
>> Description:
>> [RW] If the device is registered for writeback throttling, then
>> this file shows the target minimum read latency. If this latency
>> is exceeded in a given window of time (see wb_window_usec), then
>> the writeback throttling will start scaling back writes. Writing
>> a value of '0' to this file disables the feature. Writing a
>> value of '-1' to this file resets the value to the default
>> setting.
>>
>>
>> Best regards,
>>
>> Bart.
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: again? - Write I/O queue hangup at random on recent Linus' kernels
2022-10-11 15:15 ` Jaroslav Pulchart
2022-10-11 16:53 ` Bart Van Assche
2022-10-12 2:05 ` Yu Kuai
@ 2022-10-12 13:07 ` Ming Lei
2 siblings, 0 replies; 9+ messages in thread
From: Ming Lei @ 2022-10-12 13:07 UTC (permalink / raw)
To: Jaroslav Pulchart
Cc: Bart Van Assche, linux-block, Igor Raits, Daniel Secik, David Krupicka
On Tue, Oct 11, 2022 at 05:15:05PM +0200, Jaroslav Pulchart wrote:
> Hello,
>
> we disabled the wbt, issue is happening much sooner. The logs are attached
> 1/ "dmesg-20221011.log" form kernel messages
> 2/ "command.logs" from execution of
> (cd /sys/kernel/debug/block/vdc && find . -type f -exec grep -aH . {} \;)
>
From command.logs, looks like it is one qemu or virtio-blk issue.
Maybe you can try to revert 0e9911fa768f ("virtio-blk: support mq_ops->queue_rqs()")
and see if it makes difference.
[1] all busy tags points to in-flight IOs
grep busy temp/command.logs | grep -v -E "dispatch_busy|busy=0"
./hctx27/tags:busy=3
./hctx27/busy:00000000e4e3af26 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=167, .internal_tag=-1}
./hctx27/busy:00000000a9d6975f {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=168, .internal_tag=-1}
./hctx27/busy:00000000474663fc {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=169, .internal_tag=-1}
./hctx26/tags:busy=2
./hctx26/busy:00000000f32dd525 {.op=WRITE, .cmd_flags=SYNC, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=107, .internal_tag=-1}
./hctx26/busy:0000000055297a93 {.op=READ, .cmd_flags=FAILFAST_DEV|FAILFAST_TRANSPORT|FAILFAST_DRIVER|RAHEAD, .rq_flags=IO_STAT|STATS, .state=in_flight, .tag=108, .internal_tag=-1}
...
Thanks,
Ming
^ permalink raw reply [flat|nested] 9+ messages in thread
end of thread, other threads:[~2022-10-12 13:07 UTC | newest]
Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-10-05 19:43 again? - Write I/O queue hangup at random on recent Linus' kernels Jaroslav Pulchart
2022-10-05 21:03 ` Bart Van Assche
2022-10-06 12:36 ` Jaroslav Pulchart
2022-10-06 14:44 ` Ming Lei
2022-10-06 16:57 ` Bart Van Assche
2022-10-11 15:15 ` Jaroslav Pulchart
2022-10-11 16:53 ` Bart Van Assche
2022-10-12 2:05 ` Yu Kuai
2022-10-12 13:07 ` Ming Lei
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.