Re: [PATCH v3] ata: libata: Clear DID_TIME_OUT for ATA PT commands with sense data

["Lai, Yi" <yi1.lai@linux.intel.com>]

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
>