* Re: [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
[not found] <20240909154237.3656000-2-cassel@kernel.org>
@ 2024-10-21 10:58 ` Lai, Yi
2024-10-21 12:07 ` Niklas Cassel
0 siblings, 1 reply; 10+ messages in thread
From: Lai, Yi @ 2024-10-21 10:58 UTC (permalink / raw)
To: Niklas Cassel
Cc: Damien Le Moal, Hannes Reinecke, Martin K. Petersen, Igor Pylypiv,
Niklas Cassel, linux-ide, yi1.lai, syzkaller-bugs, linux-kernel
Hi Niklas Cassel,
Greetings!
I used Syzkaller and found that there is INFO: task hung in blk_mq_get_tag in v6.12-rc3
After bisection and the first bad commit is:
"
e5dd410acb34 ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
"
All detailed into can be found at:
https://github.com/laifryiee/syzkaller_logs/tree/main/241018_105830_blk_mq_get_tag
Syzkaller repro code:
https://github.com/laifryiee/syzkaller_logs/tree/main/241018_105830_blk_mq_get_tag/repro.c
Syzkaller repro syscall steps:
https://github.com/laifryiee/syzkaller_logs/tree/main/241018_105830_blk_mq_get_tag/repro.prog
Syzkaller report:
https://github.com/laifryiee/syzkaller_logs/tree/main/241018_105830_blk_mq_get_tag/repro.report
Kconfig(make olddefconfig):
https://github.com/laifryiee/syzkaller_logs/tree/main/241018_105830_blk_mq_get_tag/kconfig_origin
Bisect info:
https://github.com/laifryiee/syzkaller_logs/tree/main/241018_105830_blk_mq_get_tag/bisect_info.log
bzImage:
https://github.com/laifryiee/syzkaller_logs/raw/refs/heads/main/241018_105830_blk_mq_get_tag/bzImage_8e929cb546ee42c9a61d24fae60605e9e3192354
Issue dmesg:
https://github.com/laifryiee/syzkaller_logs/blob/main/241018_105830_blk_mq_get_tag/8e929cb546ee42c9a61d24fae60605e9e3192354_dmesg.log
"
[ 300.375482] INFO: task kworker/u8:0:11 blocked for more than 147 seconds.
[ 300.375906] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
[ 300.376204] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.376646] task:kworker/u8:0 state:D stack:0 pid:11 tgid:11 ppid:2 flags:0x00004000
[ 300.377158] Workqueue: writeback wb_workfn (flush-8:0)
[ 300.377479] Call Trace:
[ 300.377624] <TASK>
[ 300.377760] __schedule+0xe13/0x33a0
[ 300.377985] ? __pfx___schedule+0x10/0x10
[ 300.378222] ? lock_release+0x441/0x870
[ 300.378457] ? __pfx_lock_release+0x10/0x10
[ 300.378704] ? trace_lock_acquire+0x139/0x1b0
[ 300.378982] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.379296] ? kthread_data+0x61/0xd0
[ 300.379555] schedule+0xf6/0x3f0
[ 300.379754] io_schedule+0xce/0x150
[ 300.379968] rq_qos_wait+0x1c5/0x310
[ 300.380181] ? __pfx_wbt_cleanup_cb+0x10/0x10
[ 300.380437] ? __pfx_rq_qos_wait+0x10/0x10
[ 300.380681] ? __pfx_lock_release+0x10/0x10
[ 300.380925] ? __pfx_rq_qos_wake_function+0x10/0x10
[ 300.381214] ? __pfx_wbt_inflight_cb+0x10/0x10
[ 300.381479] ? do_raw_spin_unlock+0x15c/0x210
[ 300.381743] wbt_wait+0x1ec/0x400
[ 300.381946] ? __pfx_wbt_wait+0x10/0x10
[ 300.382174] ? __pfx_dd_bio_merge+0x10/0x10
[ 300.382437] ? __pfx_wbt_wait+0x10/0x10
[ 300.382667] __rq_qos_throttle+0x5f/0xb0
[ 300.382913] blk_mq_submit_bio+0x8ad/0x2a20
[ 300.383157] ? __kasan_check_read+0x15/0x20
[ 300.383438] ? __pfx_blk_mq_submit_bio+0x10/0x10
[ 300.383708] ? __pfx_mark_lock.part.0+0x10/0x10
[ 300.383974] ? __this_cpu_preempt_check+0x21/0x30
[ 300.384260] ? __this_cpu_preempt_check+0x21/0x30
[ 300.384532] ? lock_release+0x441/0x870
[ 300.384765] __submit_bio+0x18d/0x500
[ 300.384985] ? __pfx___submit_bio+0x10/0x10
[ 300.385234] ? __this_cpu_preempt_check+0x21/0x30
[ 300.385509] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.385875] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.386186] ? kvm_clock_get_cycles+0x43/0x70
[ 300.386451] submit_bio_noacct_nocheck+0x6a0/0xcc0
[ 300.386729] ? __pfx_submit_bio_noacct_nocheck+0x10/0x10
[ 300.387049] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.387361] submit_bio_noacct+0x61d/0x1dc0
[ 300.387612] submit_bio+0xce/0x480
[ 300.387819] submit_bh_wbc+0x58a/0x740
[ 300.388052] __block_write_full_folio+0x7a1/0xed0
[ 300.388327] ? __pfx_blkdev_get_block+0x10/0x10
[ 300.388599] block_write_full_folio+0x2e6/0x3a0
[ 300.388880] ? __pfx_blkdev_get_block+0x10/0x10
[ 300.389147] ? __pfx_blkdev_get_block+0x10/0x10
[ 300.389414] write_cache_pages+0xbc/0x140
[ 300.389654] ? __pfx_block_write_full_folio+0x10/0x10
[ 300.389954] ? __pfx_write_cache_pages+0x10/0x10
[ 300.390224] ? __this_cpu_preempt_check+0x21/0x30
[ 300.390504] blkdev_writepages+0xa5/0xf0
[ 300.390738] ? __pfx_blkdev_writepages+0x10/0x10
[ 300.391016] ? __pfx_do_raw_spin_lock+0x10/0x10
[ 300.391293] ? do_raw_spin_unlock+0x15c/0x210
[ 300.391573] ? __pfx_blkdev_writepages+0x10/0x10
[ 300.391841] do_writepages+0x1c3/0x8a0
[ 300.392068] ? __pfx_do_writepages+0x10/0x10
[ 300.392323] ? __pfx_lock_release+0x10/0x10
[ 300.392568] ? lock_release+0x441/0x870
[ 300.392805] __writeback_single_inode+0x124/0xe10
[ 300.393081] ? wbc_attach_and_unlock_inode+0x5a9/0x950
[ 300.393397] writeback_sb_inodes+0x63b/0x1000
[ 300.393661] ? __pfx_writeback_sb_inodes+0x10/0x10
[ 300.393935] ? lock_acquire.part.0+0x152/0x390
[ 300.394230] ? __sanitizer_cov_trace_const_cmp8+0x1c/0x30
[ 300.394544] __writeback_inodes_wb+0xc8/0x280
[ 300.394806] wb_writeback+0x717/0xaf0
[ 300.395039] ? __pfx_wb_writeback+0x10/0x10
[ 300.395290] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.395589] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.395868] ? get_nr_dirty_inodes+0x12c/0x1b0
[ 300.396134] ? lockdep_hardirqs_on+0x89/0x110
[ 300.396393] wb_workfn+0x76c/0xc90
[ 300.396597] ? __pfx_lock_acquire.part.0+0x10/0x10
[ 300.396882] ? __pfx_wb_workfn+0x10/0x10
[ 300.397110] ? rcu_is_watching+0x19/0xc0
[ 300.397354] process_one_work+0x92e/0x1b50
[ 300.397594] ? lock_acquire.part.0+0x152/0x390
[ 300.397879] ? __pfx_process_one_work+0x10/0x10
[ 300.398150] ? move_linked_works+0x1bf/0x2c0
[ 300.398407] ? __this_cpu_preempt_check+0x21/0x30
[ 300.398690] ? assign_work+0x19f/0x250
[ 300.398920] ? lock_is_held_type+0xef/0x150
[ 300.399174] worker_thread+0x68d/0xe90
[ 300.399428] kthread+0x35a/0x470
[ 300.399623] ? __pfx_worker_thread+0x10/0x10
[ 300.399874] ? __pfx_kthread+0x10/0x10
[ 300.400100] ret_from_fork+0x56/0x90
[ 300.400315] ? __pfx_kthread+0x10/0x10
[ 300.400540] ret_from_fork_asm+0x1a/0x30
[ 300.400783] </TASK>
[ 300.400928] INFO: task kworker/u8:2:36 blocked for more than 147 seconds.
[ 300.401309] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
[ 300.401613] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.402046] task:kworker/u8:2 state:D stack:0 pid:36 tgid:36 ppid:2 flags:0x00004000
[ 300.402638] Workqueue: writeback wb_workfn (flush-8:0)
[ 300.402941] Call Trace:
[ 300.403083] <TASK>
[ 300.403214] __schedule+0xe13/0x33a0
[ 300.403458] ? __pfx___schedule+0x10/0x10
[ 300.403686] ? lock_release+0x441/0x870
[ 300.403909] ? __pfx_lock_release+0x10/0x10
[ 300.404146] ? trace_lock_acquire+0x139/0x1b0
[ 300.404399] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.404701] ? kthread_data+0x61/0xd0
[ 300.404915] schedule+0xf6/0x3f0
[ 300.405106] io_schedule+0xce/0x150
[ 300.405309] blk_mq_get_tag+0x5e7/0xce0
[ 300.405531] ? __pfx_blk_mq_get_tag+0x10/0x10
[ 300.405771] ? __pfx_wbt_cleanup_cb+0x10/0x10
[ 300.406011] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.406288] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.406579] ? __pfx_rq_qos_wake_function+0x10/0x10
[ 300.406848] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.407136] ? dd_limit_depth+0x21e/0x2a0
[ 300.407380] ? __pfx_dd_limit_depth+0x10/0x10
[ 300.407625] __blk_mq_alloc_requests+0x6f6/0x1720
[ 300.407901] ? __pfx___blk_mq_alloc_requests+0x10/0x10
[ 300.408186] ? __pfx_wbt_wait+0x10/0x10
[ 300.408405] blk_mq_submit_bio+0x93c/0x2a20
[ 300.408632] ? __kasan_check_read+0x15/0x20
[ 300.408866] ? __pfx_blk_mq_submit_bio+0x10/0x10
[ 300.409117] ? __pfx_mark_lock.part.0+0x10/0x10
[ 300.409364] ? __this_cpu_preempt_check+0x21/0x30
[ 300.409626] ? __this_cpu_preempt_check+0x21/0x30
[ 300.409883] ? lock_release+0x441/0x870
[ 300.410098] __submit_bio+0x18d/0x500
[ 300.410303] ? __pfx___submit_bio+0x10/0x10
[ 300.410534] ? __this_cpu_preempt_check+0x21/0x30
[ 300.410790] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.411135] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.411440] ? kvm_clock_get_cycles+0x43/0x70
[ 300.411690] submit_bio_noacct_nocheck+0x6a0/0xcc0
[ 300.411958] ? __pfx_submit_bio_noacct_nocheck+0x10/0x10
[ 300.412249] ? lock_is_held_type+0xef/0x150
[ 300.412484] submit_bio_noacct+0x61d/0x1dc0
[ 300.412718] submit_bio+0xce/0x480
[ 300.412911] ext4_io_submit+0xb0/0x150
[ 300.413128] ext4_do_writepages+0xa54/0x2f30
[ 300.413372] ? __this_cpu_preempt_check+0x21/0x30
[ 300.413638] ? __pfx_ext4_do_writepages+0x10/0x10
[ 300.413892] ? rcu_is_watching+0x19/0xc0
[ 300.414113] ? __this_cpu_preempt_check+0x21/0x30
[ 300.414376] ? lock_is_held_type+0xef/0x150
[ 300.414616] ext4_writepages+0x35c/0x7c0
[ 300.414836] ? __pfx_ext4_writepages+0x10/0x10
[ 300.415087] ? lock_release+0x441/0x870
[ 300.415313] ? do_raw_spin_unlock+0x15c/0x210
[ 300.415576] ? __pfx_ext4_writepages+0x10/0x10
[ 300.415824] do_writepages+0x1c3/0x8a0
[ 300.416039] ? __pfx_do_writepages+0x10/0x10
[ 300.416278] ? __pfx_lock_release+0x10/0x10
[ 300.416510] ? __pfx_lock_release+0x10/0x10
[ 300.416754] __writeback_single_inode+0x124/0xe10
[ 300.417016] ? wbc_attach_and_unlock_inode+0x5a9/0x950
[ 300.417301] writeback_sb_inodes+0x63b/0x1000
[ 300.417546] ? lock_release+0x441/0x870
[ 300.417772] ? __pfx_writeback_sb_inodes+0x10/0x10
[ 300.418039] ? lock_acquire.part.0+0x152/0x390
[ 300.418321] ? __sanitizer_cov_trace_const_cmp8+0x1c/0x30
[ 300.418616] __writeback_inodes_wb+0xc8/0x280
[ 300.418865] wb_writeback+0x717/0xaf0
[ 300.419082] ? __pfx_wb_writeback+0x10/0x10
[ 300.419335] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.419598] ? get_nr_dirty_inodes+0x12c/0x1b0
[ 300.419847] ? lockdep_hardirqs_on+0x89/0x110
[ 300.420094] wb_workfn+0x7b5/0xc90
[ 300.420291] ? __pfx_lock_acquire.part.0+0x10/0x10
[ 300.420561] ? __pfx_wb_workfn+0x10/0x10
[ 300.420780] ? rcu_is_watching+0x19/0xc0
[ 300.421017] process_one_work+0x92e/0x1b50
[ 300.421245] ? lock_acquire.part.0+0x152/0x390
[ 300.421498] ? __pfx_process_one_work+0x10/0x10
[ 300.421743] ? move_linked_works+0x1bf/0x2c0
[ 300.421976] ? __this_cpu_preempt_check+0x21/0x30
[ 300.422236] ? assign_work+0x19f/0x250
[ 300.422442] ? lock_is_held_type+0xef/0x150
[ 300.422673] worker_thread+0x68d/0xe90
[ 300.422896] kthread+0x35a/0x470
[ 300.423074] ? __pfx_worker_thread+0x10/0x10
[ 300.423306] ? __pfx_kthread+0x10/0x10
[ 300.423538] ret_from_fork+0x56/0x90
[ 300.423735] ? __pfx_kthread+0x10/0x10
[ 300.423944] ret_from_fork_asm+0x1a/0x30
[ 300.424171] </TASK>
[ 300.424303] INFO: task kworker/1:2:80 blocked for more than 147 seconds.
[ 300.424649] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
[ 300.424930] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.425332] task:kworker/1:2 state:D stack:0 pid:80 tgid:80 ppid:2 flags:0x00004000
[ 300.425818] Workqueue: events ata_scsi_dev_rescan
[ 300.426080] Call Trace:
[ 300.426217] <TASK>
[ 300.426340] __schedule+0xe13/0x33a0
[ 300.426545] ? __pfx___schedule+0x10/0x10
[ 300.426761] ? lock_release+0x441/0x870
[ 300.426977] ? __pfx_lock_release+0x10/0x10
[ 300.427204] ? _raw_spin_unlock_irq+0x3c/0x60
[ 300.427452] schedule+0xf6/0x3f0
[ 300.427631] io_schedule+0xce/0x150
[ 300.427820] blk_mq_get_tag+0x5e7/0xce0
[ 300.428032] ? __pfx_blk_mq_get_tag+0x10/0x10
[ 300.428264] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.428542] __blk_mq_alloc_requests+0x6f6/0x1720
[ 300.428790] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.429077] ? __pfx___blk_mq_alloc_requests+0x10/0x10
[ 300.429352] blk_mq_alloc_request+0x655/0x930
[ 300.429586] ? __pfx_blk_mq_alloc_request+0x10/0x10
[ 300.429840] ? __lock_acquire+0xd87/0x5c90
[ 300.430067] scsi_execute_cmd+0x223/0x1040
[ 300.430294] ? __this_cpu_preempt_check+0x21/0x30
[ 300.430540] ? __pfx_scsi_execute_cmd+0x10/0x10
[ 300.430781] ? __pfx_lock_acquire.part.0+0x10/0x10
[ 300.431038] scsi_vpd_inquiry+0xdf/0x220
[ 300.431251] ? __pfx_scsi_vpd_inquiry+0x10/0x10
[ 300.431502] ? debug_smp_processor_id+0x20/0x30
[ 300.431741] ? rcu_is_watching+0x19/0xc0
[ 300.431953] scsi_get_vpd_size+0x11e/0x310
[ 300.432168] ? __mutex_lock+0x230/0x1490
[ 300.432377] ? __pfx_scsi_get_vpd_size+0x10/0x10
[ 300.432619] ? scsi_rescan_device+0x33/0x360
[ 300.432845] ? __pfx_mark_lock.part.0+0x10/0x10
[ 300.433083] ? __this_cpu_preempt_check+0x21/0x30
[ 300.433330] ? lock_acquire.part.0+0x152/0x390
[ 300.433565] ? __pfx___mutex_lock+0x10/0x10
[ 300.433791] scsi_get_vpd_buf+0x30/0x180
[ 300.434006] scsi_attach_vpd+0xf8/0x5b0
[ 300.434218] scsi_rescan_device+0x106/0x360
[ 300.434446] ata_scsi_dev_rescan+0x1d2/0x470
[ 300.434684] process_one_work+0x92e/0x1b50
[ 300.434904] ? lock_acquire.part.0+0x152/0x390
[ 300.435154] ? __pfx_process_one_work+0x10/0x10
[ 300.435412] ? move_linked_works+0x1bf/0x2c0
[ 300.435639] ? __this_cpu_preempt_check+0x21/0x30
[ 300.435891] ? assign_work+0x19f/0x250
[ 300.436089] ? lock_is_held_type+0xef/0x150
[ 300.436313] worker_thread+0x68d/0xe90
[ 300.436525] kthread+0x35a/0x470
[ 300.436699] ? __pfx_worker_thread+0x10/0x10
[ 300.436924] ? __pfx_kthread+0x10/0x10
[ 300.437125] ret_from_fork+0x56/0x90
[ 300.437317] ? __pfx_kthread+0x10/0x10
[ 300.437517] ret_from_fork_asm+0x1a/0x30
[ 300.437736] </TASK>
[ 300.437858] INFO: task jbd2/sda-8:104 blocked for more than 147 seconds.
[ 300.438192] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
[ 300.438465] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.438852] task:jbd2/sda-8 state:D stack:0 pid:104 tgid:104 ppid:2 flags:0x00004000
[ 300.439339] Call Trace:
[ 300.439475] <TASK>
[ 300.439595] __schedule+0xe13/0x33a0
[ 300.439794] ? __pfx___schedule+0x10/0x10
[ 300.440005] ? lock_release+0x441/0x870
[ 300.440212] ? __pfx_lock_release+0x10/0x10
[ 300.440431] ? trace_lock_acquire+0x139/0x1b0
[ 300.440666] ? lock_acquire+0x80/0xb0
[ 300.440860] ? schedule+0x216/0x3f0
[ 300.441051] schedule+0xf6/0x3f0
[ 300.441229] io_schedule+0xce/0x150
[ 300.441417] blk_mq_get_tag+0x5e7/0xce0
[ 300.441628] ? __pfx_blk_mq_get_tag+0x10/0x10
[ 300.441859] ? lock_release+0x441/0x870
[ 300.442063] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.442326] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.442596] ? blk_mq_sched_try_merge+0xce/0x650
[ 300.442841] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.443123] ? dd_limit_depth+0x21e/0x2a0
[ 300.443358] ? __pfx_dd_limit_depth+0x10/0x10
[ 300.443591] __blk_mq_alloc_requests+0x6f6/0x1720
[ 300.443846] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.444131] ? __pfx___blk_mq_alloc_requests+0x10/0x10
[ 300.444403] ? __pfx_wbt_wait+0x10/0x10
[ 300.444610] blk_mq_submit_bio+0x93c/0x2a20
[ 300.444829] ? __pfx___lock_acquire+0x10/0x10
[ 300.445064] ? __pfx_blk_mq_submit_bio+0x10/0x10
[ 300.445307] ? __this_cpu_preempt_check+0x21/0x30
[ 300.445559] ? __this_cpu_preempt_check+0x21/0x30
[ 300.445807] ? lock_release+0x441/0x870
[ 300.446014] __submit_bio+0x18d/0x500
[ 300.446211] ? __pfx___submit_bio+0x10/0x10
[ 300.446432] ? __this_cpu_preempt_check+0x21/0x30
[ 300.446677] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.447005] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.447282] ? kvm_clock_get_cycles+0x43/0x70
[ 300.447534] submit_bio_noacct_nocheck+0x6a0/0xcc0
[ 300.447787] ? __pfx_submit_bio_noacct_nocheck+0x10/0x10
[ 300.448067] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.448330] submit_bio_noacct+0x61d/0x1dc0
[ 300.448556] submit_bio+0xce/0x480
[ 300.448742] submit_bh_wbc+0x58a/0x740
[ 300.448947] submit_bh+0x2b/0x40
[ 300.449124] jbd2_journal_commit_transaction+0x2a09/0x65e0
[ 300.449431] ? __pfx_jbd2_journal_commit_transaction+0x10/0x10
[ 300.449737] ? __this_cpu_preempt_check+0x21/0x30
[ 300.449983] ? lock_release+0x441/0x870
[ 300.450196] ? __this_cpu_preempt_check+0x21/0x30
[ 300.450445] ? _raw_spin_unlock_irqrestore+0x45/0x70
[ 300.450703] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.450998] kjournald2+0x204/0x790
[ 300.451194] ? __pfx_kjournald2+0x10/0x10
[ 300.451416] ? lockdep_hardirqs_on+0x89/0x110
[ 300.451647] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.451917] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.452194] ? __kthread_parkme+0x15d/0x230
[ 300.452419] kthread+0x35a/0x470
[ 300.452594] ? __pfx_kjournald2+0x10/0x10
[ 300.452803] ? __pfx_kthread+0x10/0x10
[ 300.453004] ret_from_fork+0x56/0x90
[ 300.453198] ? __pfx_kthread+0x10/0x10
[ 300.453406] ret_from_fork_asm+0x1a/0x30
[ 300.453639] </TASK>
[ 300.453765] INFO: task auditd:239 blocked for more than 147 seconds.
[ 300.454094] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
[ 300.454367] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.454757] task:auditd state:D stack:0 pid:239 tgid:239 ppid:1 flags:0x00000002
[ 300.455219] Call Trace:
[ 300.455363] <TASK>
[ 300.455481] __schedule+0xe13/0x33a0
[ 300.455676] ? __pfx___schedule+0x10/0x10
[ 300.455883] ? lock_release+0x441/0x870
[ 300.456086] ? __pfx_lock_release+0x10/0x10
[ 300.456300] ? trace_lock_acquire+0x139/0x1b0
[ 300.456530] ? lock_acquire+0x80/0xb0
[ 300.456722] ? schedule+0x216/0x3f0
[ 300.456911] schedule+0xf6/0x3f0
[ 300.457085] io_schedule+0xce/0x150
[ 300.457271] bit_wait_io+0x1f/0x100
[ 300.457457] __wait_on_bit+0x68/0x1b0
[ 300.457649] ? __pfx_bit_wait_io+0x10/0x10
[ 300.457867] out_of_line_wait_on_bit+0xe6/0x120
[ 300.458102] ? __pfx_out_of_line_wait_on_bit+0x10/0x10
[ 300.458369] ? __pfx_wake_bit_function+0x10/0x10
[ 300.458606] ? __might_sleep+0xa3/0x170
[ 300.458808] do_get_write_access+0x83b/0x1010
[ 300.459045] jbd2_journal_get_write_access+0x1e4/0x270
[ 300.459308] __ext4_journal_get_write_access+0x72/0x3b0
[ 300.459591] ext4_reserve_inode_write+0x199/0x280
[ 300.459833] ? ext4_dirty_inode+0xeb/0x140
[ 300.460044] __ext4_mark_inode_dirty+0x18b/0x8c0
[ 300.460282] ? debug_smp_processor_id+0x20/0x30
[ 300.460515] ? __pfx___ext4_mark_inode_dirty+0x10/0x10
[ 300.460773] ? trace_jbd2_handle_start+0x77/0x210
[ 300.461017] ? jbd2__journal_start+0xff/0x6b0
[ 300.461246] ? __ext4_journal_start_sb+0x1f8/0x600
[ 300.461490] ? ext4_dirty_inode+0xb3/0x140
[ 300.461703] ? __pfx_ext4_dirty_inode+0x10/0x10
[ 300.461937] ext4_dirty_inode+0xeb/0x140
[ 300.462139] ? rcu_is_watching+0x19/0xc0
[ 300.462343] __mark_inode_dirty+0x1d0/0xd50
[ 300.462557] ? __pfx_generic_write_checks+0x10/0x10
[ 300.462810] generic_update_time+0xe0/0x110
[ 300.463032] file_modified+0x1af/0x1e0
[ 300.463233] ext4_buffered_write_iter+0x101/0x3e0
[ 300.463493] ext4_file_write_iter+0x8b8/0x1ab0
[ 300.463722] ? __pfx_lock_acquire.part.0+0x10/0x10
[ 300.463971] ? debug_smp_processor_id+0x20/0x30
[ 300.464208] ? __pfx_ext4_file_write_iter+0x10/0x10
[ 300.464459] ? __this_cpu_preempt_check+0x21/0x30
[ 300.464701] ? lock_is_held_type+0xef/0x150
[ 300.464920] vfs_write+0xc46/0x1120
[ 300.465106] ? __pfx_ext4_file_write_iter+0x10/0x10
[ 300.465356] ? __pfx_vfs_write+0x10/0x10
[ 300.465572] ? mutex_lock_nested+0x1f/0x30
[ 300.465788] ksys_write+0x14f/0x290
[ 300.465974] ? __pfx_ksys_write+0x10/0x10
[ 300.466189] __x64_sys_write+0x7b/0xc0
[ 300.466384] ? syscall_trace_enter+0x9b/0x230
[ 300.466610] x64_sys_call+0x1685/0x20d0
[ 300.466810] do_syscall_64+0x6d/0x140
[ 300.467007] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 300.467264] RIP: 0033:0x7f0f0ad3ebcf
[ 300.467465] RSP: 002b:00007fffd00b5a30 EFLAGS: 00000293 ORIG_RAX: 0000000000000001
[ 300.467838] RAX: ffffffffffffffda RBX: 00000000000000e0 RCX: 00007f0f0ad3ebcf
[ 300.468186] RDX: 00000000000000e0 RSI: 000055b1be1b80a0 RDI: 0000000000000005
[ 300.468535] RBP: 000055b1be1b80a0 R08: 0000000000000000 R09: 00007f0f0adb14e0
[ 300.468883] R10: 00007f0f0adb13e0 R11: 0000000000000293 R12: 00000000000000e0
[ 300.469231] R13: 000055b1be1ae2a0 R14: 00000000000000e0 R15: 00007f0f0adf69e0
[ 300.469591] </TASK>
[ 300.469711] INFO: task in:imjournal:321 blocked for more than 147 seconds.
[ 300.470045] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
[ 300.470311] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.470687] task:in:imjournal state:D stack:0 pid:321 tgid:302 ppid:1 flags:0x00000002
[ 300.471144] Call Trace:
[ 300.471273] <TASK>
[ 300.471406] __schedule+0xe13/0x33a0
[ 300.471601] ? __pfx___schedule+0x10/0x10
[ 300.471807] ? lock_release+0x441/0x870
[ 300.472008] ? __pfx_lock_release+0x10/0x10
[ 300.472221] ? trace_lock_acquire+0x139/0x1b0
[ 300.472450] ? lock_acquire+0x80/0xb0
[ 300.472640] ? schedule+0x216/0x3f0
[ 300.472826] schedule+0xf6/0x3f0
[ 300.472999] io_schedule+0xce/0x150
[ 300.473183] bit_wait_io+0x1f/0x100
[ 300.473368] __wait_on_bit+0x68/0x1b0
[ 300.473560] ? __pfx_bit_wait_io+0x10/0x10
[ 300.473778] out_of_line_wait_on_bit+0xe6/0x120
[ 300.474010] ? __pfx_out_of_line_wait_on_bit+0x10/0x10
[ 300.474273] ? __pfx_wake_bit_function+0x10/0x10
[ 300.474512] ? __might_sleep+0xa3/0x170
[ 300.474714] do_get_write_access+0x83b/0x1010
[ 300.474951] jbd2_journal_get_write_access+0x1e4/0x270
[ 300.475215] __ext4_journal_get_write_access+0x72/0x3b0
[ 300.475496] __ext4_new_inode+0xfef/0x5320
[ 300.475720] ? __pfx___ext4_new_inode+0x10/0x10
[ 300.475955] ? __pfx___dquot_initialize+0x10/0x10
[ 300.476202] ? _raw_spin_unlock+0x31/0x60
[ 300.476409] ? d_splice_alias+0x4e8/0xe30
[ 300.476619] ext4_create+0x32e/0x550
[ 300.476815] ? __pfx_ext4_create+0x10/0x10
[ 300.477030] ? inode_permission+0xf4/0x650
[ 300.477239] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.477510] ? __pfx_ext4_create+0x10/0x10
[ 300.477723] lookup_open.isra.0+0x117c/0x1580
[ 300.477954] ? __pfx_lookup_open.isra.0+0x10/0x10
[ 300.478200] ? lock_acquire+0x80/0xb0
[ 300.478391] ? path_openat+0xd40/0x2bf0
[ 300.478599] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.478873] path_openat+0xdbf/0x2bf0
[ 300.479085] ? __pfx_path_openat+0x10/0x10
[ 300.479298] ? __this_cpu_preempt_check+0x21/0x30
[ 300.479553] ? lock_is_held_type+0xef/0x150
[ 300.479770] ? __this_cpu_preempt_check+0x21/0x30
[ 300.480019] do_filp_open+0x1cc/0x420
[ 300.480213] ? __pfx_do_filp_open+0x10/0x10
[ 300.480429] ? lock_release+0x441/0x870
[ 300.480638] ? do_raw_spin_unlock+0x15c/0x210
[ 300.480877] do_sys_openat2+0x185/0x1f0
[ 300.481078] ? __pfx_do_sys_openat2+0x10/0x10
[ 300.481306] ? __this_cpu_preempt_check+0x21/0x30
[ 300.481548] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.481864] ? lockdep_hardirqs_on+0x89/0x110
[ 300.482094] __x64_sys_openat+0x17a/0x240
[ 300.482304] ? __pfx___x64_sys_openat+0x10/0x10
[ 300.482539] ? __audit_syscall_entry+0x39c/0x500
[ 300.482784] x64_sys_call+0x1a52/0x20d0
[ 300.482988] do_syscall_64+0x6d/0x140
[ 300.483182] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 300.483450] RIP: 0033:0x7fd79d13e8c4
[ 300.483639] RSP: 002b:00007fd79c1fea40 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
[ 300.484009] RAX: ffffffffffffffda RBX: 00007fd794000c50 RCX: 00007fd79d13e8c4
[ 300.484357] RDX: 0000000000000241 RSI: 00007fd79c1feb80 RDI: 00000000ffffff9c
[ 300.484705] RBP: 00007fd79c1feb80 R08: 0000000000000000 R09: 0000000000000001
[ 300.485053] R10: 00000000000001b6 R11: 0000000000000293 R12: 0000000000000241
[ 300.485400] R13: 00007fd794000c50 R14: 0000000000000001 R15: 00007fd79402aba0
[ 300.485761] </TASK>
[ 300.485918] INFO: task repro:686 blocked for more than 147 seconds.
[ 300.486225] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
[ 300.486491] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.486868] task:repro state:D stack:0 pid:686 tgid:686 ppid:680 flags:0x00000006
[ 300.487345] Call Trace:
[ 300.487476] <TASK>
[ 300.487595] __schedule+0xe13/0x33a0
[ 300.487790] ? __pfx___schedule+0x10/0x10
[ 300.487995] ? lock_release+0x441/0x870
[ 300.488196] ? __pfx_lock_release+0x10/0x10
[ 300.488411] ? trace_lock_acquire+0x139/0x1b0
[ 300.488640] ? lock_acquire+0x80/0xb0
[ 300.488831] ? schedule+0x216/0x3f0
[ 300.489019] schedule+0xf6/0x3f0
[ 300.489193] io_schedule+0xce/0x150
[ 300.489378] blk_mq_get_tag+0x5e7/0xce0
[ 300.489584] ? __pfx_blk_mq_get_tag+0x10/0x10
[ 300.489811] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.490082] __blk_mq_alloc_requests+0x6f6/0x1720
[ 300.490323] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.490603] ? __pfx___blk_mq_alloc_requests+0x10/0x10
[ 300.490863] ? __this_cpu_preempt_check+0x21/0x30
[ 300.491108] ? lock_acquire.part.0+0x152/0x390
[ 300.491375] blk_mq_alloc_request+0x655/0x930
[ 300.491604] ? __pfx_blk_mq_alloc_request+0x10/0x10
[ 300.491865] scsi_execute_cmd+0x223/0x1040
[ 300.492081] ? debug_smp_processor_id+0x20/0x30
[ 300.492317] ? __pfx_scsi_execute_cmd+0x10/0x10
[ 300.492548] ? rcu_is_watching+0x19/0xc0
[ 300.492754] ? __kmalloc_noprof+0x34f/0x4a0
[ 300.492970] ? ata_cmd_ioctl+0x375/0x570
[ 300.493179] ata_cmd_ioctl+0x23c/0x570
[ 300.493378] ? __pfx_ata_cmd_ioctl+0x10/0x10
[ 300.493597] ? lock_release+0x441/0x870
[ 300.493802] ? __this_cpu_preempt_check+0x21/0x30
[ 300.494052] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.494321] ? security_capable+0x19d/0x1e0
[ 300.494545] ata_sas_scsi_ioctl+0x60a/0x7c0
[ 300.494758] ? mark_lock.part.0+0xf3/0x17b0
[ 300.494979] ? __pfx_ata_sas_scsi_ioctl+0x10/0x10
[ 300.495218] ? __pfx_mark_lock.part.0+0x10/0x10
[ 300.495473] ? __this_cpu_preempt_check+0x21/0x30
[ 300.495715] ? lock_is_held_type+0xef/0x150
[ 300.495935] ? __pfx_ata_scsi_ioctl+0x10/0x10
[ 300.496161] ata_scsi_ioctl+0x70/0x90
[ 300.496355] scsi_ioctl+0xb6f/0x1630
[ 300.496546] ? __might_sleep+0xa3/0x170
[ 300.496748] ? __pfx_scsi_ioctl+0x10/0x10
[ 300.496954] ? scsi_block_when_processing_errors+0x2c4/0x390
[ 300.497244] ? __pfx_scsi_block_when_processing_errors+0x10/0x10
[ 300.497546] ? __pfx___lock_acquire+0x10/0x10
[ 300.497770] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.498028] ? __sanitizer_cov_trace_const_cmp2+0x1c/0x30
[ 300.498298] ? do_vfs_ioctl+0x4fa/0x1920
[ 300.498502] ? __pfx_do_vfs_ioctl+0x10/0x10
[ 300.498718] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.498996] sg_ioctl+0xfb8/0x2880
[ 300.499180] ? __this_cpu_preempt_check+0x21/0x30
[ 300.499436] ? lock_release+0x441/0x870
[ 300.499640] ? __pfx_sg_ioctl+0x10/0x10
[ 300.499842] ? __this_cpu_preempt_check+0x21/0x30
[ 300.500081] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.500394] ? lockdep_hardirqs_on+0x89/0x110
[ 300.500621] ? trace_hardirqs_on+0x51/0x60
[ 300.500834] ? seqcount_lockdep_reader_access.constprop.0+0xc0/0xd0
[ 300.501149] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.501395] ? ktime_get_coarse_real_ts64+0xbf/0xf0
[ 300.501649] ? __pfx_sg_ioctl+0x10/0x10
[ 300.501849] __x64_sys_ioctl+0x1b5/0x230
[ 300.502055] x64_sys_call+0x1209/0x20d0
[ 300.502255] do_syscall_64+0x6d/0x140
[ 300.502447] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 300.502702] RIP: 0033:0x7f8b9783ee5d
[ 300.502890] RSP: 002b:00007ffc0329c228 EFLAGS: 00000206 ORIG_RAX: 0000000000000010
[ 300.503265] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f8b9783ee5d
[ 300.503629] RDX: 0000000020000080 RSI: 000000000000031f RDI: 0000000000000003
[ 300.503978] RBP: 00007ffc0329c240 R08: 00007ffc0329bfb8 R09: 00007ffc0329c240
[ 300.504326] R10: 0000000000000000 R11: 0000000000000206 R12: 00007ffc0329c398
[ 300.504674] R13: 0000000000401972 R14: 0000000000403e08 R15: 00007f8b97aff000
[ 300.505034] </TASK>
[ 300.505153] INFO: task repro:687 blocked for more than 147 seconds.
[ 300.505459] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
[ 300.505724] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.506102] task:repro state:D stack:0 pid:687 tgid:687 ppid:683 flags:0x00000006
[ 300.506557] Call Trace:
[ 300.506686] <TASK>
[ 300.506803] __schedule+0xe13/0x33a0
[ 300.507000] ? __pfx___schedule+0x10/0x10
[ 300.507206] ? lock_release+0x441/0x870
[ 300.507419] ? __pfx_lock_release+0x10/0x10
[ 300.507633] ? trace_lock_acquire+0x139/0x1b0
[ 300.507865] ? lock_acquire+0x80/0xb0
[ 300.508055] ? schedule+0x216/0x3f0
[ 300.508243] schedule+0xf6/0x3f0
[ 300.508418] io_schedule+0xce/0x150
[ 300.508602] blk_mq_get_tag+0x5e7/0xce0
[ 300.508807] ? __pfx_blk_mq_get_tag+0x10/0x10
[ 300.509034] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.509306] __blk_mq_alloc_requests+0x6f6/0x1720
[ 300.509548] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.509829] ? __pfx___blk_mq_alloc_requests+0x10/0x10
[ 300.510092] ? __this_cpu_preempt_check+0x21/0x30
[ 300.510335] ? lock_acquire.part.0+0x152/0x390
[ 300.510570] blk_mq_alloc_request+0x655/0x930
[ 300.510801] ? __pfx_blk_mq_alloc_request+0x10/0x10
[ 300.511072] scsi_execute_cmd+0x223/0x1040
[ 300.511290] ? debug_smp_processor_id+0x20/0x30
[ 300.511546] ? __pfx_scsi_execute_cmd+0x10/0x10
[ 300.511780] ? rcu_is_watching+0x19/0xc0
[ 300.511984] ? __kmalloc_noprof+0x34f/0x4a0
[ 300.512200] ? ata_cmd_ioctl+0x375/0x570
[ 300.512407] ata_cmd_ioctl+0x23c/0x570
[ 300.512607] ? __pfx_ata_cmd_ioctl+0x10/0x10
[ 300.512827] ? lock_release+0x441/0x870
[ 300.513032] ? __this_cpu_preempt_check+0x21/0x30
[ 300.513282] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.513552] ? security_capable+0x19d/0x1e0
[ 300.513772] ata_sas_scsi_ioctl+0x60a/0x7c0
[ 300.513985] ? mark_lock.part.0+0xf3/0x17b0
[ 300.514200] ? __pfx_ata_sas_scsi_ioctl+0x10/0x10
[ 300.514439] ? __pfx_mark_lock.part.0+0x10/0x10
[ 300.514676] ? __this_cpu_preempt_check+0x21/0x30
[ 300.514919] ? lock_is_held_type+0xef/0x150
[ 300.515136] ? __pfx_ata_scsi_ioctl+0x10/0x10
[ 300.515374] ata_scsi_ioctl+0x70/0x90
[ 300.515568] scsi_ioctl+0xb6f/0x1630
[ 300.515759] ? __might_sleep+0xa3/0x170
[ 300.515962] ? __pfx_scsi_ioctl+0x10/0x10
[ 300.516170] ? scsi_block_when_processing_errors+0x2c4/0x390
[ 300.516459] ? __pfx_scsi_block_when_processing_errors+0x10/0x10
[ 300.516759] ? __pfx___lock_acquire+0x10/0x10
[ 300.516983] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.517239] ? __sanitizer_cov_trace_const_cmp2+0x1c/0x30
[ 300.517511] ? do_vfs_ioctl+0x4fa/0x1920
[ 300.517715] ? __pfx_do_vfs_ioctl+0x10/0x10
[ 300.517931] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.518204] sg_ioctl+0xfb8/0x2880
[ 300.518383] ? __this_cpu_preempt_check+0x21/0x30
[ 300.518623] ? lock_release+0x441/0x870
[ 300.518826] ? __pfx_sg_ioctl+0x10/0x10
[ 300.519034] ? __this_cpu_preempt_check+0x21/0x30
[ 300.519274] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.519601] ? lockdep_hardirqs_on+0x89/0x110
[ 300.519828] ? trace_hardirqs_on+0x51/0x60
[ 300.520039] ? seqcount_lockdep_reader_access.constprop.0+0xc0/0xd0
[ 300.520351] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.520598] ? ktime_get_coarse_real_ts64+0xbf/0xf0
[ 300.520853] ? __pfx_sg_ioctl+0x10/0x10
[ 300.521053] __x64_sys_ioctl+0x1b5/0x230
[ 300.521260] x64_sys_call+0x1209/0x20d0
[ 300.521459] do_syscall_64+0x6d/0x140
[ 300.521651] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 300.521907] RIP: 0033:0x7f8b9783ee5d
[ 300.522092] RSP: 002b:00007ffc0329c228 EFLAGS: 00000206 ORIG_RAX: 0000000000000010
[ 300.522464] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f8b9783ee5d
[ 300.522815] RDX: 0000000020000080 RSI: 000000000000031f RDI: 0000000000000003
[ 300.523169] RBP: 00007ffc0329c240 R08: 00007ffc0329bfb8 R09: 00007ffc0329c240
[ 300.523531] R10: 0000000000000000 R11: 0000000000000206 R12: 00007ffc0329c398
[ 300.523881] R13: 0000000000401972 R14: 0000000000403e08 R15: 00007f8b97aff000
[ 300.524241] </TASK>
[ 300.524359] INFO: task repro:688 blocked for more than 147 seconds.
[ 300.524666] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
[ 300.524932] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.525308] task:repro state:D stack:0 pid:688 tgid:688 ppid:685 flags:0x00000006
[ 300.525762] Call Trace:
[ 300.525893] <TASK>
[ 300.526011] __schedule+0xe13/0x33a0
[ 300.526207] ? __pfx___schedule+0x10/0x10
[ 300.526413] ? lock_release+0x441/0x870
[ 300.526614] ? __pfx_lock_release+0x10/0x10
[ 300.526827] ? trace_lock_acquire+0x139/0x1b0
[ 300.527060] ? lock_acquire+0x80/0xb0
[ 300.527251] ? schedule+0x216/0x3f0
[ 300.527450] schedule+0xf6/0x3f0
[ 300.527624] io_schedule+0xce/0x150
[ 300.527807] blk_mq_get_tag+0x5e7/0xce0
[ 300.528012] ? __pfx_blk_mq_get_tag+0x10/0x10
[ 300.528238] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.528508] __blk_mq_alloc_requests+0x6f6/0x1720
[ 300.528749] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.529029] ? __pfx___blk_mq_alloc_requests+0x10/0x10
[ 300.529291] ? __this_cpu_preempt_check+0x21/0x30
[ 300.529533] ? lock_acquire.part.0+0x152/0x390
[ 300.529767] blk_mq_alloc_request+0x655/0x930
[ 300.529996] ? __pfx_blk_mq_alloc_request+0x10/0x10
[ 300.530259] scsi_execute_cmd+0x223/0x1040
[ 300.530476] ? debug_smp_processor_id+0x20/0x30
[ 300.530712] ? __pfx_scsi_execute_cmd+0x10/0x10
[ 300.530946] ? rcu_is_watching+0x19/0xc0
[ 300.531156] ? __kmalloc_noprof+0x34f/0x4a0
[ 300.531389] ? ata_cmd_ioctl+0x375/0x570
[ 300.531596] ata_cmd_ioctl+0x23c/0x570
[ 300.531795] ? __pfx_ata_cmd_ioctl+0x10/0x10
[ 300.532014] ? lock_release+0x441/0x870
[ 300.532219] ? __this_cpu_preempt_check+0x21/0x30
[ 300.532468] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.532738] ? security_capable+0x19d/0x1e0
[ 300.532959] ata_sas_scsi_ioctl+0x60a/0x7c0
[ 300.533172] ? mark_lock.part.0+0xf3/0x17b0
[ 300.533386] ? __pfx_ata_sas_scsi_ioctl+0x10/0x10
[ 300.533624] ? __pfx_mark_lock.part.0+0x10/0x10
[ 300.533863] ? __this_cpu_preempt_check+0x21/0x30
[ 300.534105] ? lock_is_held_type+0xef/0x150
[ 300.534323] ? __pfx_ata_scsi_ioctl+0x10/0x10
[ 300.534547] ata_scsi_ioctl+0x70/0x90
[ 300.534742] scsi_ioctl+0xb6f/0x1630
[ 300.534937] ? __might_sleep+0xa3/0x170
[ 300.535139] ? __pfx_scsi_ioctl+0x10/0x10
[ 300.535363] ? scsi_block_when_processing_errors+0x2c4/0x390
[ 300.535652] ? __pfx_scsi_block_when_processing_errors+0x10/0x10
[ 300.535953] ? __pfx___lock_acquire+0x10/0x10
[ 300.536176] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.536432] ? __sanitizer_cov_trace_const_cmp2+0x1c/0x30
[ 300.536702] ? do_vfs_ioctl+0x4fa/0x1920
[ 300.536906] ? __pfx_do_vfs_ioctl+0x10/0x10
[ 300.537122] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.537395] sg_ioctl+0xfb8/0x2880
[ 300.537574] ? __this_cpu_preempt_check+0x21/0x30
[ 300.537815] ? lock_release+0x441/0x870
[ 300.538019] ? __pfx_sg_ioctl+0x10/0x10
[ 300.538221] ? __this_cpu_preempt_check+0x21/0x30
[ 300.538462] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.538777] ? lockdep_hardirqs_on+0x89/0x110
[ 300.539006] ? trace_hardirqs_on+0x51/0x60
[ 300.539219] ? seqcount_lockdep_reader_access.constprop.0+0xc0/0xd0
[ 300.539546] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.539792] ? ktime_get_coarse_real_ts64+0xbf/0xf0
[ 300.540047] ? __pfx_sg_ioctl+0x10/0x10
[ 300.540246] __x64_sys_ioctl+0x1b5/0x230
[ 300.540452] x64_sys_call+0x1209/0x20d0
[ 300.540650] do_syscall_64+0x6d/0x140
[ 300.540842] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 300.541097] RIP: 0033:0x7f8b9783ee5d
[ 300.541282] RSP: 002b:00007ffc0329c228 EFLAGS: 00000206 ORIG_RAX: 0000000000000010
[ 300.541652] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f8b9783ee5d
[ 300.541999] RDX: 0000000020000080 RSI: 000000000000031f RDI: 0000000000000003
[ 300.542347] RBP: 00007ffc0329c240 R08: 00007ffc0329bfb8 R09: 00007ffc0329c240
[ 300.542695] R10: 0000000000000000 R11: 0000000000000206 R12: 00007ffc0329c398
[ 300.543048] R13: 0000000000401972 R14: 0000000000403e08 R15: 00007f8b97aff000
[ 300.543422] </TASK>
[ 300.543540] INFO: task repro:690 blocked for more than 147 seconds.
[ 300.543847] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
[ 300.544111] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.544487] task:repro state:D stack:0 pid:690 tgid:690 ppid:689 flags:0x00000006
[ 300.544939] Call Trace:
[ 300.545069] <TASK>
[ 300.545186] __schedule+0xe13/0x33a0
[ 300.545380] ? __pfx___schedule+0x10/0x10
[ 300.545585] ? lock_release+0x441/0x870
[ 300.545787] ? __pfx_lock_release+0x10/0x10
[ 300.546000] ? trace_lock_acquire+0x139/0x1b0
[ 300.546230] ? lock_acquire+0x80/0xb0
[ 300.546420] ? schedule+0x216/0x3f0
[ 300.546607] schedule+0xf6/0x3f0
[ 300.546781] io_schedule+0xce/0x150
[ 300.546967] blk_mq_get_tag+0x5e7/0xce0
[ 300.547174] ? __pfx_blk_mq_get_tag+0x10/0x10
[ 300.547416] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.547687] __blk_mq_alloc_requests+0x6f6/0x1720
[ 300.547929] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.548210] ? __pfx___blk_mq_alloc_requests+0x10/0x10
[ 300.548471] ? __this_cpu_preempt_check+0x21/0x30
[ 300.548714] ? lock_acquire.part.0+0x152/0x390
[ 300.548948] blk_mq_alloc_request+0x655/0x930
[ 300.549181] ? __pfx_blk_mq_alloc_request+0x10/0x10
[ 300.549443] scsi_execute_cmd+0x223/0x1040
[ 300.549660] ? debug_smp_processor_id+0x20/0x30
[ 300.549895] ? __pfx_scsi_execute_cmd+0x10/0x10
[ 300.550126] ? rcu_is_watching+0x19/0xc0
[ 300.550329] ? __kmalloc_noprof+0x34f/0x4a0
[ 300.550543] ? ata_cmd_ioctl+0x375/0x570
[ 300.550749] ata_cmd_ioctl+0x23c/0x570
[ 300.550950] ? __pfx_ata_cmd_ioctl+0x10/0x10
[ 300.551170] ? lock_release+0x441/0x870
[ 300.551391] ? __this_cpu_preempt_check+0x21/0x30
[ 300.551641] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.551911] ? security_capable+0x19d/0x1e0
[ 300.552131] ata_sas_scsi_ioctl+0x60a/0x7c0
[ 300.552344] ? mark_lock.part.0+0xf3/0x17b0
[ 300.552558] ? __pfx_ata_sas_scsi_ioctl+0x10/0x10
[ 300.552796] ? __pfx_mark_lock.part.0+0x10/0x10
[ 300.553033] ? __this_cpu_preempt_check+0x21/0x30
[ 300.553274] ? lock_is_held_type+0xef/0x150
[ 300.553491] ? __pfx_ata_scsi_ioctl+0x10/0x10
[ 300.553716] ata_scsi_ioctl+0x70/0x90
[ 300.553909] scsi_ioctl+0xb6f/0x1630
[ 300.554099] ? __might_sleep+0xa3/0x170
[ 300.554301] ? __pfx_scsi_ioctl+0x10/0x10
[ 300.554510] ? scsi_block_when_processing_errors+0x2c4/0x390
[ 300.554800] ? __pfx_scsi_block_when_processing_errors+0x10/0x10
[ 300.555103] ? __pfx___lock_acquire+0x10/0x10
[ 300.555350] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.555608] ? __sanitizer_cov_trace_const_cmp2+0x1c/0x30
[ 300.555877] ? do_vfs_ioctl+0x4fa/0x1920
[ 300.556082] ? __pfx_do_vfs_ioctl+0x10/0x10
[ 300.556297] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.556569] sg_ioctl+0xfb8/0x2880
[ 300.556747] ? __this_cpu_preempt_check+0x21/0x30
[ 300.556987] ? lock_release+0x441/0x870
[ 300.557189] ? __pfx_sg_ioctl+0x10/0x10
[ 300.557391] ? __this_cpu_preempt_check+0x21/0x30
[ 300.557631] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.557945] ? lockdep_hardirqs_on+0x89/0x110
[ 300.558171] ? trace_hardirqs_on+0x51/0x60
[ 300.558382] ? seqcount_lockdep_reader_access.constprop.0+0xc0/0xd0
[ 300.558695] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.558944] ? ktime_get_coarse_real_ts64+0xbf/0xf0
[ 300.559201] ? __pfx_sg_ioctl+0x10/0x10
[ 300.559427] __x64_sys_ioctl+0x1b5/0x230
[ 300.559635] x64_sys_call+0x1209/0x20d0
[ 300.559833] do_syscall_64+0x6d/0x140
[ 300.560025] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 300.560278] RIP: 0033:0x7f8b9783ee5d
[ 300.560463] RSP: 002b:00007ffc0329c228 EFLAGS: 00000206 ORIG_RAX: 0000000000000010
[ 300.560832] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f8b9783ee5d
[ 300.561180] RDX: 0000000020000080 RSI: 000000000000031f RDI: 0000000000000003
[ 300.561527] RBP: 00007ffc0329c240 R08: 00007ffc0329bfb8 R09: 00007ffc0329c240
[ 300.561877] R10: 0000000000000000 R11: 0000000000000206 R12: 00007ffc0329c398
[ 300.562227] R13: 0000000000401972 R14: 0000000000403e08 R15: 00007f8b97aff000
[ 300.562588] </TASK>
[ 300.562706] Future hung task reports are suppressed, see sysctl kernel.hung_task_warnings
[ 300.563102]
[ 300.563102] Showing all locks held in the system:
[ 300.563420] 3 locks held by kworker/u8:0/11:
[ 300.563636] #0: ffff88800df9a148 ((wq_completion)writeback){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
[ 300.564146] #1: ffff88800dcd7d78 ((work_completion)(&(&wb->dwork)->work)){+.+.}-{0:0}, at: process_one_work+0x8a0/0x1b0
[ 300.564687] #2: ffff88800d77a0e0 (&type->s_umount_key#52){.+.+}-{3:3}, at: super_trylock_shared+0x2b/0x110
[ 300.565179] 4 locks held by kworker/u8:1/31:
[ 300.565394] #0: ffff8880125bd148 ((wq_completion)ext4-rsv-conversion){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
[ 300.565924] #1: ffff88800df4fd78 ((work_completion)(&ei->i_rsv_conversion_work)){+.+.}-{0:0}, at: process_one_work+0x80
[ 300.566500] #2: ffff888012672958 (jbd2_handle){++++}-{0:0}, at: start_this_handle+0x107b/0x1590
[ 300.566948] #3: ffff888023638c60 (&ei->i_data_sem){++++}-{3:3}, at: ext4_map_blocks+0x344/0x1390
[ 300.567407] 1 lock held by khungtaskd/33:
[ 300.567612] #0: ffffffff8705c9c0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x73/0x3c0
[ 300.568064] 4 locks held by kworker/u8:2/36:
[ 300.568281] #0: ffff88800df9a148 ((wq_completion)writeback){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
[ 300.568774] #1: ffff88800e4efd78 ((work_completion)(&(&wb->dwork)->work)){+.+.}-{0:0}, at: process_one_work+0x8a0/0x1b0
[ 300.569316] #2: ffff8880126740e0 (&type->s_umount_key#38){++++}-{3:3}, at: super_trylock_shared+0x2b/0x110
[ 300.569806] #3: ffff888012670b98 (&sbi->s_writepages_rwsem){++++}-{0:0}, at: do_writepages+0x1c3/0x8a0
[ 300.570281] 4 locks held by kworker/1:2/80:
[ 300.570491] #0: ffff88800d45ad48 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
[ 300.570973] #1: ffff888011fefd78 ((work_completion)(&(&ap->scsi_rescan_task)->work)){+.+.}-{0:0}, at: process_one_work0
[ 300.571572] #2: ffff888010a8c430 (&ap->scsi_scan_mutex){+.+.}-{3:3}, at: ata_scsi_dev_rescan+0x42/0x470
[ 300.572044] #3: ffff888010b46378 (&dev->mutex){....}-{3:3}, at: scsi_rescan_device+0x33/0x360
[ 300.572480] 4 locks held by auditd/239:
[ 300.572674] #0: ffff8880134ccef8 (&f->f_pos_lock){+.+.}-{3:3}, at: fdget_pos+0x25e/0x380
[ 300.573087] #1: ffff888012674408 (sb_writers#3){.+.+}-{0:0}, at: ksys_write+0x14f/0x290
[ 300.573505] #2: ffff888017c87040 (&sb->s_type->i_mutex_key#8){++++}-{3:3}, at: ext4_buffered_write_iter+0xb8/0x3e0
[ 300.574025] #3: ffff888012672958 (jbd2_handle){++++}-{0:0}, at: start_this_handle+0x107b/0x1590
[ 300.574469] 3 locks held by in:imjournal/321:
[ 300.574690] #0: ffff888012674408 (sb_writers#3){.+.+}-{0:0}, at: path_openat+0x1f7c/0x2bf0
[ 300.575118] #1: ffff88801b708dd0 (&type->i_mutex_dir_key#3){++++}-{3:3}, at: path_openat+0xd40/0x2bf0
[ 300.575606] #2: ffff888012672958 (jbd2_handle){++++}-{0:0}, at: start_this_handle+0x107b/0x1590
[ 300.576052]
[ 300.576138] =============================================
"
I hope you find it useful.
Regards,
Yi Lai
---
If you don't need the following environment to reproduce the problem or if you
already have one reproduced environment, please ignore the following information.
How to reproduce:
git clone https://gitlab.com/xupengfe/repro_vm_env.git
cd repro_vm_env
tar -xvf repro_vm_env.tar.gz
cd repro_vm_env; ./start3.sh // it needs qemu-system-x86_64 and I used v7.1.0
// start3.sh will load bzImage_2241ab53cbb5cdb08a6b2d4688feb13971058f65 v6.2-rc5 kernel
// You could change the bzImage_xxx as you want
// Maybe you need to remove line "-drive if=pflash,format=raw,readonly=on,file=./OVMF_CODE.fd \" for different qemu version
You could use below command to log in, there is no password for root.
ssh -p 10023 root@localhost
After login vm(virtual machine) successfully, you could transfer reproduced
binary to the vm by below way, and reproduce the problem in vm:
gcc -pthread -o repro repro.c
scp -P 10023 repro root@localhost:/root/
Get the bzImage for target kernel:
Please use target kconfig and copy it to kernel_src/.config
make olddefconfig
make -jx bzImage //x should equal or less than cpu num your pc has
Fill the bzImage file into above start3.sh to load the target kernel in vm.
Tips:
If you already have qemu-system-x86_64, please ignore below info.
If you want to install qemu v7.1.0 version:
git clone https://github.com/qemu/qemu.git
cd qemu
git checkout -f v7.1.0
mkdir build
cd build
yum install -y ninja-build.x86_64
yum -y install libslirp-devel.x86_64
../configure --target-list=x86_64-softmmu --enable-kvm --enable-vnc --enable-gtk --enable-sdl --enable-usb-redir --enable-slirp
make
make install
On Mon, Sep 09, 2024 at 05:42:38PM +0200, Niklas Cassel wrote:
> When ata_qc_complete() schedules a command for EH using
> ata_qc_schedule_eh(), blk_abort_request() will be called, which leads to
> req->q->mq_ops->timeout() / scsi_timeout() being called.
>
> scsi_timeout(), if the LLDD has no abort handler (libata has no abort
> handler), will set host byte to DID_TIME_OUT, and then call
> scsi_eh_scmd_add() to add the command to EH.
>
> Thus, when commands first enter libata's EH strategy_handler, all the
> commands that have been added to EH will have DID_TIME_OUT set.
>
> libata has its own flag (AC_ERR_TIMEOUT), that it sets for commands that
> have not received a completion at the time of entering EH.
>
> Thus, libata doesn't really care about DID_TIME_OUT at all, and currently
> clears the host byte at the end of EH, in ata_scsi_qc_complete(), before
> scsi_eh_finish_cmd() is called.
>
> However, this clearing in ata_scsi_qc_complete() is currently only done
> for commands that are not ATA passthrough commands.
>
> Since the host byte is visible in the completion that we return to user
> space for ATA passthrough commands, for ATA passthrough commands that got
> completed via EH (commands with sense data), the user will incorrectly see:
> ATA pass-through(16): transport error: Host_status=0x03 [DID_TIME_OUT]
>
> Fix this by moving the clearing of the host byte (which is currently only
> done for commands that are not ATA passthrough commands) from
> ata_scsi_qc_complete() to the start of EH (regardless if the command is
> ATA passthrough or not).
>
> While at it, use the proper helper function to clear the host byte, rather
> than open coding the clearing.
>
> This will make sure that we:
> -Correctly clear DID_TIME_OUT for both ATA passthrough commands and
> commands that are not ATA passthrough commands.
> -Do not needlessly clear the host byte for commands that did not go via EH.
> ata_scsi_qc_complete() is called both for commands that are completed
> normally (without going via EH), and for commands that went via EH,
> however, only commands that went via EH will have DID_TIME_OUT set.
>
> Fixes: 24aeebbf8ea9 ("scsi: ata: libata: Change ata_eh_request_sense() to not set CHECK_CONDITION")
> Reported-by: Igor Pylypiv <ipylypiv@google.com>
> Closes: https://lore.kernel.org/linux-ide/ZttIN8He8TOZ7Lct@google.com/
> Signed-off-by: Niklas Cassel <cassel@kernel.org>
> ---
> Changes since v2: use set_host_byte() as suggested by Damien.
>
> drivers/ata/libata-eh.c | 8 ++++++++
> drivers/ata/libata-scsi.c | 3 ---
> 2 files changed, 8 insertions(+), 3 deletions(-)
>
> diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
> index 7de97ee8e78b..703f5ce26765 100644
> --- a/drivers/ata/libata-eh.c
> +++ b/drivers/ata/libata-eh.c
> @@ -630,6 +630,14 @@ void ata_scsi_cmd_error_handler(struct Scsi_Host *host, struct ata_port *ap,
> list_for_each_entry_safe(scmd, tmp, eh_work_q, eh_entry) {
> struct ata_queued_cmd *qc;
>
> + /*
> + * If the scmd was added to EH, via ata_qc_schedule_eh() ->
> + * scsi_timeout() -> scsi_eh_scmd_add(), scsi_timeout() will
> + * have set DID_TIME_OUT (since libata does not have an abort
> + * handler). Thus, to clear DID_TIME_OUT, clear the host byte.
> + */
> + set_host_byte(scmd, DID_OK);
> +
> ata_qc_for_each_raw(ap, qc, i) {
> if (qc->flags & ATA_QCFLAG_ACTIVE &&
> qc->scsicmd == scmd)
> diff --git a/drivers/ata/libata-scsi.c b/drivers/ata/libata-scsi.c
> index 3a442f564b0d..6a90062c8b55 100644
> --- a/drivers/ata/libata-scsi.c
> +++ b/drivers/ata/libata-scsi.c
> @@ -1680,9 +1680,6 @@ static void ata_scsi_qc_complete(struct ata_queued_cmd *qc)
> set_status_byte(qc->scsicmd, SAM_STAT_CHECK_CONDITION);
> } else if (is_error && !have_sense) {
> ata_gen_ata_sense(qc);
> - } else {
> - /* Keep the SCSI ML and status byte, clear host byte. */
> - cmd->result &= 0x0000ffff;
> }
>
> ata_qc_done(qc);
> --
> 2.46.0
>
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
2024-10-21 10:58 ` [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data Lai, Yi
@ 2024-10-21 12:07 ` Niklas Cassel
2024-10-21 12:34 ` Damien Le Moal
2024-10-21 15:20 ` Niklas Cassel
0 siblings, 2 replies; 10+ messages in thread
From: Niklas Cassel @ 2024-10-21 12:07 UTC (permalink / raw)
To: Lai, Yi
Cc: Damien Le Moal, Hannes Reinecke, Martin K. Petersen, Igor Pylypiv,
Niklas Cassel, linux-ide, yi1.lai, syzkaller-bugs, linux-kernel
Hello Yi Lai,
On Mon, Oct 21, 2024 at 06:58:59PM +0800, Lai, Yi wrote:
> Hi Niklas Cassel,
>
> Greetings!
>
> I used Syzkaller and found that there is INFO: task hung in blk_mq_get_tag in v6.12-rc3
>
> After bisection and the first bad commit is:
> "
> e5dd410acb34 ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
> "
It might be that your bisection results are accurate.
However, after looking at the stacktraces, I find it way more likely that
bisection has landed on the wrong commit.
See this series that was just queued (for 6.13) a few days ago that solves a
similar starvation:
https://lore.kernel.org/linux-block/20241014092934.53630-1-songmuchun@bytedance.com/
https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git/log/?h=for-6.13/block
You could perhaps run with v6.14-rc4 (which should be able to trigger the bug)
and then try v6.14-rc4 + that series applied, to see if you can still trigger
the bug?
Kind regards,
Niklas
>
> All detailed into can be found at:
> https://github.com/laifryiee/syzkaller_logs/tree/main/241018_105830_blk_mq_get_tag
> Syzkaller repro code:
> https://github.com/laifryiee/syzkaller_logs/tree/main/241018_105830_blk_mq_get_tag/repro.c
> Syzkaller repro syscall steps:
> https://github.com/laifryiee/syzkaller_logs/tree/main/241018_105830_blk_mq_get_tag/repro.prog
> Syzkaller report:
> https://github.com/laifryiee/syzkaller_logs/tree/main/241018_105830_blk_mq_get_tag/repro.report
> Kconfig(make olddefconfig):
> https://github.com/laifryiee/syzkaller_logs/tree/main/241018_105830_blk_mq_get_tag/kconfig_origin
> Bisect info:
> https://github.com/laifryiee/syzkaller_logs/tree/main/241018_105830_blk_mq_get_tag/bisect_info.log
> bzImage:
> https://github.com/laifryiee/syzkaller_logs/raw/refs/heads/main/241018_105830_blk_mq_get_tag/bzImage_8e929cb546ee42c9a61d24fae60605e9e3192354
> Issue dmesg:
> https://github.com/laifryiee/syzkaller_logs/blob/main/241018_105830_blk_mq_get_tag/8e929cb546ee42c9a61d24fae60605e9e3192354_dmesg.log
>
> "
> [ 300.375482] INFO: task kworker/u8:0:11 blocked for more than 147 seconds.
> [ 300.375906] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
> [ 300.376204] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 300.376646] task:kworker/u8:0 state:D stack:0 pid:11 tgid:11 ppid:2 flags:0x00004000
> [ 300.377158] Workqueue: writeback wb_workfn (flush-8:0)
> [ 300.377479] Call Trace:
> [ 300.377624] <TASK>
> [ 300.377760] __schedule+0xe13/0x33a0
> [ 300.377985] ? __pfx___schedule+0x10/0x10
> [ 300.378222] ? lock_release+0x441/0x870
> [ 300.378457] ? __pfx_lock_release+0x10/0x10
> [ 300.378704] ? trace_lock_acquire+0x139/0x1b0
> [ 300.378982] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.379296] ? kthread_data+0x61/0xd0
> [ 300.379555] schedule+0xf6/0x3f0
> [ 300.379754] io_schedule+0xce/0x150
> [ 300.379968] rq_qos_wait+0x1c5/0x310
> [ 300.380181] ? __pfx_wbt_cleanup_cb+0x10/0x10
> [ 300.380437] ? __pfx_rq_qos_wait+0x10/0x10
> [ 300.380681] ? __pfx_lock_release+0x10/0x10
> [ 300.380925] ? __pfx_rq_qos_wake_function+0x10/0x10
> [ 300.381214] ? __pfx_wbt_inflight_cb+0x10/0x10
> [ 300.381479] ? do_raw_spin_unlock+0x15c/0x210
> [ 300.381743] wbt_wait+0x1ec/0x400
> [ 300.381946] ? __pfx_wbt_wait+0x10/0x10
> [ 300.382174] ? __pfx_dd_bio_merge+0x10/0x10
> [ 300.382437] ? __pfx_wbt_wait+0x10/0x10
> [ 300.382667] __rq_qos_throttle+0x5f/0xb0
> [ 300.382913] blk_mq_submit_bio+0x8ad/0x2a20
> [ 300.383157] ? __kasan_check_read+0x15/0x20
> [ 300.383438] ? __pfx_blk_mq_submit_bio+0x10/0x10
> [ 300.383708] ? __pfx_mark_lock.part.0+0x10/0x10
> [ 300.383974] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.384260] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.384532] ? lock_release+0x441/0x870
> [ 300.384765] __submit_bio+0x18d/0x500
> [ 300.384985] ? __pfx___submit_bio+0x10/0x10
> [ 300.385234] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.385509] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
> [ 300.385875] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
> [ 300.386186] ? kvm_clock_get_cycles+0x43/0x70
> [ 300.386451] submit_bio_noacct_nocheck+0x6a0/0xcc0
> [ 300.386729] ? __pfx_submit_bio_noacct_nocheck+0x10/0x10
> [ 300.387049] ? __sanitizer_cov_trace_switch+0x58/0xa0
> [ 300.387361] submit_bio_noacct+0x61d/0x1dc0
> [ 300.387612] submit_bio+0xce/0x480
> [ 300.387819] submit_bh_wbc+0x58a/0x740
> [ 300.388052] __block_write_full_folio+0x7a1/0xed0
> [ 300.388327] ? __pfx_blkdev_get_block+0x10/0x10
> [ 300.388599] block_write_full_folio+0x2e6/0x3a0
> [ 300.388880] ? __pfx_blkdev_get_block+0x10/0x10
> [ 300.389147] ? __pfx_blkdev_get_block+0x10/0x10
> [ 300.389414] write_cache_pages+0xbc/0x140
> [ 300.389654] ? __pfx_block_write_full_folio+0x10/0x10
> [ 300.389954] ? __pfx_write_cache_pages+0x10/0x10
> [ 300.390224] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.390504] blkdev_writepages+0xa5/0xf0
> [ 300.390738] ? __pfx_blkdev_writepages+0x10/0x10
> [ 300.391016] ? __pfx_do_raw_spin_lock+0x10/0x10
> [ 300.391293] ? do_raw_spin_unlock+0x15c/0x210
> [ 300.391573] ? __pfx_blkdev_writepages+0x10/0x10
> [ 300.391841] do_writepages+0x1c3/0x8a0
> [ 300.392068] ? __pfx_do_writepages+0x10/0x10
> [ 300.392323] ? __pfx_lock_release+0x10/0x10
> [ 300.392568] ? lock_release+0x441/0x870
> [ 300.392805] __writeback_single_inode+0x124/0xe10
> [ 300.393081] ? wbc_attach_and_unlock_inode+0x5a9/0x950
> [ 300.393397] writeback_sb_inodes+0x63b/0x1000
> [ 300.393661] ? __pfx_writeback_sb_inodes+0x10/0x10
> [ 300.393935] ? lock_acquire.part.0+0x152/0x390
> [ 300.394230] ? __sanitizer_cov_trace_const_cmp8+0x1c/0x30
> [ 300.394544] __writeback_inodes_wb+0xc8/0x280
> [ 300.394806] wb_writeback+0x717/0xaf0
> [ 300.395039] ? __pfx_wb_writeback+0x10/0x10
> [ 300.395290] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
> [ 300.395589] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
> [ 300.395868] ? get_nr_dirty_inodes+0x12c/0x1b0
> [ 300.396134] ? lockdep_hardirqs_on+0x89/0x110
> [ 300.396393] wb_workfn+0x76c/0xc90
> [ 300.396597] ? __pfx_lock_acquire.part.0+0x10/0x10
> [ 300.396882] ? __pfx_wb_workfn+0x10/0x10
> [ 300.397110] ? rcu_is_watching+0x19/0xc0
> [ 300.397354] process_one_work+0x92e/0x1b50
> [ 300.397594] ? lock_acquire.part.0+0x152/0x390
> [ 300.397879] ? __pfx_process_one_work+0x10/0x10
> [ 300.398150] ? move_linked_works+0x1bf/0x2c0
> [ 300.398407] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.398690] ? assign_work+0x19f/0x250
> [ 300.398920] ? lock_is_held_type+0xef/0x150
> [ 300.399174] worker_thread+0x68d/0xe90
> [ 300.399428] kthread+0x35a/0x470
> [ 300.399623] ? __pfx_worker_thread+0x10/0x10
> [ 300.399874] ? __pfx_kthread+0x10/0x10
> [ 300.400100] ret_from_fork+0x56/0x90
> [ 300.400315] ? __pfx_kthread+0x10/0x10
> [ 300.400540] ret_from_fork_asm+0x1a/0x30
> [ 300.400783] </TASK>
> [ 300.400928] INFO: task kworker/u8:2:36 blocked for more than 147 seconds.
> [ 300.401309] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
> [ 300.401613] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 300.402046] task:kworker/u8:2 state:D stack:0 pid:36 tgid:36 ppid:2 flags:0x00004000
> [ 300.402638] Workqueue: writeback wb_workfn (flush-8:0)
> [ 300.402941] Call Trace:
> [ 300.403083] <TASK>
> [ 300.403214] __schedule+0xe13/0x33a0
> [ 300.403458] ? __pfx___schedule+0x10/0x10
> [ 300.403686] ? lock_release+0x441/0x870
> [ 300.403909] ? __pfx_lock_release+0x10/0x10
> [ 300.404146] ? trace_lock_acquire+0x139/0x1b0
> [ 300.404399] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.404701] ? kthread_data+0x61/0xd0
> [ 300.404915] schedule+0xf6/0x3f0
> [ 300.405106] io_schedule+0xce/0x150
> [ 300.405309] blk_mq_get_tag+0x5e7/0xce0
> [ 300.405531] ? __pfx_blk_mq_get_tag+0x10/0x10
> [ 300.405771] ? __pfx_wbt_cleanup_cb+0x10/0x10
> [ 300.406011] ? __sanitizer_cov_trace_switch+0x58/0xa0
> [ 300.406288] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 300.406579] ? __pfx_rq_qos_wake_function+0x10/0x10
> [ 300.406848] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.407136] ? dd_limit_depth+0x21e/0x2a0
> [ 300.407380] ? __pfx_dd_limit_depth+0x10/0x10
> [ 300.407625] __blk_mq_alloc_requests+0x6f6/0x1720
> [ 300.407901] ? __pfx___blk_mq_alloc_requests+0x10/0x10
> [ 300.408186] ? __pfx_wbt_wait+0x10/0x10
> [ 300.408405] blk_mq_submit_bio+0x93c/0x2a20
> [ 300.408632] ? __kasan_check_read+0x15/0x20
> [ 300.408866] ? __pfx_blk_mq_submit_bio+0x10/0x10
> [ 300.409117] ? __pfx_mark_lock.part.0+0x10/0x10
> [ 300.409364] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.409626] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.409883] ? lock_release+0x441/0x870
> [ 300.410098] __submit_bio+0x18d/0x500
> [ 300.410303] ? __pfx___submit_bio+0x10/0x10
> [ 300.410534] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.410790] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
> [ 300.411135] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
> [ 300.411440] ? kvm_clock_get_cycles+0x43/0x70
> [ 300.411690] submit_bio_noacct_nocheck+0x6a0/0xcc0
> [ 300.411958] ? __pfx_submit_bio_noacct_nocheck+0x10/0x10
> [ 300.412249] ? lock_is_held_type+0xef/0x150
> [ 300.412484] submit_bio_noacct+0x61d/0x1dc0
> [ 300.412718] submit_bio+0xce/0x480
> [ 300.412911] ext4_io_submit+0xb0/0x150
> [ 300.413128] ext4_do_writepages+0xa54/0x2f30
> [ 300.413372] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.413638] ? __pfx_ext4_do_writepages+0x10/0x10
> [ 300.413892] ? rcu_is_watching+0x19/0xc0
> [ 300.414113] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.414376] ? lock_is_held_type+0xef/0x150
> [ 300.414616] ext4_writepages+0x35c/0x7c0
> [ 300.414836] ? __pfx_ext4_writepages+0x10/0x10
> [ 300.415087] ? lock_release+0x441/0x870
> [ 300.415313] ? do_raw_spin_unlock+0x15c/0x210
> [ 300.415576] ? __pfx_ext4_writepages+0x10/0x10
> [ 300.415824] do_writepages+0x1c3/0x8a0
> [ 300.416039] ? __pfx_do_writepages+0x10/0x10
> [ 300.416278] ? __pfx_lock_release+0x10/0x10
> [ 300.416510] ? __pfx_lock_release+0x10/0x10
> [ 300.416754] __writeback_single_inode+0x124/0xe10
> [ 300.417016] ? wbc_attach_and_unlock_inode+0x5a9/0x950
> [ 300.417301] writeback_sb_inodes+0x63b/0x1000
> [ 300.417546] ? lock_release+0x441/0x870
> [ 300.417772] ? __pfx_writeback_sb_inodes+0x10/0x10
> [ 300.418039] ? lock_acquire.part.0+0x152/0x390
> [ 300.418321] ? __sanitizer_cov_trace_const_cmp8+0x1c/0x30
> [ 300.418616] __writeback_inodes_wb+0xc8/0x280
> [ 300.418865] wb_writeback+0x717/0xaf0
> [ 300.419082] ? __pfx_wb_writeback+0x10/0x10
> [ 300.419335] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
> [ 300.419598] ? get_nr_dirty_inodes+0x12c/0x1b0
> [ 300.419847] ? lockdep_hardirqs_on+0x89/0x110
> [ 300.420094] wb_workfn+0x7b5/0xc90
> [ 300.420291] ? __pfx_lock_acquire.part.0+0x10/0x10
> [ 300.420561] ? __pfx_wb_workfn+0x10/0x10
> [ 300.420780] ? rcu_is_watching+0x19/0xc0
> [ 300.421017] process_one_work+0x92e/0x1b50
> [ 300.421245] ? lock_acquire.part.0+0x152/0x390
> [ 300.421498] ? __pfx_process_one_work+0x10/0x10
> [ 300.421743] ? move_linked_works+0x1bf/0x2c0
> [ 300.421976] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.422236] ? assign_work+0x19f/0x250
> [ 300.422442] ? lock_is_held_type+0xef/0x150
> [ 300.422673] worker_thread+0x68d/0xe90
> [ 300.422896] kthread+0x35a/0x470
> [ 300.423074] ? __pfx_worker_thread+0x10/0x10
> [ 300.423306] ? __pfx_kthread+0x10/0x10
> [ 300.423538] ret_from_fork+0x56/0x90
> [ 300.423735] ? __pfx_kthread+0x10/0x10
> [ 300.423944] ret_from_fork_asm+0x1a/0x30
> [ 300.424171] </TASK>
> [ 300.424303] INFO: task kworker/1:2:80 blocked for more than 147 seconds.
> [ 300.424649] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
> [ 300.424930] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 300.425332] task:kworker/1:2 state:D stack:0 pid:80 tgid:80 ppid:2 flags:0x00004000
> [ 300.425818] Workqueue: events ata_scsi_dev_rescan
> [ 300.426080] Call Trace:
> [ 300.426217] <TASK>
> [ 300.426340] __schedule+0xe13/0x33a0
> [ 300.426545] ? __pfx___schedule+0x10/0x10
> [ 300.426761] ? lock_release+0x441/0x870
> [ 300.426977] ? __pfx_lock_release+0x10/0x10
> [ 300.427204] ? _raw_spin_unlock_irq+0x3c/0x60
> [ 300.427452] schedule+0xf6/0x3f0
> [ 300.427631] io_schedule+0xce/0x150
> [ 300.427820] blk_mq_get_tag+0x5e7/0xce0
> [ 300.428032] ? __pfx_blk_mq_get_tag+0x10/0x10
> [ 300.428264] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 300.428542] __blk_mq_alloc_requests+0x6f6/0x1720
> [ 300.428790] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
> [ 300.429077] ? __pfx___blk_mq_alloc_requests+0x10/0x10
> [ 300.429352] blk_mq_alloc_request+0x655/0x930
> [ 300.429586] ? __pfx_blk_mq_alloc_request+0x10/0x10
> [ 300.429840] ? __lock_acquire+0xd87/0x5c90
> [ 300.430067] scsi_execute_cmd+0x223/0x1040
> [ 300.430294] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.430540] ? __pfx_scsi_execute_cmd+0x10/0x10
> [ 300.430781] ? __pfx_lock_acquire.part.0+0x10/0x10
> [ 300.431038] scsi_vpd_inquiry+0xdf/0x220
> [ 300.431251] ? __pfx_scsi_vpd_inquiry+0x10/0x10
> [ 300.431502] ? debug_smp_processor_id+0x20/0x30
> [ 300.431741] ? rcu_is_watching+0x19/0xc0
> [ 300.431953] scsi_get_vpd_size+0x11e/0x310
> [ 300.432168] ? __mutex_lock+0x230/0x1490
> [ 300.432377] ? __pfx_scsi_get_vpd_size+0x10/0x10
> [ 300.432619] ? scsi_rescan_device+0x33/0x360
> [ 300.432845] ? __pfx_mark_lock.part.0+0x10/0x10
> [ 300.433083] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.433330] ? lock_acquire.part.0+0x152/0x390
> [ 300.433565] ? __pfx___mutex_lock+0x10/0x10
> [ 300.433791] scsi_get_vpd_buf+0x30/0x180
> [ 300.434006] scsi_attach_vpd+0xf8/0x5b0
> [ 300.434218] scsi_rescan_device+0x106/0x360
> [ 300.434446] ata_scsi_dev_rescan+0x1d2/0x470
> [ 300.434684] process_one_work+0x92e/0x1b50
> [ 300.434904] ? lock_acquire.part.0+0x152/0x390
> [ 300.435154] ? __pfx_process_one_work+0x10/0x10
> [ 300.435412] ? move_linked_works+0x1bf/0x2c0
> [ 300.435639] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.435891] ? assign_work+0x19f/0x250
> [ 300.436089] ? lock_is_held_type+0xef/0x150
> [ 300.436313] worker_thread+0x68d/0xe90
> [ 300.436525] kthread+0x35a/0x470
> [ 300.436699] ? __pfx_worker_thread+0x10/0x10
> [ 300.436924] ? __pfx_kthread+0x10/0x10
> [ 300.437125] ret_from_fork+0x56/0x90
> [ 300.437317] ? __pfx_kthread+0x10/0x10
> [ 300.437517] ret_from_fork_asm+0x1a/0x30
> [ 300.437736] </TASK>
> [ 300.437858] INFO: task jbd2/sda-8:104 blocked for more than 147 seconds.
> [ 300.438192] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
> [ 300.438465] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 300.438852] task:jbd2/sda-8 state:D stack:0 pid:104 tgid:104 ppid:2 flags:0x00004000
> [ 300.439339] Call Trace:
> [ 300.439475] <TASK>
> [ 300.439595] __schedule+0xe13/0x33a0
> [ 300.439794] ? __pfx___schedule+0x10/0x10
> [ 300.440005] ? lock_release+0x441/0x870
> [ 300.440212] ? __pfx_lock_release+0x10/0x10
> [ 300.440431] ? trace_lock_acquire+0x139/0x1b0
> [ 300.440666] ? lock_acquire+0x80/0xb0
> [ 300.440860] ? schedule+0x216/0x3f0
> [ 300.441051] schedule+0xf6/0x3f0
> [ 300.441229] io_schedule+0xce/0x150
> [ 300.441417] blk_mq_get_tag+0x5e7/0xce0
> [ 300.441628] ? __pfx_blk_mq_get_tag+0x10/0x10
> [ 300.441859] ? lock_release+0x441/0x870
> [ 300.442063] ? __sanitizer_cov_trace_switch+0x58/0xa0
> [ 300.442326] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 300.442596] ? blk_mq_sched_try_merge+0xce/0x650
> [ 300.442841] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
> [ 300.443123] ? dd_limit_depth+0x21e/0x2a0
> [ 300.443358] ? __pfx_dd_limit_depth+0x10/0x10
> [ 300.443591] __blk_mq_alloc_requests+0x6f6/0x1720
> [ 300.443846] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.444131] ? __pfx___blk_mq_alloc_requests+0x10/0x10
> [ 300.444403] ? __pfx_wbt_wait+0x10/0x10
> [ 300.444610] blk_mq_submit_bio+0x93c/0x2a20
> [ 300.444829] ? __pfx___lock_acquire+0x10/0x10
> [ 300.445064] ? __pfx_blk_mq_submit_bio+0x10/0x10
> [ 300.445307] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.445559] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.445807] ? lock_release+0x441/0x870
> [ 300.446014] __submit_bio+0x18d/0x500
> [ 300.446211] ? __pfx___submit_bio+0x10/0x10
> [ 300.446432] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.446677] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
> [ 300.447005] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
> [ 300.447282] ? kvm_clock_get_cycles+0x43/0x70
> [ 300.447534] submit_bio_noacct_nocheck+0x6a0/0xcc0
> [ 300.447787] ? __pfx_submit_bio_noacct_nocheck+0x10/0x10
> [ 300.448067] ? __sanitizer_cov_trace_switch+0x58/0xa0
> [ 300.448330] submit_bio_noacct+0x61d/0x1dc0
> [ 300.448556] submit_bio+0xce/0x480
> [ 300.448742] submit_bh_wbc+0x58a/0x740
> [ 300.448947] submit_bh+0x2b/0x40
> [ 300.449124] jbd2_journal_commit_transaction+0x2a09/0x65e0
> [ 300.449431] ? __pfx_jbd2_journal_commit_transaction+0x10/0x10
> [ 300.449737] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.449983] ? lock_release+0x441/0x870
> [ 300.450196] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.450445] ? _raw_spin_unlock_irqrestore+0x45/0x70
> [ 300.450703] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.450998] kjournald2+0x204/0x790
> [ 300.451194] ? __pfx_kjournald2+0x10/0x10
> [ 300.451416] ? lockdep_hardirqs_on+0x89/0x110
> [ 300.451647] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 300.451917] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
> [ 300.452194] ? __kthread_parkme+0x15d/0x230
> [ 300.452419] kthread+0x35a/0x470
> [ 300.452594] ? __pfx_kjournald2+0x10/0x10
> [ 300.452803] ? __pfx_kthread+0x10/0x10
> [ 300.453004] ret_from_fork+0x56/0x90
> [ 300.453198] ? __pfx_kthread+0x10/0x10
> [ 300.453406] ret_from_fork_asm+0x1a/0x30
> [ 300.453639] </TASK>
> [ 300.453765] INFO: task auditd:239 blocked for more than 147 seconds.
> [ 300.454094] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
> [ 300.454367] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 300.454757] task:auditd state:D stack:0 pid:239 tgid:239 ppid:1 flags:0x00000002
> [ 300.455219] Call Trace:
> [ 300.455363] <TASK>
> [ 300.455481] __schedule+0xe13/0x33a0
> [ 300.455676] ? __pfx___schedule+0x10/0x10
> [ 300.455883] ? lock_release+0x441/0x870
> [ 300.456086] ? __pfx_lock_release+0x10/0x10
> [ 300.456300] ? trace_lock_acquire+0x139/0x1b0
> [ 300.456530] ? lock_acquire+0x80/0xb0
> [ 300.456722] ? schedule+0x216/0x3f0
> [ 300.456911] schedule+0xf6/0x3f0
> [ 300.457085] io_schedule+0xce/0x150
> [ 300.457271] bit_wait_io+0x1f/0x100
> [ 300.457457] __wait_on_bit+0x68/0x1b0
> [ 300.457649] ? __pfx_bit_wait_io+0x10/0x10
> [ 300.457867] out_of_line_wait_on_bit+0xe6/0x120
> [ 300.458102] ? __pfx_out_of_line_wait_on_bit+0x10/0x10
> [ 300.458369] ? __pfx_wake_bit_function+0x10/0x10
> [ 300.458606] ? __might_sleep+0xa3/0x170
> [ 300.458808] do_get_write_access+0x83b/0x1010
> [ 300.459045] jbd2_journal_get_write_access+0x1e4/0x270
> [ 300.459308] __ext4_journal_get_write_access+0x72/0x3b0
> [ 300.459591] ext4_reserve_inode_write+0x199/0x280
> [ 300.459833] ? ext4_dirty_inode+0xeb/0x140
> [ 300.460044] __ext4_mark_inode_dirty+0x18b/0x8c0
> [ 300.460282] ? debug_smp_processor_id+0x20/0x30
> [ 300.460515] ? __pfx___ext4_mark_inode_dirty+0x10/0x10
> [ 300.460773] ? trace_jbd2_handle_start+0x77/0x210
> [ 300.461017] ? jbd2__journal_start+0xff/0x6b0
> [ 300.461246] ? __ext4_journal_start_sb+0x1f8/0x600
> [ 300.461490] ? ext4_dirty_inode+0xb3/0x140
> [ 300.461703] ? __pfx_ext4_dirty_inode+0x10/0x10
> [ 300.461937] ext4_dirty_inode+0xeb/0x140
> [ 300.462139] ? rcu_is_watching+0x19/0xc0
> [ 300.462343] __mark_inode_dirty+0x1d0/0xd50
> [ 300.462557] ? __pfx_generic_write_checks+0x10/0x10
> [ 300.462810] generic_update_time+0xe0/0x110
> [ 300.463032] file_modified+0x1af/0x1e0
> [ 300.463233] ext4_buffered_write_iter+0x101/0x3e0
> [ 300.463493] ext4_file_write_iter+0x8b8/0x1ab0
> [ 300.463722] ? __pfx_lock_acquire.part.0+0x10/0x10
> [ 300.463971] ? debug_smp_processor_id+0x20/0x30
> [ 300.464208] ? __pfx_ext4_file_write_iter+0x10/0x10
> [ 300.464459] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.464701] ? lock_is_held_type+0xef/0x150
> [ 300.464920] vfs_write+0xc46/0x1120
> [ 300.465106] ? __pfx_ext4_file_write_iter+0x10/0x10
> [ 300.465356] ? __pfx_vfs_write+0x10/0x10
> [ 300.465572] ? mutex_lock_nested+0x1f/0x30
> [ 300.465788] ksys_write+0x14f/0x290
> [ 300.465974] ? __pfx_ksys_write+0x10/0x10
> [ 300.466189] __x64_sys_write+0x7b/0xc0
> [ 300.466384] ? syscall_trace_enter+0x9b/0x230
> [ 300.466610] x64_sys_call+0x1685/0x20d0
> [ 300.466810] do_syscall_64+0x6d/0x140
> [ 300.467007] entry_SYSCALL_64_after_hwframe+0x76/0x7e
> [ 300.467264] RIP: 0033:0x7f0f0ad3ebcf
> [ 300.467465] RSP: 002b:00007fffd00b5a30 EFLAGS: 00000293 ORIG_RAX: 0000000000000001
> [ 300.467838] RAX: ffffffffffffffda RBX: 00000000000000e0 RCX: 00007f0f0ad3ebcf
> [ 300.468186] RDX: 00000000000000e0 RSI: 000055b1be1b80a0 RDI: 0000000000000005
> [ 300.468535] RBP: 000055b1be1b80a0 R08: 0000000000000000 R09: 00007f0f0adb14e0
> [ 300.468883] R10: 00007f0f0adb13e0 R11: 0000000000000293 R12: 00000000000000e0
> [ 300.469231] R13: 000055b1be1ae2a0 R14: 00000000000000e0 R15: 00007f0f0adf69e0
> [ 300.469591] </TASK>
> [ 300.469711] INFO: task in:imjournal:321 blocked for more than 147 seconds.
> [ 300.470045] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
> [ 300.470311] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 300.470687] task:in:imjournal state:D stack:0 pid:321 tgid:302 ppid:1 flags:0x00000002
> [ 300.471144] Call Trace:
> [ 300.471273] <TASK>
> [ 300.471406] __schedule+0xe13/0x33a0
> [ 300.471601] ? __pfx___schedule+0x10/0x10
> [ 300.471807] ? lock_release+0x441/0x870
> [ 300.472008] ? __pfx_lock_release+0x10/0x10
> [ 300.472221] ? trace_lock_acquire+0x139/0x1b0
> [ 300.472450] ? lock_acquire+0x80/0xb0
> [ 300.472640] ? schedule+0x216/0x3f0
> [ 300.472826] schedule+0xf6/0x3f0
> [ 300.472999] io_schedule+0xce/0x150
> [ 300.473183] bit_wait_io+0x1f/0x100
> [ 300.473368] __wait_on_bit+0x68/0x1b0
> [ 300.473560] ? __pfx_bit_wait_io+0x10/0x10
> [ 300.473778] out_of_line_wait_on_bit+0xe6/0x120
> [ 300.474010] ? __pfx_out_of_line_wait_on_bit+0x10/0x10
> [ 300.474273] ? __pfx_wake_bit_function+0x10/0x10
> [ 300.474512] ? __might_sleep+0xa3/0x170
> [ 300.474714] do_get_write_access+0x83b/0x1010
> [ 300.474951] jbd2_journal_get_write_access+0x1e4/0x270
> [ 300.475215] __ext4_journal_get_write_access+0x72/0x3b0
> [ 300.475496] __ext4_new_inode+0xfef/0x5320
> [ 300.475720] ? __pfx___ext4_new_inode+0x10/0x10
> [ 300.475955] ? __pfx___dquot_initialize+0x10/0x10
> [ 300.476202] ? _raw_spin_unlock+0x31/0x60
> [ 300.476409] ? d_splice_alias+0x4e8/0xe30
> [ 300.476619] ext4_create+0x32e/0x550
> [ 300.476815] ? __pfx_ext4_create+0x10/0x10
> [ 300.477030] ? inode_permission+0xf4/0x650
> [ 300.477239] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.477510] ? __pfx_ext4_create+0x10/0x10
> [ 300.477723] lookup_open.isra.0+0x117c/0x1580
> [ 300.477954] ? __pfx_lookup_open.isra.0+0x10/0x10
> [ 300.478200] ? lock_acquire+0x80/0xb0
> [ 300.478391] ? path_openat+0xd40/0x2bf0
> [ 300.478599] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.478873] path_openat+0xdbf/0x2bf0
> [ 300.479085] ? __pfx_path_openat+0x10/0x10
> [ 300.479298] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.479553] ? lock_is_held_type+0xef/0x150
> [ 300.479770] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.480019] do_filp_open+0x1cc/0x420
> [ 300.480213] ? __pfx_do_filp_open+0x10/0x10
> [ 300.480429] ? lock_release+0x441/0x870
> [ 300.480638] ? do_raw_spin_unlock+0x15c/0x210
> [ 300.480877] do_sys_openat2+0x185/0x1f0
> [ 300.481078] ? __pfx_do_sys_openat2+0x10/0x10
> [ 300.481306] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.481548] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
> [ 300.481864] ? lockdep_hardirqs_on+0x89/0x110
> [ 300.482094] __x64_sys_openat+0x17a/0x240
> [ 300.482304] ? __pfx___x64_sys_openat+0x10/0x10
> [ 300.482539] ? __audit_syscall_entry+0x39c/0x500
> [ 300.482784] x64_sys_call+0x1a52/0x20d0
> [ 300.482988] do_syscall_64+0x6d/0x140
> [ 300.483182] entry_SYSCALL_64_after_hwframe+0x76/0x7e
> [ 300.483450] RIP: 0033:0x7fd79d13e8c4
> [ 300.483639] RSP: 002b:00007fd79c1fea40 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
> [ 300.484009] RAX: ffffffffffffffda RBX: 00007fd794000c50 RCX: 00007fd79d13e8c4
> [ 300.484357] RDX: 0000000000000241 RSI: 00007fd79c1feb80 RDI: 00000000ffffff9c
> [ 300.484705] RBP: 00007fd79c1feb80 R08: 0000000000000000 R09: 0000000000000001
> [ 300.485053] R10: 00000000000001b6 R11: 0000000000000293 R12: 0000000000000241
> [ 300.485400] R13: 00007fd794000c50 R14: 0000000000000001 R15: 00007fd79402aba0
> [ 300.485761] </TASK>
> [ 300.485918] INFO: task repro:686 blocked for more than 147 seconds.
> [ 300.486225] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
> [ 300.486491] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 300.486868] task:repro state:D stack:0 pid:686 tgid:686 ppid:680 flags:0x00000006
> [ 300.487345] Call Trace:
> [ 300.487476] <TASK>
> [ 300.487595] __schedule+0xe13/0x33a0
> [ 300.487790] ? __pfx___schedule+0x10/0x10
> [ 300.487995] ? lock_release+0x441/0x870
> [ 300.488196] ? __pfx_lock_release+0x10/0x10
> [ 300.488411] ? trace_lock_acquire+0x139/0x1b0
> [ 300.488640] ? lock_acquire+0x80/0xb0
> [ 300.488831] ? schedule+0x216/0x3f0
> [ 300.489019] schedule+0xf6/0x3f0
> [ 300.489193] io_schedule+0xce/0x150
> [ 300.489378] blk_mq_get_tag+0x5e7/0xce0
> [ 300.489584] ? __pfx_blk_mq_get_tag+0x10/0x10
> [ 300.489811] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 300.490082] __blk_mq_alloc_requests+0x6f6/0x1720
> [ 300.490323] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
> [ 300.490603] ? __pfx___blk_mq_alloc_requests+0x10/0x10
> [ 300.490863] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.491108] ? lock_acquire.part.0+0x152/0x390
> [ 300.491375] blk_mq_alloc_request+0x655/0x930
> [ 300.491604] ? __pfx_blk_mq_alloc_request+0x10/0x10
> [ 300.491865] scsi_execute_cmd+0x223/0x1040
> [ 300.492081] ? debug_smp_processor_id+0x20/0x30
> [ 300.492317] ? __pfx_scsi_execute_cmd+0x10/0x10
> [ 300.492548] ? rcu_is_watching+0x19/0xc0
> [ 300.492754] ? __kmalloc_noprof+0x34f/0x4a0
> [ 300.492970] ? ata_cmd_ioctl+0x375/0x570
> [ 300.493179] ata_cmd_ioctl+0x23c/0x570
> [ 300.493378] ? __pfx_ata_cmd_ioctl+0x10/0x10
> [ 300.493597] ? lock_release+0x441/0x870
> [ 300.493802] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.494052] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.494321] ? security_capable+0x19d/0x1e0
> [ 300.494545] ata_sas_scsi_ioctl+0x60a/0x7c0
> [ 300.494758] ? mark_lock.part.0+0xf3/0x17b0
> [ 300.494979] ? __pfx_ata_sas_scsi_ioctl+0x10/0x10
> [ 300.495218] ? __pfx_mark_lock.part.0+0x10/0x10
> [ 300.495473] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.495715] ? lock_is_held_type+0xef/0x150
> [ 300.495935] ? __pfx_ata_scsi_ioctl+0x10/0x10
> [ 300.496161] ata_scsi_ioctl+0x70/0x90
> [ 300.496355] scsi_ioctl+0xb6f/0x1630
> [ 300.496546] ? __might_sleep+0xa3/0x170
> [ 300.496748] ? __pfx_scsi_ioctl+0x10/0x10
> [ 300.496954] ? scsi_block_when_processing_errors+0x2c4/0x390
> [ 300.497244] ? __pfx_scsi_block_when_processing_errors+0x10/0x10
> [ 300.497546] ? __pfx___lock_acquire+0x10/0x10
> [ 300.497770] ? __sanitizer_cov_trace_switch+0x58/0xa0
> [ 300.498028] ? __sanitizer_cov_trace_const_cmp2+0x1c/0x30
> [ 300.498298] ? do_vfs_ioctl+0x4fa/0x1920
> [ 300.498502] ? __pfx_do_vfs_ioctl+0x10/0x10
> [ 300.498718] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.498996] sg_ioctl+0xfb8/0x2880
> [ 300.499180] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.499436] ? lock_release+0x441/0x870
> [ 300.499640] ? __pfx_sg_ioctl+0x10/0x10
> [ 300.499842] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.500081] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
> [ 300.500394] ? lockdep_hardirqs_on+0x89/0x110
> [ 300.500621] ? trace_hardirqs_on+0x51/0x60
> [ 300.500834] ? seqcount_lockdep_reader_access.constprop.0+0xc0/0xd0
> [ 300.501149] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
> [ 300.501395] ? ktime_get_coarse_real_ts64+0xbf/0xf0
> [ 300.501649] ? __pfx_sg_ioctl+0x10/0x10
> [ 300.501849] __x64_sys_ioctl+0x1b5/0x230
> [ 300.502055] x64_sys_call+0x1209/0x20d0
> [ 300.502255] do_syscall_64+0x6d/0x140
> [ 300.502447] entry_SYSCALL_64_after_hwframe+0x76/0x7e
> [ 300.502702] RIP: 0033:0x7f8b9783ee5d
> [ 300.502890] RSP: 002b:00007ffc0329c228 EFLAGS: 00000206 ORIG_RAX: 0000000000000010
> [ 300.503265] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f8b9783ee5d
> [ 300.503629] RDX: 0000000020000080 RSI: 000000000000031f RDI: 0000000000000003
> [ 300.503978] RBP: 00007ffc0329c240 R08: 00007ffc0329bfb8 R09: 00007ffc0329c240
> [ 300.504326] R10: 0000000000000000 R11: 0000000000000206 R12: 00007ffc0329c398
> [ 300.504674] R13: 0000000000401972 R14: 0000000000403e08 R15: 00007f8b97aff000
> [ 300.505034] </TASK>
> [ 300.505153] INFO: task repro:687 blocked for more than 147 seconds.
> [ 300.505459] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
> [ 300.505724] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 300.506102] task:repro state:D stack:0 pid:687 tgid:687 ppid:683 flags:0x00000006
> [ 300.506557] Call Trace:
> [ 300.506686] <TASK>
> [ 300.506803] __schedule+0xe13/0x33a0
> [ 300.507000] ? __pfx___schedule+0x10/0x10
> [ 300.507206] ? lock_release+0x441/0x870
> [ 300.507419] ? __pfx_lock_release+0x10/0x10
> [ 300.507633] ? trace_lock_acquire+0x139/0x1b0
> [ 300.507865] ? lock_acquire+0x80/0xb0
> [ 300.508055] ? schedule+0x216/0x3f0
> [ 300.508243] schedule+0xf6/0x3f0
> [ 300.508418] io_schedule+0xce/0x150
> [ 300.508602] blk_mq_get_tag+0x5e7/0xce0
> [ 300.508807] ? __pfx_blk_mq_get_tag+0x10/0x10
> [ 300.509034] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 300.509306] __blk_mq_alloc_requests+0x6f6/0x1720
> [ 300.509548] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
> [ 300.509829] ? __pfx___blk_mq_alloc_requests+0x10/0x10
> [ 300.510092] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.510335] ? lock_acquire.part.0+0x152/0x390
> [ 300.510570] blk_mq_alloc_request+0x655/0x930
> [ 300.510801] ? __pfx_blk_mq_alloc_request+0x10/0x10
> [ 300.511072] scsi_execute_cmd+0x223/0x1040
> [ 300.511290] ? debug_smp_processor_id+0x20/0x30
> [ 300.511546] ? __pfx_scsi_execute_cmd+0x10/0x10
> [ 300.511780] ? rcu_is_watching+0x19/0xc0
> [ 300.511984] ? __kmalloc_noprof+0x34f/0x4a0
> [ 300.512200] ? ata_cmd_ioctl+0x375/0x570
> [ 300.512407] ata_cmd_ioctl+0x23c/0x570
> [ 300.512607] ? __pfx_ata_cmd_ioctl+0x10/0x10
> [ 300.512827] ? lock_release+0x441/0x870
> [ 300.513032] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.513282] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.513552] ? security_capable+0x19d/0x1e0
> [ 300.513772] ata_sas_scsi_ioctl+0x60a/0x7c0
> [ 300.513985] ? mark_lock.part.0+0xf3/0x17b0
> [ 300.514200] ? __pfx_ata_sas_scsi_ioctl+0x10/0x10
> [ 300.514439] ? __pfx_mark_lock.part.0+0x10/0x10
> [ 300.514676] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.514919] ? lock_is_held_type+0xef/0x150
> [ 300.515136] ? __pfx_ata_scsi_ioctl+0x10/0x10
> [ 300.515374] ata_scsi_ioctl+0x70/0x90
> [ 300.515568] scsi_ioctl+0xb6f/0x1630
> [ 300.515759] ? __might_sleep+0xa3/0x170
> [ 300.515962] ? __pfx_scsi_ioctl+0x10/0x10
> [ 300.516170] ? scsi_block_when_processing_errors+0x2c4/0x390
> [ 300.516459] ? __pfx_scsi_block_when_processing_errors+0x10/0x10
> [ 300.516759] ? __pfx___lock_acquire+0x10/0x10
> [ 300.516983] ? __sanitizer_cov_trace_switch+0x58/0xa0
> [ 300.517239] ? __sanitizer_cov_trace_const_cmp2+0x1c/0x30
> [ 300.517511] ? do_vfs_ioctl+0x4fa/0x1920
> [ 300.517715] ? __pfx_do_vfs_ioctl+0x10/0x10
> [ 300.517931] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.518204] sg_ioctl+0xfb8/0x2880
> [ 300.518383] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.518623] ? lock_release+0x441/0x870
> [ 300.518826] ? __pfx_sg_ioctl+0x10/0x10
> [ 300.519034] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.519274] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
> [ 300.519601] ? lockdep_hardirqs_on+0x89/0x110
> [ 300.519828] ? trace_hardirqs_on+0x51/0x60
> [ 300.520039] ? seqcount_lockdep_reader_access.constprop.0+0xc0/0xd0
> [ 300.520351] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
> [ 300.520598] ? ktime_get_coarse_real_ts64+0xbf/0xf0
> [ 300.520853] ? __pfx_sg_ioctl+0x10/0x10
> [ 300.521053] __x64_sys_ioctl+0x1b5/0x230
> [ 300.521260] x64_sys_call+0x1209/0x20d0
> [ 300.521459] do_syscall_64+0x6d/0x140
> [ 300.521651] entry_SYSCALL_64_after_hwframe+0x76/0x7e
> [ 300.521907] RIP: 0033:0x7f8b9783ee5d
> [ 300.522092] RSP: 002b:00007ffc0329c228 EFLAGS: 00000206 ORIG_RAX: 0000000000000010
> [ 300.522464] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f8b9783ee5d
> [ 300.522815] RDX: 0000000020000080 RSI: 000000000000031f RDI: 0000000000000003
> [ 300.523169] RBP: 00007ffc0329c240 R08: 00007ffc0329bfb8 R09: 00007ffc0329c240
> [ 300.523531] R10: 0000000000000000 R11: 0000000000000206 R12: 00007ffc0329c398
> [ 300.523881] R13: 0000000000401972 R14: 0000000000403e08 R15: 00007f8b97aff000
> [ 300.524241] </TASK>
> [ 300.524359] INFO: task repro:688 blocked for more than 147 seconds.
> [ 300.524666] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
> [ 300.524932] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 300.525308] task:repro state:D stack:0 pid:688 tgid:688 ppid:685 flags:0x00000006
> [ 300.525762] Call Trace:
> [ 300.525893] <TASK>
> [ 300.526011] __schedule+0xe13/0x33a0
> [ 300.526207] ? __pfx___schedule+0x10/0x10
> [ 300.526413] ? lock_release+0x441/0x870
> [ 300.526614] ? __pfx_lock_release+0x10/0x10
> [ 300.526827] ? trace_lock_acquire+0x139/0x1b0
> [ 300.527060] ? lock_acquire+0x80/0xb0
> [ 300.527251] ? schedule+0x216/0x3f0
> [ 300.527450] schedule+0xf6/0x3f0
> [ 300.527624] io_schedule+0xce/0x150
> [ 300.527807] blk_mq_get_tag+0x5e7/0xce0
> [ 300.528012] ? __pfx_blk_mq_get_tag+0x10/0x10
> [ 300.528238] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 300.528508] __blk_mq_alloc_requests+0x6f6/0x1720
> [ 300.528749] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
> [ 300.529029] ? __pfx___blk_mq_alloc_requests+0x10/0x10
> [ 300.529291] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.529533] ? lock_acquire.part.0+0x152/0x390
> [ 300.529767] blk_mq_alloc_request+0x655/0x930
> [ 300.529996] ? __pfx_blk_mq_alloc_request+0x10/0x10
> [ 300.530259] scsi_execute_cmd+0x223/0x1040
> [ 300.530476] ? debug_smp_processor_id+0x20/0x30
> [ 300.530712] ? __pfx_scsi_execute_cmd+0x10/0x10
> [ 300.530946] ? rcu_is_watching+0x19/0xc0
> [ 300.531156] ? __kmalloc_noprof+0x34f/0x4a0
> [ 300.531389] ? ata_cmd_ioctl+0x375/0x570
> [ 300.531596] ata_cmd_ioctl+0x23c/0x570
> [ 300.531795] ? __pfx_ata_cmd_ioctl+0x10/0x10
> [ 300.532014] ? lock_release+0x441/0x870
> [ 300.532219] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.532468] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.532738] ? security_capable+0x19d/0x1e0
> [ 300.532959] ata_sas_scsi_ioctl+0x60a/0x7c0
> [ 300.533172] ? mark_lock.part.0+0xf3/0x17b0
> [ 300.533386] ? __pfx_ata_sas_scsi_ioctl+0x10/0x10
> [ 300.533624] ? __pfx_mark_lock.part.0+0x10/0x10
> [ 300.533863] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.534105] ? lock_is_held_type+0xef/0x150
> [ 300.534323] ? __pfx_ata_scsi_ioctl+0x10/0x10
> [ 300.534547] ata_scsi_ioctl+0x70/0x90
> [ 300.534742] scsi_ioctl+0xb6f/0x1630
> [ 300.534937] ? __might_sleep+0xa3/0x170
> [ 300.535139] ? __pfx_scsi_ioctl+0x10/0x10
> [ 300.535363] ? scsi_block_when_processing_errors+0x2c4/0x390
> [ 300.535652] ? __pfx_scsi_block_when_processing_errors+0x10/0x10
> [ 300.535953] ? __pfx___lock_acquire+0x10/0x10
> [ 300.536176] ? __sanitizer_cov_trace_switch+0x58/0xa0
> [ 300.536432] ? __sanitizer_cov_trace_const_cmp2+0x1c/0x30
> [ 300.536702] ? do_vfs_ioctl+0x4fa/0x1920
> [ 300.536906] ? __pfx_do_vfs_ioctl+0x10/0x10
> [ 300.537122] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.537395] sg_ioctl+0xfb8/0x2880
> [ 300.537574] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.537815] ? lock_release+0x441/0x870
> [ 300.538019] ? __pfx_sg_ioctl+0x10/0x10
> [ 300.538221] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.538462] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
> [ 300.538777] ? lockdep_hardirqs_on+0x89/0x110
> [ 300.539006] ? trace_hardirqs_on+0x51/0x60
> [ 300.539219] ? seqcount_lockdep_reader_access.constprop.0+0xc0/0xd0
> [ 300.539546] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
> [ 300.539792] ? ktime_get_coarse_real_ts64+0xbf/0xf0
> [ 300.540047] ? __pfx_sg_ioctl+0x10/0x10
> [ 300.540246] __x64_sys_ioctl+0x1b5/0x230
> [ 300.540452] x64_sys_call+0x1209/0x20d0
> [ 300.540650] do_syscall_64+0x6d/0x140
> [ 300.540842] entry_SYSCALL_64_after_hwframe+0x76/0x7e
> [ 300.541097] RIP: 0033:0x7f8b9783ee5d
> [ 300.541282] RSP: 002b:00007ffc0329c228 EFLAGS: 00000206 ORIG_RAX: 0000000000000010
> [ 300.541652] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f8b9783ee5d
> [ 300.541999] RDX: 0000000020000080 RSI: 000000000000031f RDI: 0000000000000003
> [ 300.542347] RBP: 00007ffc0329c240 R08: 00007ffc0329bfb8 R09: 00007ffc0329c240
> [ 300.542695] R10: 0000000000000000 R11: 0000000000000206 R12: 00007ffc0329c398
> [ 300.543048] R13: 0000000000401972 R14: 0000000000403e08 R15: 00007f8b97aff000
> [ 300.543422] </TASK>
> [ 300.543540] INFO: task repro:690 blocked for more than 147 seconds.
> [ 300.543847] Not tainted 6.12.0-rc3-8e929cb546ee+ #1
> [ 300.544111] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 300.544487] task:repro state:D stack:0 pid:690 tgid:690 ppid:689 flags:0x00000006
> [ 300.544939] Call Trace:
> [ 300.545069] <TASK>
> [ 300.545186] __schedule+0xe13/0x33a0
> [ 300.545380] ? __pfx___schedule+0x10/0x10
> [ 300.545585] ? lock_release+0x441/0x870
> [ 300.545787] ? __pfx_lock_release+0x10/0x10
> [ 300.546000] ? trace_lock_acquire+0x139/0x1b0
> [ 300.546230] ? lock_acquire+0x80/0xb0
> [ 300.546420] ? schedule+0x216/0x3f0
> [ 300.546607] schedule+0xf6/0x3f0
> [ 300.546781] io_schedule+0xce/0x150
> [ 300.546967] blk_mq_get_tag+0x5e7/0xce0
> [ 300.547174] ? __pfx_blk_mq_get_tag+0x10/0x10
> [ 300.547416] ? __pfx_autoremove_wake_function+0x10/0x10
> [ 300.547687] __blk_mq_alloc_requests+0x6f6/0x1720
> [ 300.547929] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
> [ 300.548210] ? __pfx___blk_mq_alloc_requests+0x10/0x10
> [ 300.548471] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.548714] ? lock_acquire.part.0+0x152/0x390
> [ 300.548948] blk_mq_alloc_request+0x655/0x930
> [ 300.549181] ? __pfx_blk_mq_alloc_request+0x10/0x10
> [ 300.549443] scsi_execute_cmd+0x223/0x1040
> [ 300.549660] ? debug_smp_processor_id+0x20/0x30
> [ 300.549895] ? __pfx_scsi_execute_cmd+0x10/0x10
> [ 300.550126] ? rcu_is_watching+0x19/0xc0
> [ 300.550329] ? __kmalloc_noprof+0x34f/0x4a0
> [ 300.550543] ? ata_cmd_ioctl+0x375/0x570
> [ 300.550749] ata_cmd_ioctl+0x23c/0x570
> [ 300.550950] ? __pfx_ata_cmd_ioctl+0x10/0x10
> [ 300.551170] ? lock_release+0x441/0x870
> [ 300.551391] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.551641] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.551911] ? security_capable+0x19d/0x1e0
> [ 300.552131] ata_sas_scsi_ioctl+0x60a/0x7c0
> [ 300.552344] ? mark_lock.part.0+0xf3/0x17b0
> [ 300.552558] ? __pfx_ata_sas_scsi_ioctl+0x10/0x10
> [ 300.552796] ? __pfx_mark_lock.part.0+0x10/0x10
> [ 300.553033] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.553274] ? lock_is_held_type+0xef/0x150
> [ 300.553491] ? __pfx_ata_scsi_ioctl+0x10/0x10
> [ 300.553716] ata_scsi_ioctl+0x70/0x90
> [ 300.553909] scsi_ioctl+0xb6f/0x1630
> [ 300.554099] ? __might_sleep+0xa3/0x170
> [ 300.554301] ? __pfx_scsi_ioctl+0x10/0x10
> [ 300.554510] ? scsi_block_when_processing_errors+0x2c4/0x390
> [ 300.554800] ? __pfx_scsi_block_when_processing_errors+0x10/0x10
> [ 300.555103] ? __pfx___lock_acquire+0x10/0x10
> [ 300.555350] ? __sanitizer_cov_trace_switch+0x58/0xa0
> [ 300.555608] ? __sanitizer_cov_trace_const_cmp2+0x1c/0x30
> [ 300.555877] ? do_vfs_ioctl+0x4fa/0x1920
> [ 300.556082] ? __pfx_do_vfs_ioctl+0x10/0x10
> [ 300.556297] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
> [ 300.556569] sg_ioctl+0xfb8/0x2880
> [ 300.556747] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.556987] ? lock_release+0x441/0x870
> [ 300.557189] ? __pfx_sg_ioctl+0x10/0x10
> [ 300.557391] ? __this_cpu_preempt_check+0x21/0x30
> [ 300.557631] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
> [ 300.557945] ? lockdep_hardirqs_on+0x89/0x110
> [ 300.558171] ? trace_hardirqs_on+0x51/0x60
> [ 300.558382] ? seqcount_lockdep_reader_access.constprop.0+0xc0/0xd0
> [ 300.558695] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
> [ 300.558944] ? ktime_get_coarse_real_ts64+0xbf/0xf0
> [ 300.559201] ? __pfx_sg_ioctl+0x10/0x10
> [ 300.559427] __x64_sys_ioctl+0x1b5/0x230
> [ 300.559635] x64_sys_call+0x1209/0x20d0
> [ 300.559833] do_syscall_64+0x6d/0x140
> [ 300.560025] entry_SYSCALL_64_after_hwframe+0x76/0x7e
> [ 300.560278] RIP: 0033:0x7f8b9783ee5d
> [ 300.560463] RSP: 002b:00007ffc0329c228 EFLAGS: 00000206 ORIG_RAX: 0000000000000010
> [ 300.560832] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f8b9783ee5d
> [ 300.561180] RDX: 0000000020000080 RSI: 000000000000031f RDI: 0000000000000003
> [ 300.561527] RBP: 00007ffc0329c240 R08: 00007ffc0329bfb8 R09: 00007ffc0329c240
> [ 300.561877] R10: 0000000000000000 R11: 0000000000000206 R12: 00007ffc0329c398
> [ 300.562227] R13: 0000000000401972 R14: 0000000000403e08 R15: 00007f8b97aff000
> [ 300.562588] </TASK>
> [ 300.562706] Future hung task reports are suppressed, see sysctl kernel.hung_task_warnings
> [ 300.563102]
> [ 300.563102] Showing all locks held in the system:
> [ 300.563420] 3 locks held by kworker/u8:0/11:
> [ 300.563636] #0: ffff88800df9a148 ((wq_completion)writeback){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
> [ 300.564146] #1: ffff88800dcd7d78 ((work_completion)(&(&wb->dwork)->work)){+.+.}-{0:0}, at: process_one_work+0x8a0/0x1b0
> [ 300.564687] #2: ffff88800d77a0e0 (&type->s_umount_key#52){.+.+}-{3:3}, at: super_trylock_shared+0x2b/0x110
> [ 300.565179] 4 locks held by kworker/u8:1/31:
> [ 300.565394] #0: ffff8880125bd148 ((wq_completion)ext4-rsv-conversion){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
> [ 300.565924] #1: ffff88800df4fd78 ((work_completion)(&ei->i_rsv_conversion_work)){+.+.}-{0:0}, at: process_one_work+0x80
> [ 300.566500] #2: ffff888012672958 (jbd2_handle){++++}-{0:0}, at: start_this_handle+0x107b/0x1590
> [ 300.566948] #3: ffff888023638c60 (&ei->i_data_sem){++++}-{3:3}, at: ext4_map_blocks+0x344/0x1390
> [ 300.567407] 1 lock held by khungtaskd/33:
> [ 300.567612] #0: ffffffff8705c9c0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x73/0x3c0
> [ 300.568064] 4 locks held by kworker/u8:2/36:
> [ 300.568281] #0: ffff88800df9a148 ((wq_completion)writeback){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
> [ 300.568774] #1: ffff88800e4efd78 ((work_completion)(&(&wb->dwork)->work)){+.+.}-{0:0}, at: process_one_work+0x8a0/0x1b0
> [ 300.569316] #2: ffff8880126740e0 (&type->s_umount_key#38){++++}-{3:3}, at: super_trylock_shared+0x2b/0x110
> [ 300.569806] #3: ffff888012670b98 (&sbi->s_writepages_rwsem){++++}-{0:0}, at: do_writepages+0x1c3/0x8a0
> [ 300.570281] 4 locks held by kworker/1:2/80:
> [ 300.570491] #0: ffff88800d45ad48 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
> [ 300.570973] #1: ffff888011fefd78 ((work_completion)(&(&ap->scsi_rescan_task)->work)){+.+.}-{0:0}, at: process_one_work0
> [ 300.571572] #2: ffff888010a8c430 (&ap->scsi_scan_mutex){+.+.}-{3:3}, at: ata_scsi_dev_rescan+0x42/0x470
> [ 300.572044] #3: ffff888010b46378 (&dev->mutex){....}-{3:3}, at: scsi_rescan_device+0x33/0x360
> [ 300.572480] 4 locks held by auditd/239:
> [ 300.572674] #0: ffff8880134ccef8 (&f->f_pos_lock){+.+.}-{3:3}, at: fdget_pos+0x25e/0x380
> [ 300.573087] #1: ffff888012674408 (sb_writers#3){.+.+}-{0:0}, at: ksys_write+0x14f/0x290
> [ 300.573505] #2: ffff888017c87040 (&sb->s_type->i_mutex_key#8){++++}-{3:3}, at: ext4_buffered_write_iter+0xb8/0x3e0
> [ 300.574025] #3: ffff888012672958 (jbd2_handle){++++}-{0:0}, at: start_this_handle+0x107b/0x1590
> [ 300.574469] 3 locks held by in:imjournal/321:
> [ 300.574690] #0: ffff888012674408 (sb_writers#3){.+.+}-{0:0}, at: path_openat+0x1f7c/0x2bf0
> [ 300.575118] #1: ffff88801b708dd0 (&type->i_mutex_dir_key#3){++++}-{3:3}, at: path_openat+0xd40/0x2bf0
> [ 300.575606] #2: ffff888012672958 (jbd2_handle){++++}-{0:0}, at: start_this_handle+0x107b/0x1590
> [ 300.576052]
> [ 300.576138] =============================================
> "
>
> I hope you find it useful.
>
> Regards,
> Yi Lai
>
> ---
>
> If you don't need the following environment to reproduce the problem or if you
> already have one reproduced environment, please ignore the following information.
>
> How to reproduce:
> git clone https://gitlab.com/xupengfe/repro_vm_env.git
> cd repro_vm_env
> tar -xvf repro_vm_env.tar.gz
> cd repro_vm_env; ./start3.sh // it needs qemu-system-x86_64 and I used v7.1.0
> // start3.sh will load bzImage_2241ab53cbb5cdb08a6b2d4688feb13971058f65 v6.2-rc5 kernel
> // You could change the bzImage_xxx as you want
> // Maybe you need to remove line "-drive if=pflash,format=raw,readonly=on,file=./OVMF_CODE.fd \" for different qemu version
> You could use below command to log in, there is no password for root.
> ssh -p 10023 root@localhost
>
> After login vm(virtual machine) successfully, you could transfer reproduced
> binary to the vm by below way, and reproduce the problem in vm:
> gcc -pthread -o repro repro.c
> scp -P 10023 repro root@localhost:/root/
>
> Get the bzImage for target kernel:
> Please use target kconfig and copy it to kernel_src/.config
> make olddefconfig
> make -jx bzImage //x should equal or less than cpu num your pc has
>
> Fill the bzImage file into above start3.sh to load the target kernel in vm.
>
>
> Tips:
> If you already have qemu-system-x86_64, please ignore below info.
> If you want to install qemu v7.1.0 version:
> git clone https://github.com/qemu/qemu.git
> cd qemu
> git checkout -f v7.1.0
> mkdir build
> cd build
> yum install -y ninja-build.x86_64
> yum -y install libslirp-devel.x86_64
> ../configure --target-list=x86_64-softmmu --enable-kvm --enable-vnc --enable-gtk --enable-sdl --enable-usb-redir --enable-slirp
> make
> make install
>
> On Mon, Sep 09, 2024 at 05:42:38PM +0200, Niklas Cassel wrote:
> > When ata_qc_complete() schedules a command for EH using
> > ata_qc_schedule_eh(), blk_abort_request() will be called, which leads to
> > req->q->mq_ops->timeout() / scsi_timeout() being called.
> >
> > scsi_timeout(), if the LLDD has no abort handler (libata has no abort
> > handler), will set host byte to DID_TIME_OUT, and then call
> > scsi_eh_scmd_add() to add the command to EH.
> >
> > Thus, when commands first enter libata's EH strategy_handler, all the
> > commands that have been added to EH will have DID_TIME_OUT set.
> >
> > libata has its own flag (AC_ERR_TIMEOUT), that it sets for commands that
> > have not received a completion at the time of entering EH.
> >
> > Thus, libata doesn't really care about DID_TIME_OUT at all, and currently
> > clears the host byte at the end of EH, in ata_scsi_qc_complete(), before
> > scsi_eh_finish_cmd() is called.
> >
> > However, this clearing in ata_scsi_qc_complete() is currently only done
> > for commands that are not ATA passthrough commands.
> >
> > Since the host byte is visible in the completion that we return to user
> > space for ATA passthrough commands, for ATA passthrough commands that got
> > completed via EH (commands with sense data), the user will incorrectly see:
> > ATA pass-through(16): transport error: Host_status=0x03 [DID_TIME_OUT]
> >
> > Fix this by moving the clearing of the host byte (which is currently only
> > done for commands that are not ATA passthrough commands) from
> > ata_scsi_qc_complete() to the start of EH (regardless if the command is
> > ATA passthrough or not).
> >
> > While at it, use the proper helper function to clear the host byte, rather
> > than open coding the clearing.
> >
> > This will make sure that we:
> > -Correctly clear DID_TIME_OUT for both ATA passthrough commands and
> > commands that are not ATA passthrough commands.
> > -Do not needlessly clear the host byte for commands that did not go via EH.
> > ata_scsi_qc_complete() is called both for commands that are completed
> > normally (without going via EH), and for commands that went via EH,
> > however, only commands that went via EH will have DID_TIME_OUT set.
> >
> > Fixes: 24aeebbf8ea9 ("scsi: ata: libata: Change ata_eh_request_sense() to not set CHECK_CONDITION")
> > Reported-by: Igor Pylypiv <ipylypiv@google.com>
> > Closes: https://lore.kernel.org/linux-ide/ZttIN8He8TOZ7Lct@google.com/
> > Signed-off-by: Niklas Cassel <cassel@kernel.org>
> > ---
> > Changes since v2: use set_host_byte() as suggested by Damien.
> >
> > drivers/ata/libata-eh.c | 8 ++++++++
> > drivers/ata/libata-scsi.c | 3 ---
> > 2 files changed, 8 insertions(+), 3 deletions(-)
> >
> > diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
> > index 7de97ee8e78b..703f5ce26765 100644
> > --- a/drivers/ata/libata-eh.c
> > +++ b/drivers/ata/libata-eh.c
> > @@ -630,6 +630,14 @@ void ata_scsi_cmd_error_handler(struct Scsi_Host *host, struct ata_port *ap,
> > list_for_each_entry_safe(scmd, tmp, eh_work_q, eh_entry) {
> > struct ata_queued_cmd *qc;
> >
> > + /*
> > + * If the scmd was added to EH, via ata_qc_schedule_eh() ->
> > + * scsi_timeout() -> scsi_eh_scmd_add(), scsi_timeout() will
> > + * have set DID_TIME_OUT (since libata does not have an abort
> > + * handler). Thus, to clear DID_TIME_OUT, clear the host byte.
> > + */
> > + set_host_byte(scmd, DID_OK);
> > +
> > ata_qc_for_each_raw(ap, qc, i) {
> > if (qc->flags & ATA_QCFLAG_ACTIVE &&
> > qc->scsicmd == scmd)
> > diff --git a/drivers/ata/libata-scsi.c b/drivers/ata/libata-scsi.c
> > index 3a442f564b0d..6a90062c8b55 100644
> > --- a/drivers/ata/libata-scsi.c
> > +++ b/drivers/ata/libata-scsi.c
> > @@ -1680,9 +1680,6 @@ static void ata_scsi_qc_complete(struct ata_queued_cmd *qc)
> > set_status_byte(qc->scsicmd, SAM_STAT_CHECK_CONDITION);
> > } else if (is_error && !have_sense) {
> > ata_gen_ata_sense(qc);
> > - } else {
> > - /* Keep the SCSI ML and status byte, clear host byte. */
> > - cmd->result &= 0x0000ffff;
> > }
> >
> > ata_qc_done(qc);
> > --
> > 2.46.0
> >
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
2024-10-21 12:07 ` Niklas Cassel
@ 2024-10-21 12:34 ` Damien Le Moal
2024-10-21 15:20 ` Niklas Cassel
1 sibling, 0 replies; 10+ messages in thread
From: Damien Le Moal @ 2024-10-21 12:34 UTC (permalink / raw)
To: Niklas Cassel, Lai, Yi
Cc: Hannes Reinecke, Martin K. Petersen, Igor Pylypiv, Niklas Cassel,
linux-ide, yi1.lai, syzkaller-bugs, linux-kernel
On 10/21/24 21:07, Niklas Cassel wrote:
> Hello Yi Lai,
>
> On Mon, Oct 21, 2024 at 06:58:59PM +0800, Lai, Yi wrote:
>> Hi Niklas Cassel,
>>
>> Greetings!
>>
>> I used Syzkaller and found that there is INFO: task hung in blk_mq_get_tag in v6.12-rc3
>>
>> After bisection and the first bad commit is:
>> "
>> e5dd410acb34 ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
>> "
>
> It might be that your bisection results are accurate.
>
> However, after looking at the stacktraces, I find it way more likely that
> bisection has landed on the wrong commit.
>
> See this series that was just queued (for 6.13) a few days ago that solves a
> similar starvation:
> https://lore.kernel.org/linux-block/20241014092934.53630-1-songmuchun@bytedance.com/
> https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git/log/?h=for-6.13/block
>
> You could perhaps run with v6.14-rc4 (which should be able to trigger the bug)
> and then try v6.14-rc4 + that series applied, to see if you can still trigger
> the bug?
s/6.14/6.13 in this paragraph :)
--
Damien Le Moal
Western Digital Research
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
2024-10-21 12:07 ` Niklas Cassel
2024-10-21 12:34 ` Damien Le Moal
@ 2024-10-21 15:20 ` Niklas Cassel
2024-10-22 5:44 ` Lai, Yi
1 sibling, 1 reply; 10+ messages in thread
From: Niklas Cassel @ 2024-10-21 15:20 UTC (permalink / raw)
To: Lai, Yi
Cc: Damien Le Moal, Hannes Reinecke, Martin K. Petersen, Igor Pylypiv,
Niklas Cassel, linux-ide, yi1.lai, syzkaller-bugs, linux-kernel
On Mon, Oct 21, 2024 at 02:07:21PM +0200, Niklas Cassel wrote:
> Hello Yi Lai,
>
> On Mon, Oct 21, 2024 at 06:58:59PM +0800, Lai, Yi wrote:
> > Hi Niklas Cassel,
> >
> > Greetings!
> >
> > I used Syzkaller and found that there is INFO: task hung in blk_mq_get_tag in v6.12-rc3
> >
> > After bisection and the first bad commit is:
> > "
> > e5dd410acb34 ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
> > "
>
> It might be that your bisection results are accurate.
>
> However, after looking at the stacktraces, I find it way more likely that
> bisection has landed on the wrong commit.
>
> See this series that was just queued (for 6.13) a few days ago that solves a
> similar starvation:
> https://lore.kernel.org/linux-block/20241014092934.53630-1-songmuchun@bytedance.com/
> https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git/log/?h=for-6.13/block
>
> You could perhaps run with v6.14-rc4 (which should be able to trigger the bug)
> and then try v6.14-rc4 + that series applied, to see if you can still trigger
> the bug?
Another patch that might be relevant:
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=e972b08b91ef48488bae9789f03cfedb148667fb
Which fixes a use after delete in rq_qos_wake_function().
(We can see that the stack trace has rq_qos_wake_function() before
getting stuck forever in rq_qos_wait())
Who knows what could go wrong when accessing a deleted entry, in the
report there was a crash, but I could image other surprises :)
The fix was first included in v6.12-rc4.
Kind regards,
Niklas
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
2024-10-21 15:20 ` Niklas Cassel
@ 2024-10-22 5:44 ` Lai, Yi
2024-10-22 8:48 ` Niklas Cassel
0 siblings, 1 reply; 10+ messages in thread
From: Lai, Yi @ 2024-10-22 5:44 UTC (permalink / raw)
To: Niklas Cassel
Cc: Damien Le Moal, Hannes Reinecke, Martin K. Petersen, Igor Pylypiv,
Niklas Cassel, linux-ide, yi1.lai, syzkaller-bugs, linux-kernel
On Mon, Oct 21, 2024 at 05:20:12PM +0200, Niklas Cassel wrote:
> On Mon, Oct 21, 2024 at 02:07:21PM +0200, Niklas Cassel wrote:
> > Hello Yi Lai,
> >
> > On Mon, Oct 21, 2024 at 06:58:59PM +0800, Lai, Yi wrote:
> > > Hi Niklas Cassel,
> > >
> > > Greetings!
> > >
> > > I used Syzkaller and found that there is INFO: task hung in blk_mq_get_tag in v6.12-rc3
> > >
> > > After bisection and the first bad commit is:
> > > "
> > > e5dd410acb34 ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
> > > "
> >
> > It might be that your bisection results are accurate.
> >
> > However, after looking at the stacktraces, I find it way more likely that
> > bisection has landed on the wrong commit.
> >
> > See this series that was just queued (for 6.13) a few days ago that solves a
> > similar starvation:
> > https://lore.kernel.org/linux-block/20241014092934.53630-1-songmuchun@bytedance.com/
> > https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git/log/?h=for-6.13/block
> >
> > You could perhaps run with v6.14-rc4 (which should be able to trigger the bug)
> > and then try v6.14-rc4 + that series applied, to see if you can still trigger
> > the bug?
>
> Another patch that might be relevant:
> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=e972b08b91ef48488bae9789f03cfedb148667fb
>
> Which fixes a use after delete in rq_qos_wake_function().
> (We can see that the stack trace has rq_qos_wake_function() before
> getting stuck forever in rq_qos_wait())
>
> Who knows what could go wrong when accessing a deleted entry, in the
> report there was a crash, but I could image other surprises :)
> The fix was first included in v6.12-rc4.
>
>
Hi Niklas,
Thanks for the info. I have tried using v6.12-rc4 kernel to reproduce
the issue. Using the same repro binary, the issue still exists.
[ 300.430914] INFO: task kworker/u8:0:11 blocked for more than 147 seconds.
[ 300.431593] Not tainted 6.12.0-rc4-kvm #1
[ 300.431988] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.432640] task:kworker/u8:0 state:D stack:0 pid:11 tgid:11 ppid:2 flags:0x00004000
[ 300.433431] Workqueue: writeback wb_workfn (flush-8:0)
[ 300.433908] Call Trace:
[ 300.434132] <TASK>
[ 300.434335] __schedule+0xe13/0x33a0
[ 300.434687] ? __pfx___schedule+0x10/0x10
[ 300.435055] ? lock_release+0x441/0x870
[ 300.435393] ? __pfx_lock_release+0x10/0x10
[ 300.435730] ? trace_lock_acquire+0x139/0x1b0
[ 300.436100] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.436533] ? kthread_data+0x61/0xd0
[ 300.436848] schedule+0xf6/0x3f0
[ 300.437123] io_schedule+0xce/0x150
[ 300.437413] bit_wait_io+0x1f/0x100
[ 300.437707] __wait_on_bit+0x68/0x1b0
[ 300.438011] ? __pfx_bit_wait_io+0x10/0x10
[ 300.438351] out_of_line_wait_on_bit+0xe6/0x120
[ 300.438750] ? __pfx_out_of_line_wait_on_bit+0x10/0x10
[ 300.439162] ? __pfx_wake_bit_function+0x10/0x10
[ 300.439540] ? __might_sleep+0xa3/0x170
[ 300.439864] do_get_write_access+0x83b/0x1010
[ 300.440241] jbd2_journal_get_write_access+0x1e4/0x270
[ 300.440655] __ext4_journal_get_write_access+0x72/0x3b0
[ 300.441238] ext4_mb_mark_context+0x184/0xe30
[ 300.441709] ? __pfx_lock_release+0x10/0x10
[ 300.442156] ? __pfx_ext4_mb_mark_context+0x10/0x10
[ 300.442650] ? ext4_sb_block_valid+0x3a6/0x670
[ 300.443134] ext4_mb_mark_diskspace_used+0x44d/0x9e0
[ 300.443595] ? ext4_get_group_no_and_offset+0x186/0x1f0
[ 300.444074] ? __pfx_ext4_mb_mark_diskspace_used+0x10/0x10
[ 300.444582] ext4_mb_new_blocks+0x779/0x4790
[ 300.444966] ? lock_is_held_type+0xef/0x150
[ 300.445349] ? kasan_save_track+0x18/0x40
[ 300.445727] ? __pfx_ext4_mb_new_blocks+0x10/0x10
[ 300.446139] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.446598] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.447066] ? ext4_inode_to_goal_block+0x340/0x450
[ 300.447486] ext4_ext_map_blocks+0x16f0/0x6060
[ 300.447877] ? __pfx___lock_acquire+0x10/0x10
[ 300.448251] ? stack_trace_save+0x97/0xd0
[ 300.448599] ? __pfx_ext4_ext_map_blocks+0x10/0x10
[ 300.449001] ? debug_smp_processor_id+0x20/0x30
[ 300.449372] ? rcu_is_watching+0x19/0xc0
[ 300.449701] ? trace_lock_acquire+0x139/0x1b0
[ 300.450065] ? lock_acquire+0x80/0xb0
[ 300.450359] ? ext4_map_blocks+0x344/0x1390
[ 300.450696] ? __pfx_down_write+0x10/0x10
[ 300.451048] ext4_map_blocks+0x421/0x1390
[ 300.451373] ? __pfx_ext4_map_blocks+0x10/0x10
[ 300.451718] ? kasan_save_track+0x18/0x40
[ 300.452030] ? debug_smp_processor_id+0x20/0x30
[ 300.452374] ? rcu_is_watching+0x19/0xc0
[ 300.452674] ? kmem_cache_alloc_noprof+0x2e7/0x370
[ 300.453040] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.453430] ext4_do_writepages+0x18e0/0x2f30
[ 300.453775] ? __pfx_ext4_do_writepages+0x10/0x10
[ 300.454115] ? rcu_is_watching+0x19/0xc0
[ 300.454411] ? __this_cpu_preempt_check+0x21/0x30
[ 300.454760] ? lock_is_held_type+0xef/0x150
[ 300.455063] ext4_writepages+0x35c/0x7c0
[ 300.455345] ? __pfx_ext4_writepages+0x10/0x10
[ 300.455658] ? lock_release+0x441/0x870
[ 300.455948] ? do_raw_spin_unlock+0x15c/0x210
[ 300.456250] ? __pfx_ext4_writepages+0x10/0x10
[ 300.456557] do_writepages+0x1c3/0x8a0
[ 300.456833] ? __pfx_do_writepages+0x10/0x10
[ 300.457127] ? __pfx_lock_release+0x10/0x10
[ 300.457413] ? __pfx_lock_release+0x10/0x10
[ 300.457711] __writeback_single_inode+0x124/0xe10
[ 300.458033] ? wbc_attach_and_unlock_inode+0x5a9/0x950
[ 300.458385] writeback_sb_inodes+0x63b/0x1000
[ 300.458675] ? lock_release+0x441/0x870
[ 300.458956] ? __pfx_writeback_sb_inodes+0x10/0x10
[ 300.459270] ? lock_acquire.part.0+0x152/0x390
[ 300.459605] ? __sanitizer_cov_trace_const_cmp8+0x1c/0x30
[ 300.459959] __writeback_inodes_wb+0xc8/0x280
[ 300.460248] wb_writeback+0x717/0xaf0
[ 300.460496] ? __pfx_wb_writeback+0x10/0x10
[ 300.460772] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.461086] ? get_nr_dirty_inodes+0x12c/0x1b0
[ 300.461374] ? lockdep_hardirqs_on+0x89/0x110
[ 300.461660] wb_workfn+0x7b5/0xc90
[ 300.461888] ? __pfx_lock_acquire.part.0+0x10/0x10
[ 300.462198] ? __pfx_wb_workfn+0x10/0x10
[ 300.462446] ? rcu_is_watching+0x19/0xc0
[ 300.462707] process_one_work+0x92e/0x1b50
[ 300.462994] ? lock_acquire.part.0+0x152/0x390
[ 300.463285] ? __pfx_process_one_work+0x10/0x10
[ 300.463566] ? move_linked_works+0x1bf/0x2c0
[ 300.463839] ? __this_cpu_preempt_check+0x21/0x30
[ 300.464138] ? assign_work+0x19f/0x250
[ 300.464375] ? lock_is_held_type+0xef/0x150
[ 300.464641] worker_thread+0x68d/0xe90
[ 300.464893] kthread+0x35a/0x470
[ 300.465095] ? __pfx_worker_thread+0x10/0x10
[ 300.465355] ? __pfx_kthread+0x10/0x10
[ 300.465587] ret_from_fork+0x56/0x90
[ 300.465812] ? __pfx_kthread+0x10/0x10
[ 300.466043] ret_from_fork_asm+0x1a/0x30
[ 300.466297] </TASK>
[ 300.466451] INFO: task kworker/u8:1:31 blocked for more than 147 seconds.
[ 300.466858] Not tainted 6.12.0-rc4-kvm #1
[ 300.467127] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.467573] task:kworker/u8:1 state:D stack:0 pid:31 tgid:31 ppid:2 flags:0x00004000
[ 300.468115] Workqueue: writeback wb_workfn (flush-8:0)
[ 300.468426] Call Trace:
[ 300.468579] <TASK>
[ 300.468717] __schedule+0xe13/0x33a0
[ 300.468951] ? __pfx___schedule+0x10/0x10
[ 300.469194] ? lock_release+0x441/0x870
[ 300.469433] ? __pfx_lock_release+0x10/0x10
[ 300.469686] ? trace_lock_acquire+0x139/0x1b0
[ 300.469957] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.470270] ? kthread_data+0x61/0xd0
[ 300.470492] schedule+0xf6/0x3f0
[ 300.470692] io_schedule+0xce/0x150
[ 300.470917] blk_mq_get_tag+0x5e7/0xce0
[ 300.471160] ? __pfx_blk_mq_get_tag+0x10/0x10
[ 300.471417] ? __pfx_wbt_cleanup_cb+0x10/0x10
[ 300.471677] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.471971] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.472275] ? __pfx_rq_qos_wake_function+0x10/0x10
[ 300.472558] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.472863] ? dd_limit_depth+0x21e/0x2a0
[ 300.473098] ? __pfx_dd_limit_depth+0x10/0x10
[ 300.473349] __blk_mq_alloc_requests+0x6f6/0x1720
[ 300.473632] ? __pfx___blk_mq_alloc_requests+0x10/0x10
[ 300.473926] ? __pfx_wbt_wait+0x10/0x10
[ 300.474152] blk_mq_submit_bio+0x93c/0x2a20
[ 300.474391] ? __kasan_check_read+0x15/0x20
[ 300.474645] ? __pfx_blk_mq_submit_bio+0x10/0x10
[ 300.474921] ? __pfx_mark_lock.part.0+0x10/0x10
[ 300.475182] ? __this_cpu_preempt_check+0x21/0x30
[ 300.475457] ? __this_cpu_preempt_check+0x21/0x30
[ 300.475727] ? lock_release+0x441/0x870
[ 300.475953] __submit_bio+0x18d/0x500
[ 300.476169] ? __pfx___submit_bio+0x10/0x10
[ 300.476407] ? __this_cpu_preempt_check+0x21/0x30
[ 300.476668] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.477018] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.477313] ? kvm_clock_get_cycles+0x43/0x70
[ 300.477566] submit_bio_noacct_nocheck+0x6a0/0xcc0
[ 300.477834] ? __pfx_submit_bio_noacct_nocheck+0x10/0x10
[ 300.478127] ? lock_is_held_type+0xef/0x150
[ 300.478369] submit_bio_noacct+0x61d/0x1dc0
[ 300.478610] submit_bio+0xce/0x480
[ 300.478819] ext4_io_submit+0xb0/0x150
[ 300.479036] ext4_do_writepages+0xa54/0x2f30
[ 300.479284] ? __this_cpu_preempt_check+0x21/0x30
[ 300.479556] ? __pfx_ext4_do_writepages+0x10/0x10
[ 300.479817] ? rcu_is_watching+0x19/0xc0
[ 300.480042] ? __this_cpu_preempt_check+0x21/0x30
[ 300.480304] ? lock_is_held_type+0xef/0x150
[ 300.480544] ext4_writepages+0x35c/0x7c0
[ 300.480766] ? __pfx_ext4_writepages+0x10/0x10
[ 300.481019] ? lock_release+0x441/0x870
[ 300.481247] ? do_raw_spin_unlock+0x15c/0x210
[ 300.481491] ? __pfx_ext4_writepages+0x10/0x10
[ 300.481734] do_writepages+0x1c3/0x8a0
[ 300.481947] ? __pfx_do_writepages+0x10/0x10
[ 300.482181] ? __pfx_lock_release+0x10/0x10
[ 300.482409] ? __pfx_lock_release+0x10/0x10
[ 300.482646] __writeback_single_inode+0x124/0xe10
[ 300.482912] ? wbc_attach_and_unlock_inode+0x5a9/0x950
[ 300.483192] writeback_sb_inodes+0x63b/0x1000
[ 300.483431] ? lock_release+0x441/0x870
[ 300.483652] ? __pfx_writeback_sb_inodes+0x10/0x10
[ 300.483911] ? lock_acquire.part.0+0x152/0x390
[ 300.484187] ? __sanitizer_cov_trace_const_cmp8+0x1c/0x30
[ 300.484478] __writeback_inodes_wb+0xc8/0x280
[ 300.484724] wb_writeback+0x717/0xaf0
[ 300.484938] ? __pfx_wb_writeback+0x10/0x10
[ 300.485172] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.485433] ? get_nr_dirty_inodes+0x12c/0x1b0
[ 300.485675] ? lockdep_hardirqs_on+0x89/0x110
[ 300.485917] wb_workfn+0x7b5/0xc90
[ 300.486111] ? __pfx_lock_acquire.part.0+0x10/0x10
[ 300.486375] ? __pfx_wb_workfn+0x10/0x10
[ 300.486591] ? rcu_is_watching+0x19/0xc0
[ 300.486831] process_one_work+0x92e/0x1b50
[ 300.487055] ? lock_acquire.part.0+0x152/0x390
[ 300.487308] ? __pfx_process_one_work+0x10/0x10
[ 300.487555] ? move_linked_works+0x1bf/0x2c0
[ 300.487791] ? __this_cpu_preempt_check+0x21/0x30
[ 300.488053] ? assign_work+0x19f/0x250
[ 300.488260] ? lock_is_held_type+0xef/0x150
[ 300.488493] worker_thread+0x68d/0xe90
[ 300.488701] ? lockdep_hardirqs_on+0x89/0x110
[ 300.488960] kthread+0x35a/0x470
[ 300.489141] ? __pfx_worker_thread+0x10/0x10
[ 300.489377] ? __pfx_kthread+0x10/0x10
[ 300.489586] ret_from_fork+0x56/0x90
[ 300.489785] ? __pfx_kthread+0x10/0x10
[ 300.489993] ret_from_fork_asm+0x1a/0x30
[ 300.490221] </TASK>
[ 300.490347] INFO: task kworker/u8:2:35 blocked for more than 147 seconds.
[ 300.490698] Not tainted 6.12.0-rc4-kvm #1
[ 300.490952] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.491353] task:kworker/u8:2 state:D stack:0 pid:35 tgid:35 ppid:2 flags:0x00004000
[ 300.491835] Workqueue: writeback wb_workfn (flush-8:0)
[ 300.492115] Call Trace:
[ 300.492252] <TASK>
[ 300.492377] __schedule+0xe13/0x33a0
[ 300.492585] ? __pfx___schedule+0x10/0x10
[ 300.492811] ? lock_release+0x441/0x870
[ 300.493031] ? __pfx_lock_release+0x10/0x10
[ 300.493259] ? trace_lock_acquire+0x139/0x1b0
[ 300.493502] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.493784] ? kthread_data+0x61/0xd0
[ 300.493985] schedule+0xf6/0x3f0
[ 300.494165] io_schedule+0xce/0x150
[ 300.494358] blk_mq_get_tag+0x5e7/0xce0
[ 300.494570] ? __pfx_blk_mq_get_tag+0x10/0x10
[ 300.494815] ? __pfx___mod_timer+0x10/0x10
[ 300.495036] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.495311] ? __pfx_rq_qos_wake_function+0x10/0x10
[ 300.495571] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.495852] ? dd_limit_depth+0x21e/0x2a0
[ 300.496069] ? __pfx_dd_limit_depth+0x10/0x10
[ 300.496303] __blk_mq_alloc_requests+0x6f6/0x1720
[ 300.496552] ? mod_timer+0x29/0x40
[ 300.496749] ? __pfx___blk_mq_alloc_requests+0x10/0x10
[ 300.497028] ? __pfx_wbt_wait+0x10/0x10
[ 300.497239] blk_mq_submit_bio+0x93c/0x2a20
[ 300.497461] ? __kasan_check_read+0x15/0x20
[ 300.497691] ? __pfx_blk_mq_submit_bio+0x10/0x10
[ 300.497935] ? __pfx_mark_lock.part.0+0x10/0x10
[ 300.498177] ? __this_cpu_preempt_check+0x21/0x30
[ 300.498433] ? __this_cpu_preempt_check+0x21/0x30
[ 300.498683] ? lock_release+0x441/0x870
[ 300.498905] __submit_bio+0x18d/0x500
[ 300.499105] ? __pfx___submit_bio+0x10/0x10
[ 300.499329] ? __this_cpu_preempt_check+0x21/0x30
[ 300.499578] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.499908] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.500192] ? kvm_clock_get_cycles+0x43/0x70
[ 300.500430] submit_bio_noacct_nocheck+0x6a0/0xcc0
[ 300.500687] ? __pfx_submit_bio_noacct_nocheck+0x10/0x10
[ 300.500985] submit_bio_noacct+0x61d/0x1dc0
[ 300.501216] submit_bio+0xce/0x480
[ 300.501405] ext4_io_submit+0xb0/0x150
[ 300.501611] ext4_do_writepages+0x1103/0x2f30
[ 300.501862] ? __pfx_ext4_do_writepages+0x10/0x10
[ 300.502111] ? rcu_is_watching+0x19/0xc0
[ 300.502326] ? __this_cpu_preempt_check+0x21/0x30
[ 300.502577] ? lock_is_held_type+0xef/0x150
[ 300.502820] ext4_writepages+0x35c/0x7c0
[ 300.503034] ? __pfx_ext4_writepages+0x10/0x10
[ 300.503271] ? lock_release+0x441/0x870
[ 300.503489] ? do_raw_spin_unlock+0x15c/0x210
[ 300.503725] ? __pfx_ext4_writepages+0x10/0x10
[ 300.503964] do_writepages+0x1c3/0x8a0
[ 300.504171] ? __pfx_do_writepages+0x10/0x10
[ 300.504400] ? __pfx_lock_release+0x10/0x10
[ 300.504623] ? __pfx_lock_release+0x10/0x10
[ 300.504865] __writeback_single_inode+0x124/0xe10
[ 300.505117] ? wbc_attach_and_unlock_inode+0x5a9/0x950
[ 300.505399] writeback_sb_inodes+0x63b/0x1000
[ 300.505641] ? lock_release+0x441/0x870
[ 300.505863] ? __pfx_writeback_sb_inodes+0x10/0x10
[ 300.506123] ? lock_acquire.part.0+0x152/0x390
[ 300.506400] ? __sanitizer_cov_trace_const_cmp8+0x1c/0x30
[ 300.506692] __writeback_inodes_wb+0xc8/0x280
[ 300.506953] wb_writeback+0x717/0xaf0
[ 300.507164] ? __pfx_wb_writeback+0x10/0x10
[ 300.507394] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.507656] ? get_nr_dirty_inodes+0x12c/0x1b0
[ 300.507898] ? lockdep_hardirqs_on+0x89/0x110
[ 300.508140] wb_workfn+0x7b5/0xc90
[ 300.508337] ? __pfx_lock_acquire.part.0+0x10/0x10
[ 300.508601] ? __pfx_wb_workfn+0x10/0x10
[ 300.508822] ? rcu_is_watching+0x19/0xc0
[ 300.509047] process_one_work+0x92e/0x1b50
[ 300.509265] ? lock_acquire.part.0+0x152/0x390
[ 300.509512] ? __pfx_process_one_work+0x10/0x10
[ 300.509752] ? move_linked_works+0x1bf/0x2c0
[ 300.509982] ? __this_cpu_preempt_check+0x21/0x30
[ 300.510238] ? assign_work+0x19f/0x250
[ 300.510440] ? lock_is_held_type+0xef/0x150
[ 300.510667] worker_thread+0x68d/0xe90
[ 300.510895] kthread+0x35a/0x470
[ 300.511073] ? __pfx_worker_thread+0x10/0x10
[ 300.511302] ? __pfx_kthread+0x10/0x10
[ 300.511507] ret_from_fork+0x56/0x90
[ 300.511702] ? __pfx_kthread+0x10/0x10
[ 300.511906] ret_from_fork_asm+0x1a/0x30
[ 300.512128] </TASK>
[ 300.512270] INFO: task jbd2/sda-8:104 blocked for more than 147 seconds.
[ 300.512609] Not tainted 6.12.0-rc4-kvm #1
[ 300.512847] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.513237] task:jbd2/sda-8 state:D stack:0 pid:104 tgid:104 ppid:2 flags:0x00004000
[ 300.513707] Call Trace:
[ 300.513840] <TASK>
[ 300.513961] __schedule+0xe13/0x33a0
[ 300.514162] ? __pfx___schedule+0x10/0x10
[ 300.514376] ? lock_release+0x441/0x870
[ 300.514586] ? __pfx_lock_release+0x10/0x10
[ 300.514819] ? trace_lock_acquire+0x139/0x1b0
[ 300.515057] ? lock_acquire+0x80/0xb0
[ 300.515254] ? schedule+0x216/0x3f0
[ 300.515448] schedule+0xf6/0x3f0
[ 300.515629] io_schedule+0xce/0x150
[ 300.515820] blk_mq_get_tag+0x5e7/0xce0
[ 300.516033] ? __pfx_blk_mq_get_tag+0x10/0x10
[ 300.516266] ? lock_release+0x441/0x870
[ 300.516471] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.516737] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.517014] ? blk_mq_sched_try_merge+0xce/0x650
[ 300.517261] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.517542] ? dd_limit_depth+0x21e/0x2a0
[ 300.517758] ? __pfx_dd_limit_depth+0x10/0x10
[ 300.517992] __blk_mq_alloc_requests+0x6f6/0x1720
[ 300.518246] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.518534] ? __pfx___blk_mq_alloc_requests+0x10/0x10
[ 300.518818] ? __pfx_wbt_wait+0x10/0x10
[ 300.519029] blk_mq_submit_bio+0x93c/0x2a20
[ 300.519251] ? __pfx___lock_acquire+0x10/0x10
[ 300.519490] ? __pfx_blk_mq_submit_bio+0x10/0x10
[ 300.519736] ? __this_cpu_preempt_check+0x21/0x30
[ 300.519991] ? __this_cpu_preempt_check+0x21/0x30
[ 300.520242] ? lock_release+0x441/0x870
[ 300.520451] __submit_bio+0x18d/0x500
[ 300.520650] ? __pfx___submit_bio+0x10/0x10
[ 300.520879] ? __this_cpu_preempt_check+0x21/0x30
[ 300.521130] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.521458] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.521738] ? kvm_clock_get_cycles+0x43/0x70
[ 300.521977] submit_bio_noacct_nocheck+0x6a0/0xcc0
[ 300.522226] ? __pfx_submit_bio_noacct_nocheck+0x10/0x10
[ 300.522504] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.522782] submit_bio_noacct+0x61d/0x1dc0
[ 300.523006] submit_bio+0xce/0x480
[ 300.523190] submit_bh_wbc+0x58a/0x740
[ 300.523397] submit_bh+0x2b/0x40
[ 300.523572] jbd2_journal_commit_transaction+0x2a09/0x65e0
[ 300.523873] ? __pfx_jbd2_journal_commit_transaction+0x10/0x10
[ 300.524176] ? __this_cpu_preempt_check+0x21/0x30
[ 300.524420] ? lock_release+0x441/0x870
[ 300.524630] ? __this_cpu_preempt_check+0x21/0x30
[ 300.524879] ? _raw_spin_unlock_irqrestore+0x45/0x70
[ 300.525135] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.525417] ? kjournald2+0x5e7/0x790
[ 300.525616] kjournald2+0x204/0x790
[ 300.525809] ? __pfx_kjournald2+0x10/0x10
[ 300.526017] ? lockdep_hardirqs_on+0x89/0x110
[ 300.526245] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.526513] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.526797] ? __kthread_parkme+0x15d/0x230
[ 300.527019] kthread+0x35a/0x470
[ 300.527192] ? __pfx_kjournald2+0x10/0x10
[ 300.527399] ? __pfx_kthread+0x10/0x10
[ 300.527597] ret_from_fork+0x56/0x90
[ 300.527787] ? __pfx_kthread+0x10/0x10
[ 300.527984] ret_from_fork_asm+0x1a/0x30
[ 300.528200] </TASK>
[ 300.528319] INFO: task kworker/u8:4:167 blocked for more than 147 seconds.
[ 300.528657] Not tainted 6.12.0-rc4-kvm #1
[ 300.528891] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.529273] task:kworker/u8:4 state:D stack:0 pid:167 tgid:167 ppid:2 flags:0x00004000
[ 300.529732] Workqueue: writeback wb_workfn (flush-8:0)
[ 300.529998] Call Trace:
[ 300.530128] <TASK>
[ 300.530246] __schedule+0xe13/0x33a0
[ 300.530443] ? __pfx___schedule+0x10/0x10
[ 300.530651] ? lock_release+0x441/0x870
[ 300.530867] ? __pfx_lock_release+0x10/0x10
[ 300.531084] ? trace_lock_acquire+0x139/0x1b0
[ 300.531316] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.531589] ? kthread_data+0x61/0xd0
[ 300.531785] schedule+0xf6/0x3f0
[ 300.531961] io_schedule+0xce/0x150
[ 300.532148] rq_qos_wait+0x1c5/0x310
[ 300.532336] ? __pfx_wbt_cleanup_cb+0x10/0x10
[ 300.532563] ? __pfx_rq_qos_wait+0x10/0x10
[ 300.532780] ? __pfx_lock_release+0x10/0x10
[ 300.533000] ? __pfx_rq_qos_wake_function+0x10/0x10
[ 300.533254] ? __pfx_wbt_inflight_cb+0x10/0x10
[ 300.533487] ? do_raw_spin_unlock+0x15c/0x210
[ 300.533719] wbt_wait+0x1ec/0x400
[ 300.533898] ? __pfx_wbt_wait+0x10/0x10
[ 300.534100] ? __pfx_dd_bio_merge+0x10/0x10
[ 300.534321] ? __pfx_wbt_wait+0x10/0x10
[ 300.534523] __rq_qos_throttle+0x5f/0xb0
[ 300.534748] blk_mq_submit_bio+0x8ad/0x2a20
[ 300.534966] ? __kasan_check_read+0x15/0x20
[ 300.535188] ? __pfx_blk_mq_submit_bio+0x10/0x10
[ 300.535426] ? __pfx_mark_lock.part.0+0x10/0x10
[ 300.535663] ? __this_cpu_preempt_check+0x21/0x30
[ 300.535912] ? __this_cpu_preempt_check+0x21/0x30
[ 300.536156] ? lock_release+0x441/0x870
[ 300.536362] __submit_bio+0x18d/0x500
[ 300.536556] ? __pfx___submit_bio+0x10/0x10
[ 300.536777] ? __this_cpu_preempt_check+0x21/0x30
[ 300.537021] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.537342] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.537616] ? kvm_clock_get_cycles+0x43/0x70
[ 300.537849] submit_bio_noacct_nocheck+0x6a0/0xcc0
[ 300.538098] ? __pfx_submit_bio_noacct_nocheck+0x10/0x10
[ 300.538375] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.538637] submit_bio_noacct+0x61d/0x1dc0
[ 300.538874] submit_bio+0xce/0x480
[ 300.539059] submit_bh_wbc+0x58a/0x740
[ 300.539263] __block_write_full_folio+0x7a1/0xed0
[ 300.539506] ? __pfx_blkdev_get_block+0x10/0x10
[ 300.539749] block_write_full_folio+0x2e6/0x3a0
[ 300.539985] ? __pfx_blkdev_get_block+0x10/0x10
[ 300.540224] ? __pfx_blkdev_get_block+0x10/0x10
[ 300.540460] write_cache_pages+0xbc/0x140
[ 300.540670] ? __pfx_block_write_full_folio+0x10/0x10
[ 300.540933] ? __pfx_write_cache_pages+0x10/0x10
[ 300.541178] ? __this_cpu_preempt_check+0x21/0x30
[ 300.541427] blkdev_writepages+0xa5/0xf0
[ 300.541634] ? __pfx_blkdev_writepages+0x10/0x10
[ 300.541874] ? __pfx_do_raw_spin_lock+0x10/0x10
[ 300.542117] ? do_raw_spin_unlock+0x15c/0x210
[ 300.542349] ? __pfx_blkdev_writepages+0x10/0x10
[ 300.542590] do_writepages+0x1c3/0x8a0
[ 300.542809] ? __pfx_do_writepages+0x10/0x10
[ 300.543017] ? __pfx_lock_release+0x10/0x10
[ 300.543216] ? lock_release+0x441/0x870
[ 300.543410] __writeback_single_inode+0x124/0xe10
[ 300.543649] ? wbc_attach_and_unlock_inode+0x5a9/0x950
[ 300.543918] writeback_sb_inodes+0x63b/0x1000
[ 300.544159] ? __pfx_writeback_sb_inodes+0x10/0x10
[ 300.544405] ? lock_acquire.part.0+0x152/0x390
[ 300.544669] ? __sanitizer_cov_trace_const_cmp8+0x1c/0x30
[ 300.544949] __writeback_inodes_wb+0xc8/0x280
[ 300.545184] wb_writeback+0x717/0xaf0
[ 300.545385] ? __pfx_wb_writeback+0x10/0x10
[ 300.545604] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.545859] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.546109] ? get_nr_dirty_inodes+0x12c/0x1b0
[ 300.546342] ? lockdep_hardirqs_on+0x89/0x110
[ 300.546574] wb_workfn+0x76c/0xc90
[ 300.546773] ? __pfx_lock_acquire.part.0+0x10/0x10
[ 300.547026] ? __pfx_wb_workfn+0x10/0x10
[ 300.547234] ? rcu_is_watching+0x19/0xc0
[ 300.547452] process_one_work+0x92e/0x1b50
[ 300.547666] ? lock_acquire.part.0+0x152/0x390
[ 300.547908] ? __pfx_process_one_work+0x10/0x10
[ 300.548144] ? move_linked_works+0x1bf/0x2c0
[ 300.548370] ? __this_cpu_preempt_check+0x21/0x30
[ 300.548620] ? assign_work+0x19f/0x250
[ 300.548821] ? lock_is_held_type+0xef/0x150
[ 300.549043] worker_thread+0x68d/0xe90
[ 300.549242] ? lockdep_hardirqs_on+0x89/0x110
[ 300.549481] kthread+0x35a/0x470
[ 300.549655] ? __pfx_worker_thread+0x10/0x10
[ 300.549880] ? __pfx_kthread+0x10/0x10
[ 300.550080] ret_from_fork+0x56/0x90
[ 300.550270] ? __pfx_kthread+0x10/0x10
[ 300.550470] ret_from_fork_asm+0x1a/0x30
[ 300.550687] </TASK>
[ 300.550826] INFO: task kworker/1:3:233 blocked for more than 147 seconds.
[ 300.551165] Not tainted 6.12.0-rc4-kvm #1
[ 300.551396] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.551780] task:kworker/1:3 state:D stack:0 pid:233 tgid:233 ppid:2 flags:0x00004000
[ 300.552242] Workqueue: events ata_scsi_dev_rescan
[ 300.552501] Call Trace:
[ 300.552635] <TASK>
[ 300.552754] __schedule+0xe13/0x33a0
[ 300.552955] ? __pfx___schedule+0x10/0x10
[ 300.553165] ? lock_release+0x441/0x870
[ 300.553370] ? __pfx_lock_release+0x10/0x10
[ 300.553594] ? _raw_spin_unlock_irq+0x3c/0x60
[ 300.553825] schedule+0xf6/0x3f0
[ 300.554002] io_schedule+0xce/0x150
[ 300.554190] blk_mq_get_tag+0x5e7/0xce0
[ 300.554398] ? __pfx_blk_mq_get_tag+0x10/0x10
[ 300.554629] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.554934] __blk_mq_alloc_requests+0x6f6/0x1720
[ 300.555181] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.555466] ? __pfx___blk_mq_alloc_requests+0x10/0x10
[ 300.555740] blk_mq_alloc_request+0x655/0x930
[ 300.555973] ? __pfx_blk_mq_alloc_request+0x10/0x10
[ 300.556225] ? __lock_acquire+0xd87/0x5c90
[ 300.556450] scsi_execute_cmd+0x223/0x1040
[ 300.556684] ? __this_cpu_preempt_check+0x21/0x30
[ 300.556933] ? __pfx_scsi_execute_cmd+0x10/0x10
[ 300.557178] ? __pfx_lock_acquire.part.0+0x10/0x10
[ 300.557431] scsi_vpd_inquiry+0xdf/0x220
[ 300.557641] ? __pfx_scsi_vpd_inquiry+0x10/0x10
[ 300.557877] ? debug_smp_processor_id+0x20/0x30
[ 300.558113] ? rcu_is_watching+0x19/0xc0
[ 300.558325] scsi_get_vpd_size+0x11e/0x310
[ 300.558539] ? __mutex_lock+0x230/0x1490
[ 300.558763] ? __pfx_scsi_get_vpd_size+0x10/0x10
[ 300.559004] ? scsi_rescan_device+0x33/0x360
[ 300.559227] ? __pfx_mark_lock.part.0+0x10/0x10
[ 300.559465] ? __this_cpu_preempt_check+0x21/0x30
[ 300.559713] ? lock_acquire.part.0+0x152/0x390
[ 300.559947] ? __pfx___mutex_lock+0x10/0x10
[ 300.560172] scsi_get_vpd_buf+0x30/0x180
[ 300.560382] scsi_attach_vpd+0xf8/0x5b0
[ 300.560591] scsi_rescan_device+0x106/0x360
[ 300.560820] ata_scsi_dev_rescan+0x1d2/0x470
[ 300.561051] process_one_work+0x92e/0x1b50
[ 300.561264] ? lock_acquire.part.0+0x152/0x390
[ 300.561505] ? __pfx_process_one_work+0x10/0x10
[ 300.561741] ? move_linked_works+0x1bf/0x2c0
[ 300.561972] ? __this_cpu_preempt_check+0x21/0x30
[ 300.562220] ? assign_work+0x19f/0x250
[ 300.562421] ? lock_is_held_type+0xef/0x150
[ 300.562645] worker_thread+0x68d/0xe90
[ 300.562856] ? lockdep_hardirqs_on+0x89/0x110
[ 300.563105] kthread+0x35a/0x470
[ 300.563278] ? __pfx_worker_thread+0x10/0x10
[ 300.563501] ? __pfx_kthread+0x10/0x10
[ 300.563700] ret_from_fork+0x56/0x90
[ 300.563892] ? __pfx_kthread+0x10/0x10
[ 300.564093] ret_from_fork_asm+0x1a/0x30
[ 300.564313] </TASK>
[ 300.564432] INFO: task auditd:240 blocked for more than 147 seconds.
[ 300.564749] Not tainted 6.12.0-rc4-kvm #1
[ 300.564984] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.565375] task:auditd state:D stack:0 pid:240 tgid:240 ppid:1 flags:0x00000002
[ 300.565832] Call Trace:
[ 300.565963] <TASK>
[ 300.566084] __schedule+0xe13/0x33a0
[ 300.566284] ? __pfx___schedule+0x10/0x10
[ 300.566495] ? lock_release+0x441/0x870
[ 300.566700] ? __pfx_lock_release+0x10/0x10
[ 300.566932] ? trace_lock_acquire+0x139/0x1b0
[ 300.567165] ? lock_acquire+0x80/0xb0
[ 300.567362] ? schedule+0x216/0x3f0
[ 300.567553] schedule+0xf6/0x3f0
[ 300.567730] io_schedule+0xce/0x150
[ 300.567921] bit_wait_io+0x1f/0x100
[ 300.568110] __wait_on_bit+0x68/0x1b0
[ 300.568307] ? __pfx_bit_wait_io+0x10/0x10
[ 300.568528] out_of_line_wait_on_bit+0xe6/0x120
[ 300.568775] ? __pfx_out_of_line_wait_on_bit+0x10/0x10
[ 300.569042] ? __pfx_wake_bit_function+0x10/0x10
[ 300.569286] ? __might_sleep+0xa3/0x170
[ 300.569495] do_get_write_access+0x83b/0x1010
[ 300.569733] jbd2_journal_get_write_access+0x1e4/0x270
[ 300.570003] __ext4_journal_get_write_access+0x72/0x3b0
[ 300.570276] ext4_reserve_inode_write+0x199/0x280
[ 300.570522] ? ext4_dirty_inode+0xeb/0x140
[ 300.570754] __ext4_mark_inode_dirty+0x18b/0x8c0
[ 300.570999] ? debug_smp_processor_id+0x20/0x30
[ 300.571238] ? __pfx___ext4_mark_inode_dirty+0x10/0x10
[ 300.571502] ? trace_jbd2_handle_start+0x77/0x210
[ 300.571750] ? jbd2__journal_start+0xff/0x6b0
[ 300.571986] ? __ext4_journal_start_sb+0x1f8/0x600
[ 300.572237] ? ext4_dirty_inode+0xb3/0x140
[ 300.572460] ? __pfx_ext4_dirty_inode+0x10/0x10
[ 300.572702] ext4_dirty_inode+0xeb/0x140
[ 300.572911] ? rcu_is_watching+0x19/0xc0
[ 300.573121] __mark_inode_dirty+0x1d0/0xd50
[ 300.573343] ? __pfx_generic_write_checks+0x10/0x10
[ 300.573608] generic_update_time+0xe0/0x110
[ 300.573832] file_modified+0x1af/0x1e0
[ 300.574039] ext4_buffered_write_iter+0x101/0x3e0
[ 300.574292] ext4_file_write_iter+0x8b8/0x1ab0
[ 300.574524] ? __pfx_lock_acquire.part.0+0x10/0x10
[ 300.574791] ? debug_smp_processor_id+0x20/0x30
[ 300.575035] ? __pfx_ext4_file_write_iter+0x10/0x10
[ 300.575288] ? __this_cpu_preempt_check+0x21/0x30
[ 300.575531] ? lock_is_held_type+0xef/0x150
[ 300.575758] vfs_write+0xc46/0x1120
[ 300.575950] ? __pfx_ext4_file_write_iter+0x10/0x10
[ 300.576211] ? __pfx_vfs_write+0x10/0x10
[ 300.576429] ? mutex_lock_nested+0x1f/0x30
[ 300.576647] ksys_write+0x14f/0x290
[ 300.576839] ? __pfx_ksys_write+0x10/0x10
[ 300.577058] __x64_sys_write+0x7b/0xc0
[ 300.577256] ? syscall_trace_enter+0x9b/0x230
[ 300.577490] x64_sys_call+0x1685/0x20d0
[ 300.577692] do_syscall_64+0x6d/0x140
[ 300.577889] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 300.578156] RIP: 0033:0x7fe1ebf3ebcf
[ 300.578348] RSP: 002b:00007ffebc24a5e0 EFLAGS: 00000293 ORIG_RAX: 0000000000000001
[ 300.578741] RAX: ffffffffffffffda RBX: 00000000000000e0 RCX: 00007fe1ebf3ebcf
[ 300.579094] RDX: 00000000000000e0 RSI: 0000559099024040 RDI: 0000000000000005
[ 300.579448] RBP: 0000559099024040 R08: 0000000000000000 R09: 00007fe1ebfb14e0
[ 300.579802] R10: 00007fe1ebfb13e0 R11: 0000000000000293 R12: 00000000000000e0
[ 300.580154] R13: 000055909901a2a0 R14: 00000000000000e0 R15: 00007fe1ebff69e0
[ 300.580518] </TASK>
[ 300.580641] INFO: task in:imjournal:319 blocked for more than 147 seconds.
[ 300.580981] Not tainted 6.12.0-rc4-kvm #1
[ 300.581211] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.581591] task:in:imjournal state:D stack:0 pid:319 tgid:300 ppid:1 flags:0x00000002
[ 300.582047] Call Trace:
[ 300.582177] <TASK>
[ 300.582296] __schedule+0xe13/0x33a0
[ 300.582492] ? __pfx___schedule+0x10/0x10
[ 300.582700] ? lock_release+0x441/0x870
[ 300.582918] ? __pfx_lock_release+0x10/0x10
[ 300.583135] ? trace_lock_acquire+0x139/0x1b0
[ 300.583366] ? lock_acquire+0x80/0xb0
[ 300.583558] ? schedule+0x216/0x3f0
[ 300.583747] schedule+0xf6/0x3f0
[ 300.583923] io_schedule+0xce/0x150
[ 300.584109] bit_wait_io+0x1f/0x100
[ 300.584297] __wait_on_bit+0x68/0x1b0
[ 300.584491] ? __pfx_bit_wait_io+0x10/0x10
[ 300.584710] out_of_line_wait_on_bit+0xe6/0x120
[ 300.584950] ? __pfx_out_of_line_wait_on_bit+0x10/0x10
[ 300.585216] ? __pfx_wake_bit_function+0x10/0x10
[ 300.585457] ? __might_sleep+0xa3/0x170
[ 300.585662] do_get_write_access+0x83b/0x1010
[ 300.585899] jbd2_journal_get_write_access+0x1e4/0x270
[ 300.586166] __ext4_journal_get_write_access+0x72/0x3b0
[ 300.586436] __ext4_new_inode+0xd66/0x5320
[ 300.586661] ? __pfx___ext4_new_inode+0x10/0x10
[ 300.586910] ? __pfx___dquot_initialize+0x10/0x10
[ 300.587163] ? _raw_spin_unlock+0x31/0x60
[ 300.587372] ? d_splice_alias+0x4e8/0xe30
[ 300.587585] ext4_create+0x32e/0x550
[ 300.587783] ? __pfx_ext4_create+0x10/0x10
[ 300.588000] ? inode_permission+0xf4/0x650
[ 300.588215] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.588489] ? __pfx_ext4_create+0x10/0x10
[ 300.588704] lookup_open.isra.0+0x117c/0x1580
[ 300.588942] ? __pfx_lookup_open.isra.0+0x10/0x10
[ 300.589192] ? lock_acquire+0x80/0xb0
[ 300.589385] ? path_openat+0xd40/0x2bf0
[ 300.589597] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.589876] path_openat+0xdbf/0x2bf0
[ 300.590080] ? __pfx_path_openat+0x10/0x10
[ 300.590294] ? __this_cpu_preempt_check+0x21/0x30
[ 300.590540] ? lock_is_held_type+0xef/0x150
[ 300.590777] ? __this_cpu_preempt_check+0x21/0x30
[ 300.591026] do_filp_open+0x1cc/0x420
[ 300.591221] ? __pfx_do_filp_open+0x10/0x10
[ 300.591440] ? lock_release+0x441/0x870
[ 300.591652] ? do_raw_spin_unlock+0x15c/0x210
[ 300.591895] do_sys_openat2+0x185/0x1f0
[ 300.592097] ? __pfx_do_sys_openat2+0x10/0x10
[ 300.592327] ? __this_cpu_preempt_check+0x21/0x30
[ 300.592570] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.592891] ? lockdep_hardirqs_on+0x89/0x110
[ 300.593122] __x64_sys_openat+0x17a/0x240
[ 300.593332] ? __pfx___x64_sys_openat+0x10/0x10
[ 300.593569] ? __audit_syscall_entry+0x39c/0x500
[ 300.593816] x64_sys_call+0x1a52/0x20d0
[ 300.594017] do_syscall_64+0x6d/0x140
[ 300.594212] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 300.594470] RIP: 0033:0x7f4af113e8c4
[ 300.594657] RSP: 002b:00007f4af01fea40 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
[ 300.595043] RAX: ffffffffffffffda RBX: 00007f4ae8000c50 RCX: 00007f4af113e8c4
[ 300.595396] RDX: 0000000000000241 RSI: 00007f4af01feb80 RDI: 00000000ffffff9c
[ 300.595748] RBP: 00007f4af01feb80 R08: 0000000000000000 R09: 0000000000000001
[ 300.596099] R10: 00000000000001b6 R11: 0000000000000293 R12: 0000000000000241
[ 300.596451] R13: 00007f4ae8000c50 R14: 0000000000000001 R15: 00007f4ae8010540
[ 300.596818] </TASK>
[ 300.596937] INFO: task rs:main Q:Reg:322 blocked for more than 147 seconds.
[ 300.597279] Not tainted 6.12.0-rc4-kvm #1
[ 300.597508] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.597889] task:rs:main Q:Reg state:D stack:0 pid:322 tgid:300 ppid:1 flags:0x00000002
[ 300.598345] Call Trace:
[ 300.598479] <TASK>
[ 300.598597] __schedule+0xe13/0x33a0
[ 300.598804] ? __pfx___schedule+0x10/0x10
[ 300.599013] ? lock_release+0x441/0x870
[ 300.599217] ? __pfx_lock_release+0x10/0x10
[ 300.599433] ? trace_lock_acquire+0x139/0x1b0
[ 300.599664] ? lock_acquire+0x80/0xb0
[ 300.599857] ? schedule+0x216/0x3f0
[ 300.600046] schedule+0xf6/0x3f0
[ 300.600221] io_schedule+0xce/0x150
[ 300.600408] bit_wait_io+0x1f/0x100
[ 300.600595] __wait_on_bit+0x68/0x1b0
[ 300.600791] ? __pfx_bit_wait_io+0x10/0x10
[ 300.601010] out_of_line_wait_on_bit+0xe6/0x120
[ 300.601246] ? __pfx_out_of_line_wait_on_bit+0x10/0x10
[ 300.601512] ? __pfx_wake_bit_function+0x10/0x10
[ 300.601753] ? __might_sleep+0xa3/0x170
[ 300.601959] do_get_write_access+0x83b/0x1010
[ 300.602196] jbd2_journal_get_write_access+0x1e4/0x270
[ 300.602462] __ext4_journal_get_write_access+0x72/0x3b0
[ 300.602744] ext4_reserve_inode_write+0x199/0x280
[ 300.602990] ? ext4_dirty_inode+0xeb/0x140
[ 300.603204] __ext4_mark_inode_dirty+0x18b/0x8c0
[ 300.603446] ? debug_smp_processor_id+0x20/0x30
[ 300.603683] ? __pfx___ext4_mark_inode_dirty+0x10/0x10
[ 300.603945] ? trace_jbd2_handle_start+0x77/0x210
[ 300.604192] ? jbd2__journal_start+0xff/0x6b0
[ 300.604425] ? __ext4_journal_start_sb+0x1f8/0x600
[ 300.604672] ? ext4_dirty_inode+0xb3/0x140
[ 300.604892] ? __pfx_ext4_dirty_inode+0x10/0x10
[ 300.605127] ext4_dirty_inode+0xeb/0x140
[ 300.605332] ? rcu_is_watching+0x19/0xc0
[ 300.605539] __mark_inode_dirty+0x1d0/0xd50
[ 300.605756] ? __pfx_generic_write_checks+0x10/0x10
[ 300.606011] generic_update_time+0xe0/0x110
[ 300.606232] file_modified+0x1af/0x1e0
[ 300.606432] ext4_buffered_write_iter+0x101/0x3e0
[ 300.606678] ext4_file_write_iter+0x8b8/0x1ab0
[ 300.606924] ? __pfx_lock_acquire.part.0+0x10/0x10
[ 300.607175] ? debug_smp_processor_id+0x20/0x30
[ 300.607414] ? __pfx_ext4_file_write_iter+0x10/0x10
[ 300.607667] ? __this_cpu_preempt_check+0x21/0x30
[ 300.607912] ? lock_is_held_type+0xef/0x150
[ 300.608135] vfs_write+0xc46/0x1120
[ 300.608324] ? __pfx_ext4_file_write_iter+0x10/0x10
[ 300.608577] ? __pfx_vfs_write+0x10/0x10
[ 300.608797] ? mutex_lock_nested+0x1f/0x30
[ 300.609016] ksys_write+0x14f/0x290
[ 300.609206] ? __pfx_ksys_write+0x10/0x10
[ 300.609420] ? __audit_syscall_entry+0x39c/0x500
[ 300.609663] __x64_sys_write+0x7b/0xc0
[ 300.609860] ? syscall_trace_enter+0x14a/0x230
[ 300.610093] x64_sys_call+0x1685/0x20d0
[ 300.610294] do_syscall_64+0x6d/0x140
[ 300.610490] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 300.610763] RIP: 0033:0x7f4af113ebcf
[ 300.610950] RSP: 002b:00007f4aefbff890 EFLAGS: 00000293 ORIG_RAX: 0000000000000001
[ 300.611326] RAX: ffffffffffffffda RBX: 00007f4ae0000e70 RCX: 00007f4af113ebcf
[ 300.611678] RDX: 0000000000000040 RSI: 00007f4ae0001150 RDI: 0000000000000005
[ 300.612031] RBP: 00007f4ae0001150 R08: 0000000000000000 R09: 0000000000000000
[ 300.612384] R10: 0000000000000007 R11: 0000000000000293 R12: 0000000000000000
[ 300.612738] R13: 000055979b901330 R14: 00007f4ae0000e70 R15: 0000000000000040
[ 300.613110] </TASK>
[ 300.613251] INFO: task repro:684 blocked for more than 147 seconds.
[ 300.613537] Not tainted 6.12.0-rc4-kvm #1
[ 300.613749] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 300.614135] task:repro state:D stack:0 pid:684 tgid:684 ppid:679 flags:0x00000006
[ 300.614606] Call Trace:
[ 300.614754] <TASK>
[ 300.614874] __schedule+0xe13/0x33a0
[ 300.615073] ? __pfx___schedule+0x10/0x10
[ 300.615283] ? lock_release+0x441/0x870
[ 300.615489] ? __pfx_lock_release+0x10/0x10
[ 300.615708] ? trace_lock_acquire+0x139/0x1b0
[ 300.615942] ? lock_acquire+0x80/0xb0
[ 300.616136] ? schedule+0x216/0x3f0
[ 300.616327] schedule+0xf6/0x3f0
[ 300.616507] io_schedule+0xce/0x150
[ 300.616695] blk_mq_get_tag+0x5e7/0xce0
[ 300.616909] ? __pfx_blk_mq_get_tag+0x10/0x10
[ 300.617146] ? __pfx_autoremove_wake_function+0x10/0x10
[ 300.617429] __blk_mq_alloc_requests+0x6f6/0x1720
[ 300.617678] ? __sanitizer_cov_trace_const_cmp1+0x1e/0x30
[ 300.617970] ? __pfx___blk_mq_alloc_requests+0x10/0x10
[ 300.618236] ? __this_cpu_preempt_check+0x21/0x30
[ 300.618480] ? lock_acquire.part.0+0x152/0x390
[ 300.618733] blk_mq_alloc_request+0x655/0x930
[ 300.618967] ? __pfx_blk_mq_alloc_request+0x10/0x10
[ 300.619234] scsi_execute_cmd+0x223/0x1040
[ 300.619455] ? debug_smp_processor_id+0x20/0x30
[ 300.619695] ? __pfx_scsi_execute_cmd+0x10/0x10
[ 300.619931] ? rcu_is_watching+0x19/0xc0
[ 300.620139] ? __kmalloc_noprof+0x34f/0x4a0
[ 300.620358] ? ata_cmd_ioctl+0x375/0x570
[ 300.620570] ata_cmd_ioctl+0x23c/0x570
[ 300.620775] ? __pfx_ata_cmd_ioctl+0x10/0x10
[ 300.621000] ? lock_release+0x441/0x870
[ 300.621209] ? __this_cpu_preempt_check+0x21/0x30
[ 300.621463] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.621740] ? security_capable+0x19d/0x1e0
[ 300.621976] ata_sas_scsi_ioctl+0x60a/0x7c0
[ 300.622195] ? mark_lock.part.0+0xf3/0x17b0
[ 300.622415] ? __pfx_ata_sas_scsi_ioctl+0x10/0x10
[ 300.622658] ? __pfx_mark_lock.part.0+0x10/0x10
[ 300.622915] ? __this_cpu_preempt_check+0x21/0x30
[ 300.623161] ? lock_is_held_type+0xef/0x150
[ 300.623382] ? __pfx_ata_scsi_ioctl+0x10/0x10
[ 300.623610] ata_scsi_ioctl+0x70/0x90
[ 300.623807] scsi_ioctl+0xb6f/0x1630
[ 300.624001] ? __might_sleep+0xa3/0x170
[ 300.624208] ? __pfx_scsi_ioctl+0x10/0x10
[ 300.624419] ? scsi_block_when_processing_errors+0x2c4/0x390
[ 300.624711] ? __pfx_scsi_block_when_processing_errors+0x10/0x10
[ 300.625022] ? __pfx___lock_acquire+0x10/0x10
[ 300.625250] ? __sanitizer_cov_trace_switch+0x58/0xa0
[ 300.625512] ? __sanitizer_cov_trace_const_cmp2+0x1c/0x30
[ 300.625787] ? do_vfs_ioctl+0x4fa/0x1920
[ 300.625997] ? __pfx_do_vfs_ioctl+0x10/0x10
[ 300.626217] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
[ 300.626497] sg_ioctl+0xfb8/0x2880
[ 300.626686] ? __this_cpu_preempt_check+0x21/0x30
[ 300.626947] ? lock_release+0x441/0x870
[ 300.627155] ? __pfx_sg_ioctl+0x10/0x10
[ 300.627366] ? __this_cpu_preempt_check+0x21/0x30
[ 300.627615] ? seqcount_lockdep_reader_access.constprop.0+0xb4/0xd0
[ 300.627932] ? lockdep_hardirqs_on+0x89/0x110
[ 300.628160] ? trace_hardirqs_on+0x51/0x60
[ 300.628381] ? seqcount_lockdep_reader_access.constprop.0+0xc0/0xd0
[ 300.628697] ? __sanitizer_cov_trace_cmp4+0x1a/0x20
[ 300.628949] ? ktime_get_coarse_real_ts64+0xbf/0xf0
[ 300.629210] ? __pfx_sg_ioctl+0x10/0x10
[ 300.629421] __x64_sys_ioctl+0x1b5/0x230
[ 300.629639] x64_sys_call+0x1209/0x20d0
[ 300.629844] do_syscall_64+0x6d/0x140
[ 300.630044] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 300.630310] RIP: 0033:0x7fc80ee3ee5d
[ 300.630502] RSP: 002b:00007fffa979c518 EFLAGS: 00000206 ORIG_RAX: 0000000000000010
[ 300.630915] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fc80ee3ee5d
[ 300.631281] RDX: 0000000020000080 RSI: 000000000000031f RDI: 0000000000000003
[ 300.631640] RBP: 00007fffa979c530 R08: 00007fffa979c2a8 R09: 00007fffa979c530
[ 300.631997] R10: 0000000000000000 R11: 0000000000000206 R12: 00007fffa979c688
[ 300.632354] R13: 0000000000401972 R14: 0000000000403e08 R15: 00007fc80f193000
[ 300.632722] </TASK>
[ 300.632849] Future hung task reports are suppressed, see sysctl kernel.hung_task_warnings
[ 300.633253]
[ 300.633253] Showing all locks held in the system:
[ 300.633567] 7 locks held by kworker/u8:0/11:
[ 300.633790] #0: ffff88800e4a8948 ((wq_completion)writeback){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
[ 300.634296] #1: ffff88800dcd7d78 ((work_completion)(&(&wb->dwork)->work)){+.+.}-{0:0}, at: process_one_work+0x8a0/0x1b0
[ 300.634871] #2: ffff888011f480e0 (&type->s_umount_key#38){++++}-{3:3}, at: super_trylock_shared+0x2b/0x110
[ 300.635370] #3: ffff888011f4ab98 (&sbi->s_writepages_rwsem){++++}-{0:0}, at: do_writepages+0x1c3/0x8a0
[ 300.635848] #4: ffff888011f4c958 (jbd2_handle){++++}-{0:0}, at: start_this_handle+0x107b/0x1590
[ 300.636299] #5: ffff888023bb33c0 (&ei->i_data_sem){++++}-{3:3}, at: ext4_map_blocks+0x344/0x1390
[ 300.636754] #6: ffffe8ffffc077f8 (&lg->lg_mutex){+.+.}-{3:3}, at: ext4_mb_initialize_context+0x8a3/0xd20
[ 300.637257] 4 locks held by kworker/u8:1/31:
[ 300.637479] #0: ffff88800e4a8948 ((wq_completion)writeback){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
[ 300.637979] #1: ffff88800df47d78 ((work_completion)(&(&wb->dwork)->work)){+.+.}-{0:0}, at: process_one_work+0x8a0/0x1b0
[ 300.638532] #2: ffff888011f480e0 (&type->s_umount_key#38){++++}-{3:3}, at: super_trylock_shared+0x2b/0x110
[ 300.639046] #3: ffff888011f4ab98 (&sbi->s_writepages_rwsem){++++}-{0:0}, at: do_writepages+0x1c3/0x8a0
[ 300.639525] 1 lock held by khungtaskd/33:
[ 300.639732] #0: ffffffff8705ca00 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x73/0x3c0
[ 300.640191] 4 locks held by kworker/u8:2/35:
[ 300.640411] #0: ffff88800e4a8948 ((wq_completion)writeback){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
[ 300.640917] #1: ffff88800e4bfd78 ((work_completion)(&(&wb->dwork)->work)){+.+.}-{0:0}, at: process_one_work+0x8a0/0x1b0
[ 300.641479] #2: ffff888011f480e0 (&type->s_umount_key#38){++++}-{3:3}, at: super_trylock_shared+0x2b/0x110
[ 300.641990] #3: ffff888011f4ab98 (&sbi->s_writepages_rwsem){++++}-{0:0}, at: do_writepages+0x1c3/0x8a0
[ 300.642483] 3 locks held by kworker/u8:4/167:
[ 300.642709] #0: ffff88800e4a8948 ((wq_completion)writeback){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
[ 300.643228] #1: ffff888013e07d78 ((work_completion)(&(&wb->dwork)->work)){+.+.}-{0:0}, at: process_one_work+0x8a0/0x1b0
[ 300.643782] #2: ffff88800d77e0e0 (&type->s_umount_key#52){.+.+}-{3:3}, at: super_trylock_shared+0x2b/0x110
[ 300.644282] 4 locks held by kworker/1:3/233:
[ 300.644503] #0: ffff88800d45ad48 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x11fc/0x1b50
[ 300.644995] #1: ffff888014ea7d78 ((work_completion)(&(&ap->scsi_rescan_task)->work)){+.+.}-{0:0}, at: process_one_work0
[ 300.645610] #2: ffff88801042c430 (&ap->scsi_scan_mutex){+.+.}-{3:3}, at: ata_scsi_dev_rescan+0x42/0x470
[ 300.646096] #3: ffff8880103e8378 (&dev->mutex){....}-{3:3}, at: scsi_rescan_device+0x33/0x360
[ 300.646542] 4 locks held by auditd/240:
[ 300.646757] #0: ffff8880111580f8 (&f->f_pos_lock){+.+.}-{3:3}, at: fdget_pos+0x25e/0x380
[ 300.647182] #1: ffff888011f48408 (sb_writers#3){.+.+}-{0:0}, at: ksys_write+0x14f/0x290
[ 300.647605] #2: ffff888017c8d2b8 (&sb->s_type->i_mutex_key#8){++++}-{3:3}, at: ext4_buffered_write_iter+0xb8/0x3e0
[ 300.648137] #3: ffff888011f4c958 (jbd2_handle){++++}-{0:0}, at: start_this_handle+0x107b/0x1590
[ 300.648591] 3 locks held by in:imjournal/319:
[ 300.648820] #0: ffff888011f48408 (sb_writers#3){.+.+}-{0:0}, at: path_openat+0x1f7c/0x2bf0
[ 300.649260] #1: ffff88801ae1f040 (&type->i_mutex_dir_key#3){++++}-{3:3}, at: path_openat+0xd40/0x2bf0
[ 300.649745] #2: ffff888011f4c958 (jbd2_handle){++++}-{0:0}, at: start_this_handle+0x107b/0x1590
[ 300.650205] 4 locks held by rs:main Q:Reg/322:
[ 300.650437] #0: ffff888013b782b8 (&f->f_pos_lock){+.+.}-{3:3}, at: fdget_pos+0x25e/0x380
[ 300.650880] #1: ffff888011f48408 (sb_writers#3){.+.+}-{0:0}, at: ksys_write+0x14f/0x290
[ 300.651306] #2: ffff8880195183f8 (&sb->s_type->i_mutex_key#8){++++}-{3:3}, at: ext4_buffered_write_iter+0xb8/0x3e0
[ 300.651844] #3: ffff888011f4c958 (jbd2_handle){++++}-{0:0}, at: start_this_handle+0x107b/0x1590
[ 300.652307]
[ 300.652397] =============================================
> Kind regards,
> Niklas
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
2024-10-22 5:44 ` Lai, Yi
@ 2024-10-22 8:48 ` Niklas Cassel
2024-10-22 9:55 ` Lai, Yi
0 siblings, 1 reply; 10+ messages in thread
From: Niklas Cassel @ 2024-10-22 8:48 UTC (permalink / raw)
To: Lai, Yi
Cc: Damien Le Moal, Hannes Reinecke, Martin K. Petersen, Igor Pylypiv,
Niklas Cassel, linux-ide, yi1.lai, syzkaller-bugs, linux-kernel
On Tue, Oct 22, 2024 at 01:44:08PM +0800, Lai, Yi wrote:
> On Mon, Oct 21, 2024 at 05:20:12PM +0200, Niklas Cassel wrote:
> > On Mon, Oct 21, 2024 at 02:07:21PM +0200, Niklas Cassel wrote:
> > > Hello Yi Lai,
> > >
> > > On Mon, Oct 21, 2024 at 06:58:59PM +0800, Lai, Yi wrote:
> > > > Hi Niklas Cassel,
> > > >
> > > > Greetings!
> > > >
> > > > I used Syzkaller and found that there is INFO: task hung in blk_mq_get_tag in v6.12-rc3
> > > >
> > > > After bisection and the first bad commit is:
> > > > "
> > > > e5dd410acb34 ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
> > > > "
> > >
> > > It might be that your bisection results are accurate.
> > >
> > > However, after looking at the stacktraces, I find it way more likely that
> > > bisection has landed on the wrong commit.
> > >
> > > See this series that was just queued (for 6.13) a few days ago that solves a
> > > similar starvation:
> > > https://lore.kernel.org/linux-block/20241014092934.53630-1-songmuchun@bytedance.com/
> > > https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git/log/?h=for-6.13/block
> > >
> > > You could perhaps run with v6.14-rc4 (which should be able to trigger the bug)
> > > and then try v6.14-rc4 + that series applied, to see if you can still trigger
> > > the bug?
> >
> > Another patch that might be relevant:
> > https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=e972b08b91ef48488bae9789f03cfedb148667fb
> >
> > Which fixes a use after delete in rq_qos_wake_function().
> > (We can see that the stack trace has rq_qos_wake_function() before
> > getting stuck forever in rq_qos_wait())
> >
> > Who knows what could go wrong when accessing a deleted entry, in the
> > report there was a crash, but I could image other surprises :)
> > The fix was first included in v6.12-rc4.
> >
> >
> Hi Niklas,
>
> Thanks for the info. I have tried using v6.12-rc4 kernel to reproduce
> the issue. Using the same repro binary, the issue still exists.
Thanks a lot for your help with testing!
The first series that I pointed to, which looks most likely to be related:
https://lore.kernel.org/linux-block/20241014092934.53630-1-songmuchun@bytedance.com/
Is only merged in:
https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git/log/?h=for-6.13/block
It is not included in v6.12-rc4.
Would it please be possible for you to test with Jens's for-6.13/block branch?
Kind regards,
Niklas
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
2024-10-22 8:48 ` Niklas Cassel
@ 2024-10-22 9:55 ` Lai, Yi
2024-10-22 11:04 ` Niklas Cassel
0 siblings, 1 reply; 10+ messages in thread
From: Lai, Yi @ 2024-10-22 9:55 UTC (permalink / raw)
To: Niklas Cassel
Cc: Damien Le Moal, Hannes Reinecke, Martin K. Petersen, Igor Pylypiv,
Niklas Cassel, linux-ide, yi1.lai, syzkaller-bugs, linux-kernel
On Tue, Oct 22, 2024 at 10:48:04AM +0200, Niklas Cassel wrote:
> On Tue, Oct 22, 2024 at 01:44:08PM +0800, Lai, Yi wrote:
> > On Mon, Oct 21, 2024 at 05:20:12PM +0200, Niklas Cassel wrote:
> > > On Mon, Oct 21, 2024 at 02:07:21PM +0200, Niklas Cassel wrote:
> > > > Hello Yi Lai,
> > > >
> > > > On Mon, Oct 21, 2024 at 06:58:59PM +0800, Lai, Yi wrote:
> > > > > Hi Niklas Cassel,
> > > > >
> > > > > Greetings!
> > > > >
> > > > > I used Syzkaller and found that there is INFO: task hung in blk_mq_get_tag in v6.12-rc3
> > > > >
> > > > > After bisection and the first bad commit is:
> > > > > "
> > > > > e5dd410acb34 ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
> > > > > "
> > > >
> > > > It might be that your bisection results are accurate.
> > > >
> > > > However, after looking at the stacktraces, I find it way more likely that
> > > > bisection has landed on the wrong commit.
> > > >
> > > > See this series that was just queued (for 6.13) a few days ago that solves a
> > > > similar starvation:
> > > > https://lore.kernel.org/linux-block/20241014092934.53630-1-songmuchun@bytedance.com/
> > > > https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git/log/?h=for-6.13/block
> > > >
> > > > You could perhaps run with v6.14-rc4 (which should be able to trigger the bug)
> > > > and then try v6.14-rc4 + that series applied, to see if you can still trigger
> > > > the bug?
> > >
I tried kernel linux-block
https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git
branch for-6.13/block commit c97f91b1807a7966077b69b24f28c2dbcde664e9.
Issue can still be reproduced.
> > > Another patch that might be relevant:
> > > https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=e972b08b91ef48488bae9789f03cfedb148667fb
> > >
> > > Which fixes a use after delete in rq_qos_wake_function().
> > > (We can see that the stack trace has rq_qos_wake_function() before
> > > getting stuck forever in rq_qos_wait())
> > >
> > > Who knows what could go wrong when accessing a deleted entry, in the
> > > report there was a crash, but I could image other surprises :)
> > > The fix was first included in v6.12-rc4.
> > >
> > >
> > Hi Niklas,
> >
> > Thanks for the info. I have tried using v6.12-rc4 kernel to reproduce
> > the issue. Using the same repro binary, the issue still exists.
>
> Thanks a lot for your help with testing!
>
> The first series that I pointed to, which looks most likely to be related:
> https://lore.kernel.org/linux-block/20241014092934.53630-1-songmuchun@bytedance.com/
>
> Is only merged in:
> https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git/log/?h=for-6.13/block
>
> It is not included in v6.12-rc4.
>
> Would it please be possible for you to test with Jens's for-6.13/block branch?
>
>
> Kind regards,
> Niklas
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
2024-10-22 9:55 ` Lai, Yi
@ 2024-10-22 11:04 ` Niklas Cassel
2024-10-22 15:59 ` Niklas Cassel
0 siblings, 1 reply; 10+ messages in thread
From: Niklas Cassel @ 2024-10-22 11:04 UTC (permalink / raw)
To: Lai, Yi
Cc: Damien Le Moal, Hannes Reinecke, Martin K. Petersen, Igor Pylypiv,
Niklas Cassel, linux-ide, yi1.lai, syzkaller-bugs, linux-kernel
On Tue, Oct 22, 2024 at 05:55:17PM +0800, Lai, Yi wrote:
> On Tue, Oct 22, 2024 at 10:48:04AM +0200, Niklas Cassel wrote:
> > On Tue, Oct 22, 2024 at 01:44:08PM +0800, Lai, Yi wrote:
> > > On Mon, Oct 21, 2024 at 05:20:12PM +0200, Niklas Cassel wrote:
> > > > On Mon, Oct 21, 2024 at 02:07:21PM +0200, Niklas Cassel wrote:
> > > > > Hello Yi Lai,
> > > > >
> > > > > On Mon, Oct 21, 2024 at 06:58:59PM +0800, Lai, Yi wrote:
> > > > > > Hi Niklas Cassel,
> > > > > >
> > > > > > Greetings!
> > > > > >
> > > > > > I used Syzkaller and found that there is INFO: task hung in blk_mq_get_tag in v6.12-rc3
> > > > > >
> > > > > > After bisection and the first bad commit is:
> > > > > > "
> > > > > > e5dd410acb34 ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
> > > > > > "
> > > > >
> > > > > It might be that your bisection results are accurate.
> > > > >
> > > > > However, after looking at the stacktraces, I find it way more likely that
> > > > > bisection has landed on the wrong commit.
> > > > >
> > > > > See this series that was just queued (for 6.13) a few days ago that solves a
> > > > > similar starvation:
> > > > > https://lore.kernel.org/linux-block/20241014092934.53630-1-songmuchun@bytedance.com/
> > > > > https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git/log/?h=for-6.13/block
> > > > >
> > > > > You could perhaps run with v6.14-rc4 (which should be able to trigger the bug)
> > > > > and then try v6.14-rc4 + that series applied, to see if you can still trigger
> > > > > the bug?
> > > >
>
> I tried kernel linux-block
> https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git
> branch for-6.13/block commit c97f91b1807a7966077b69b24f28c2dbcde664e9.
>
> Issue can still be reproduced.
Thanks again for your testing!
I will try to reproduce using your reproducer (repo.c),
and see if I can make any sense of this.
Kind regards,
Niklas
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
2024-10-22 11:04 ` Niklas Cassel
@ 2024-10-22 15:59 ` Niklas Cassel
2024-10-23 2:55 ` Lai, Yi
0 siblings, 1 reply; 10+ messages in thread
From: Niklas Cassel @ 2024-10-22 15:59 UTC (permalink / raw)
To: Lai, Yi
Cc: Damien Le Moal, Hannes Reinecke, Martin K. Petersen, Igor Pylypiv,
Niklas Cassel, linux-ide, yi1.lai, syzkaller-bugs, linux-kernel
On Tue, Oct 22, 2024 at 01:04:10PM +0200, Niklas Cassel wrote:
> On Tue, Oct 22, 2024 at 05:55:17PM +0800, Lai, Yi wrote:
> > On Tue, Oct 22, 2024 at 10:48:04AM +0200, Niklas Cassel wrote:
> > > On Tue, Oct 22, 2024 at 01:44:08PM +0800, Lai, Yi wrote:
> > > > On Mon, Oct 21, 2024 at 05:20:12PM +0200, Niklas Cassel wrote:
> > > > > On Mon, Oct 21, 2024 at 02:07:21PM +0200, Niklas Cassel wrote:
> > > > > > Hello Yi Lai,
> > > > > >
> > > > > > On Mon, Oct 21, 2024 at 06:58:59PM +0800, Lai, Yi wrote:
> > > > > > > Hi Niklas Cassel,
> > > > > > >
> > > > > > > Greetings!
> > > > > > >
> > > > > > > I used Syzkaller and found that there is INFO: task hung in blk_mq_get_tag in v6.12-rc3
> > > > > > >
> > > > > > > After bisection and the first bad commit is:
> > > > > > > "
> > > > > > > e5dd410acb34 ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
> > > > > > > "
> > > > > >
> > > > > > It might be that your bisection results are accurate.
> > > > > >
> > > > > > However, after looking at the stacktraces, I find it way more likely that
> > > > > > bisection has landed on the wrong commit.
> > > > > >
> > > > > > See this series that was just queued (for 6.13) a few days ago that solves a
> > > > > > similar starvation:
> > > > > > https://lore.kernel.org/linux-block/20241014092934.53630-1-songmuchun@bytedance.com/
> > > > > > https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git/log/?h=for-6.13/block
> > > > > >
> > > > > > You could perhaps run with v6.14-rc4 (which should be able to trigger the bug)
> > > > > > and then try v6.14-rc4 + that series applied, to see if you can still trigger
> > > > > > the bug?
> > > > >
> >
> > I tried kernel linux-block
> > https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git
> > branch for-6.13/block commit c97f91b1807a7966077b69b24f28c2dbcde664e9.
> >
> > Issue can still be reproduced.
>
> Thanks again for your testing!
>
> I will try to reproduce using your reproducer (repo.c),
> and see if I can make any sense of this.
Hello Yi Lai,
An important thing that I noticed is that even when I look at your good commit
(v5.11) - the first commit you marked as as good in git bisect, it has this:
https://github.com/laifryiee/syzkaller_logs/blob/main/241018_105830_blk_mq_get_tag/f40ddce88593482919761f74910f42f4b84c004b_dmesg.log
[ 300.525626] __schedule+0xb9f/0x2eb0^M
[ 300.525843] ? __pfx___schedule+0x10/0x10^M
[ 300.526056] ? lock_release+0x441/0x870^M
[ 300.526286] ? __pfx_lock_release+0x10/0x10^M
[ 300.526512] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20^M
[ 300.526801] ? kthread_data+0x61/0xd0^M
[ 300.527007] schedule+0xf6/0x3f0^M
[ 300.527225] io_schedule+0xce/0x150^M
[ 300.527408] rq_qos_wait+0x1c5/0x310^M
[ 300.527610] ? __pfx_wbt_cleanup_cb+0x10/0x10^M
[ 300.527847] ? __pfx_rq_qos_wait+0x10/0x10^M
[ 300.528070] ? __pfx_lock_release+0x10/0x10^M
[ 300.528296] ? __pfx_rq_qos_wake_function+0x10/0x10^M
[ 300.528562] ? __pfx_wbt_inflight_cb+0x10/0x10^M
[ 300.528806] ? do_raw_spin_unlock+0x15c/0x210^M
[ 300.529048] wbt_wait+0x1ec/0x400^M
In fact, most *_dmesg.log logs in your syzlog directory has a stack trace that
contains a "blocked for more than 147 seconds" error.
Many of these logs are (with the "blocked for more than 147 seconds" error)
are commits that your bisect script has classified as "good".
If we look at your own dmesg with Linux 6.12-rc3 + e5dd410acb34 reverted,
which passes your git bisect script, even if it has a
"blocked for more than 147 seconds" error:
https://github.com/laifryiee/syzkaller_logs/blob/main/241018_105830_blk_mq_get_tag/8e929cb546ee42c9a61d24fae60605e9e3192354_e5dd410acb34c7341a0a93b429dcf3dabf9e3323_revert_dmesg.log
It seems that the reason is because you don't find "blk_mq_get_tag" in dmesg:
|1019_054406|/var/www/html/bzimage/bzImage_8e929cb546ee42c9a61d24fae60605e9e3192354_e5dd410acb34c7341a0a93b429dcf3dabf9e3323_revert didn't contain blk_mq_get_tag: in dmesg, pass|
|1019_054406|Bisect successfully! 8e929cb546ee42c9a61d24fae60605e9e3192354_e5dd410acb34c7341a0a93b429dcf3dabf9e3323_revert bzimage passed!|
So it seems that both v5.11 and "v6.12-rc3 + e5dd410acb34 reverted" has
problems.
I managed to reproduce using your reproducer, and with
v6.12-rc4 + e5dd410acb34 reverted, I see:
[ 299.641187] __schedule+0x1144/0x3200
[ 299.641425] ? __pfx___schedule+0x10/0x10
[ 299.641651] ? lock_release+0x4b0/0x870
[ 299.641868] ? debug_smp_processor_id+0x1b/0x30
[ 299.642128] ? __pfx_lock_release+0x10/0x10
[ 299.642362] ? srso_alias_return_thunk+0x5/0xfbef5
[ 299.642640] ? lock_acquire+0x80/0xb0
[ 299.642852] ? schedule+0x202/0x3d0
[ 299.643068] schedule+0xe7/0x3d0
[ 299.643261] io_schedule+0x96/0x100
[ 299.643494] bit_wait_io+0x17/0xf0
[ 299.643703] __wait_on_bit_lock+0x118/0x1a0
[ 299.643941] ? __pfx_bit_wait_io+0x10/0x10
[ 299.644195] out_of_line_wait_on_bit_lock+0xe8/0x120
[ 299.644475] ? __pfx_out_of_line_wait_on_bit_lock+0x10/0x10
[ 299.644793] ? __pfx_wake_bit_function+0x10/0x10
[ 299.645060] ? srso_alias_return_thunk+0x5/0xfbef5
[ 299.645344] __lock_buffer+0x72/0x80
[ 299.645569] do_get_write_access+0x7d0/0x1130
[ 299.645838] jbd2_journal_get_write_access+0x1e9/0x270
[ 299.646136] __ext4_journal_get_write_access+0x72/0x3b0
[ 299.646436] ext4_reserve_inode_write+0x145/0x280
So even with e5dd410acb34 reverted, we see a problem!
The difference seems to be the stack trace before and after e5dd410acb34 is
slightly different.
Before e5dd410acb34 the stack trace often looks like one of the two above.
After e5dd410acb34 the stack trace instead always has blk_mq_get (and seems
to be easier to reproduce).
I think that the stack trace that contains "blk_mq_get" actually indicates a
new problem though, so thank you for that!
I have a fix for it:
diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
index fa41ea57a978..3b303d4ae37a 100644
--- a/drivers/ata/libata-eh.c
+++ b/drivers/ata/libata-eh.c
@@ -651,6 +651,7 @@ void ata_scsi_cmd_error_handler(struct Scsi_Host *host, struct ata_port *ap,
/* the scmd has an associated qc */
if (!(qc->flags & ATA_QCFLAG_EH)) {
/* which hasn't failed yet, timeout */
+ set_host_byte(scmd, DID_TIME_OUT);
qc->err_mask |= AC_ERR_TIMEOUT;
qc->flags |= ATA_QCFLAG_EH;
nr_timedout++;
I will post it as a real fix for the new problem (blk_mq_get) tomorrow.
This just solves the new problem though.
You probably need to do another bisection to find the problem that exists on
v5.11 and earlier kernels.
Kind regards,
Niklas
^ permalink raw reply related [flat|nested] 10+ messages in thread
* Re: [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
2024-10-22 15:59 ` Niklas Cassel
@ 2024-10-23 2:55 ` Lai, Yi
0 siblings, 0 replies; 10+ messages in thread
From: Lai, Yi @ 2024-10-23 2:55 UTC (permalink / raw)
To: Niklas Cassel
Cc: Damien Le Moal, Hannes Reinecke, Martin K. Petersen, Igor Pylypiv,
Niklas Cassel, linux-ide, yi1.lai, syzkaller-bugs, linux-kernel
On Tue, Oct 22, 2024 at 05:59:13PM +0200, Niklas Cassel wrote:
> On Tue, Oct 22, 2024 at 01:04:10PM +0200, Niklas Cassel wrote:
> > On Tue, Oct 22, 2024 at 05:55:17PM +0800, Lai, Yi wrote:
> > > On Tue, Oct 22, 2024 at 10:48:04AM +0200, Niklas Cassel wrote:
> > > > On Tue, Oct 22, 2024 at 01:44:08PM +0800, Lai, Yi wrote:
> > > > > On Mon, Oct 21, 2024 at 05:20:12PM +0200, Niklas Cassel wrote:
> > > > > > On Mon, Oct 21, 2024 at 02:07:21PM +0200, Niklas Cassel wrote:
> > > > > > > Hello Yi Lai,
> > > > > > >
> > > > > > > On Mon, Oct 21, 2024 at 06:58:59PM +0800, Lai, Yi wrote:
> > > > > > > > Hi Niklas Cassel,
> > > > > > > >
> > > > > > > > Greetings!
> > > > > > > >
> > > > > > > > I used Syzkaller and found that there is INFO: task hung in blk_mq_get_tag in v6.12-rc3
> > > > > > > >
> > > > > > > > After bisection and the first bad commit is:
> > > > > > > > "
> > > > > > > > e5dd410acb34 ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data
> > > > > > > > "
> > > > > > >
> > > > > > > It might be that your bisection results are accurate.
> > > > > > >
> > > > > > > However, after looking at the stacktraces, I find it way more likely that
> > > > > > > bisection has landed on the wrong commit.
> > > > > > >
> > > > > > > See this series that was just queued (for 6.13) a few days ago that solves a
> > > > > > > similar starvation:
> > > > > > > https://lore.kernel.org/linux-block/20241014092934.53630-1-songmuchun@bytedance.com/
> > > > > > > https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git/log/?h=for-6.13/block
> > > > > > >
> > > > > > > You could perhaps run with v6.14-rc4 (which should be able to trigger the bug)
> > > > > > > and then try v6.14-rc4 + that series applied, to see if you can still trigger
> > > > > > > the bug?
> > > > > >
> > >
> > > I tried kernel linux-block
> > > https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git
> > > branch for-6.13/block commit c97f91b1807a7966077b69b24f28c2dbcde664e9.
> > >
> > > Issue can still be reproduced.
> >
> > Thanks again for your testing!
> >
> > I will try to reproduce using your reproducer (repo.c),
> > and see if I can make any sense of this.
>
> Hello Yi Lai,
>
>
> An important thing that I noticed is that even when I look at your good commit
> (v5.11) - the first commit you marked as as good in git bisect, it has this:
> https://github.com/laifryiee/syzkaller_logs/blob/main/241018_105830_blk_mq_get_tag/f40ddce88593482919761f74910f42f4b84c004b_dmesg.log
>
> [ 300.525626] __schedule+0xb9f/0x2eb0^M
> [ 300.525843] ? __pfx___schedule+0x10/0x10^M
> [ 300.526056] ? lock_release+0x441/0x870^M
> [ 300.526286] ? __pfx_lock_release+0x10/0x10^M
> [ 300.526512] ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20^M
> [ 300.526801] ? kthread_data+0x61/0xd0^M
> [ 300.527007] schedule+0xf6/0x3f0^M
> [ 300.527225] io_schedule+0xce/0x150^M
> [ 300.527408] rq_qos_wait+0x1c5/0x310^M
> [ 300.527610] ? __pfx_wbt_cleanup_cb+0x10/0x10^M
> [ 300.527847] ? __pfx_rq_qos_wait+0x10/0x10^M
> [ 300.528070] ? __pfx_lock_release+0x10/0x10^M
> [ 300.528296] ? __pfx_rq_qos_wake_function+0x10/0x10^M
> [ 300.528562] ? __pfx_wbt_inflight_cb+0x10/0x10^M
> [ 300.528806] ? do_raw_spin_unlock+0x15c/0x210^M
> [ 300.529048] wbt_wait+0x1ec/0x400^M
>
> In fact, most *_dmesg.log logs in your syzlog directory has a stack trace that
> contains a "blocked for more than 147 seconds" error.
> Many of these logs are (with the "blocked for more than 147 seconds" error)
> are commits that your bisect script has classified as "good".
>
>
> If we look at your own dmesg with Linux 6.12-rc3 + e5dd410acb34 reverted,
> which passes your git bisect script, even if it has a
> "blocked for more than 147 seconds" error:
> https://github.com/laifryiee/syzkaller_logs/blob/main/241018_105830_blk_mq_get_tag/8e929cb546ee42c9a61d24fae60605e9e3192354_e5dd410acb34c7341a0a93b429dcf3dabf9e3323_revert_dmesg.log
> It seems that the reason is because you don't find "blk_mq_get_tag" in dmesg:
> |1019_054406|/var/www/html/bzimage/bzImage_8e929cb546ee42c9a61d24fae60605e9e3192354_e5dd410acb34c7341a0a93b429dcf3dabf9e3323_revert didn't contain blk_mq_get_tag: in dmesg, pass|
> |1019_054406|Bisect successfully! 8e929cb546ee42c9a61d24fae60605e9e3192354_e5dd410acb34c7341a0a93b429dcf3dabf9e3323_revert bzimage passed!|
>
> So it seems that both v5.11 and "v6.12-rc3 + e5dd410acb34 reverted" has
> problems.
>
>
> I managed to reproduce using your reproducer, and with
> v6.12-rc4 + e5dd410acb34 reverted, I see:
> [ 299.641187] __schedule+0x1144/0x3200
> [ 299.641425] ? __pfx___schedule+0x10/0x10
> [ 299.641651] ? lock_release+0x4b0/0x870
> [ 299.641868] ? debug_smp_processor_id+0x1b/0x30
> [ 299.642128] ? __pfx_lock_release+0x10/0x10
> [ 299.642362] ? srso_alias_return_thunk+0x5/0xfbef5
> [ 299.642640] ? lock_acquire+0x80/0xb0
> [ 299.642852] ? schedule+0x202/0x3d0
> [ 299.643068] schedule+0xe7/0x3d0
> [ 299.643261] io_schedule+0x96/0x100
> [ 299.643494] bit_wait_io+0x17/0xf0
> [ 299.643703] __wait_on_bit_lock+0x118/0x1a0
> [ 299.643941] ? __pfx_bit_wait_io+0x10/0x10
> [ 299.644195] out_of_line_wait_on_bit_lock+0xe8/0x120
> [ 299.644475] ? __pfx_out_of_line_wait_on_bit_lock+0x10/0x10
> [ 299.644793] ? __pfx_wake_bit_function+0x10/0x10
> [ 299.645060] ? srso_alias_return_thunk+0x5/0xfbef5
> [ 299.645344] __lock_buffer+0x72/0x80
> [ 299.645569] do_get_write_access+0x7d0/0x1130
> [ 299.645838] jbd2_journal_get_write_access+0x1e9/0x270
> [ 299.646136] __ext4_journal_get_write_access+0x72/0x3b0
> [ 299.646436] ext4_reserve_inode_write+0x145/0x280
>
> So even with e5dd410acb34 reverted, we see a problem!
>
>
>
> The difference seems to be the stack trace before and after e5dd410acb34 is
> slightly different.
> Before e5dd410acb34 the stack trace often looks like one of the two above.
> After e5dd410acb34 the stack trace instead always has blk_mq_get (and seems
> to be easier to reproduce).
>
>
> I think that the stack trace that contains "blk_mq_get" actually indicates a
> new problem though, so thank you for that!
>
> I have a fix for it:
> diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
> index fa41ea57a978..3b303d4ae37a 100644
> --- a/drivers/ata/libata-eh.c
> +++ b/drivers/ata/libata-eh.c
> @@ -651,6 +651,7 @@ void ata_scsi_cmd_error_handler(struct Scsi_Host *host, struct ata_port *ap,
> /* the scmd has an associated qc */
> if (!(qc->flags & ATA_QCFLAG_EH)) {
> /* which hasn't failed yet, timeout */
> + set_host_byte(scmd, DID_TIME_OUT);
> qc->err_mask |= AC_ERR_TIMEOUT;
> qc->flags |= ATA_QCFLAG_EH;
> nr_timedout++;
>
>
>
> I will post it as a real fix for the new problem (blk_mq_get) tomorrow.
>
I applied this fix on top of linux v6.12-rc4. The new problem
cannot be reproduced.
If possible, please help add reported-by tag.
> This just solves the new problem though.
>
> You probably need to do another bisection to find the problem that exists on
> v5.11 and earlier kernels.
Thanks for the analysis. It indeed gives direction for me to further improve the
issue reproduction and bisection handling flow. I will follow up.
Regards,
Yi Lai
>
>
> Kind regards,
> Niklas
^ permalink raw reply [flat|nested] 10+ messages in thread
end of thread, other threads:[~2024-10-23 2:56 UTC | newest]
Thread overview: 10+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
[not found] <20240909154237.3656000-2-cassel@kernel.org>
2024-10-21 10:58 ` [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data Lai, Yi
2024-10-21 12:07 ` Niklas Cassel
2024-10-21 12:34 ` Damien Le Moal
2024-10-21 15:20 ` Niklas Cassel
2024-10-22 5:44 ` Lai, Yi
2024-10-22 8:48 ` Niklas Cassel
2024-10-22 9:55 ` Lai, Yi
2024-10-22 11:04 ` Niklas Cassel
2024-10-22 15:59 ` Niklas Cassel
2024-10-23 2:55 ` Lai, Yi
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox