You are not logged in.

#1 2020-03-10 00:55:32

JBman100
Member
Registered: 2017-03-15
Posts: 6

Very slow/hanging IO

Hello everyone,

I had to create a bootable USB stick recently and tried to do that with my Arch box. Every attempt failed with a hanging dd that did not finish after more than 3-4h of waiting.

The options used were every variation of the following:

dd bs=4M if=Downloads/archlinux-2020.03.01-x86_64.iso of=/dev/sdb conv=fdatasync,fsync status=progress

I know that dd is slow, and I am checked /proc/meminfo for the Writeback and Dirty fields, which did not decrease at all during the process. Doing the same in a tty highlighted some debug messages, such as:

Mar 09 17:28:36 arc1 kernel: INFO: task scsi_eh_2:2920 blocked for more than 245 seconds.
Mar 09 17:28:36 arc1 kernel:       Tainted: G          I       5.5.8-arch1-1 #1
Mar 09 17:28:36 arc1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

I then tried the manual installation method and formatted the stick with two partitions (2g of fat32 and 30 of ext4), and mkfs has troubles finishing the ext4 fs.

Checking journalctl gave me some tracebacks with the warnings, that I quote here just for integrity.

Mar 09 17:28:36 arc1 kernel: INFO: task scsi_eh_2:2920 blocked for more than 245 seconds.
Mar 09 17:28:36 arc1 kernel:       Tainted: G          I       5.5.8-arch1-1 #1
Mar 09 17:28:36 arc1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 09 17:28:36 arc1 kernel: scsi_eh_2       D    0  2920      2 0x80004080
Mar 09 17:28:36 arc1 kernel: Call Trace:
Mar 09 17:28:36 arc1 kernel:  ? __schedule+0x2e8/0x7a0
Mar 09 17:28:36 arc1 kernel:  schedule+0x46/0xf0
Mar 09 17:28:36 arc1 kernel:  schedule_preempt_disabled+0x14/0x20
Mar 09 17:28:36 arc1 kernel:  __mutex_lock.isra.0+0x1ae/0x550
Mar 09 17:28:36 arc1 kernel:  ? __switch_to_asm+0x34/0x70
Mar 09 17:28:36 arc1 kernel:  ? __switch_to_asm+0x40/0x70
Mar 09 17:28:36 arc1 kernel:  device_reset+0x1d/0x50 [usb_storage]
Mar 09 17:28:36 arc1 kernel:  scsi_eh_ready_devs+0x56f/0xa40 [scsi_mod]
Mar 09 17:28:36 arc1 kernel:  ? _raw_spin_unlock_irqrestore+0x20/0x40
Mar 09 17:28:36 arc1 kernel:  ? __pm_runtime_resume+0x49/0x60
Mar 09 17:28:36 arc1 kernel:  scsi_error_handler+0x44a/0x530 [scsi_mod]
Mar 09 17:28:36 arc1 kernel:  ? __schedule+0x6d3/0x7a0
Mar 09 17:28:36 arc1 kernel:  kthread+0xfb/0x130
Mar 09 17:28:36 arc1 kernel:  ? scsi_eh_get_sense+0x1f0/0x1f0 [scsi_mod]
Mar 09 17:28:36 arc1 kernel:  ? kthread_park+0x90/0x90
Mar 09 17:28:36 arc1 kernel:  ret_from_fork+0x35/0x40
Mar 09 17:28:36 arc1 kernel: INFO: task usb-storage:2922 blocked for more than 245 seconds.
Mar 09 17:28:36 arc1 kernel:       Tainted: G          I       5.5.8-arch1-1 #1
Mar 09 17:28:36 arc1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 09 17:28:36 arc1 kernel: usb-storage     D    0  2922      2 0x80004080
Mar 09 17:28:36 arc1 kernel: Call Trace:
Mar 09 17:28:36 arc1 kernel:  ? __schedule+0x2e8/0x7a0
Mar 09 17:28:36 arc1 kernel:  schedule+0x46/0xf0
Mar 09 17:28:36 arc1 kernel:  schedule_timeout+0x231/0x310
Mar 09 17:28:36 arc1 kernel:  ? usb_hcd_submit_urb+0xbf/0xbb0
Mar 09 17:28:36 arc1 kernel:  wait_for_completion+0xa6/0x100
Mar 09 17:28:36 arc1 kernel:  ? wake_up_q+0xa0/0xa0
Mar 09 17:28:36 arc1 kernel:  usb_sg_wait+0xc9/0x150
Mar 09 17:28:36 arc1 kernel:  usb_stor_bulk_transfer_sglist.part.0+0x64/0xb0 [usb_storage]
Mar 09 17:28:36 arc1 kernel:  usb_stor_bulk_srb+0x51/0x80 [usb_storage]
Mar 09 17:28:36 arc1 kernel:  usb_stor_Bulk_transport+0x179/0x3f0 [usb_storage]
Mar 09 17:28:36 arc1 kernel:  usb_stor_invoke_transport+0x59/0x510 [usb_storage]
Mar 09 17:28:36 arc1 kernel:  usb_stor_control_thread+0x233/0x300 [usb_storage]
Mar 09 17:28:36 arc1 kernel:  kthread+0xfb/0x130
Mar 09 17:28:36 arc1 kernel:  ? fill_inquiry_response+0x10/0x10 [usb_storage]
Mar 09 17:28:36 arc1 kernel:  ? kthread_park+0x90/0x90
Mar 09 17:28:36 arc1 kernel:  ret_from_fork+0x35/0x40
Mar 09 17:28:36 arc1 kernel: INFO: task mkfs.ext4:3312 blocked for more than 245 seconds.
Mar 09 17:28:36 arc1 kernel:       Tainted: G          I       5.5.8-arch1-1 #1
Mar 09 17:28:36 arc1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 09 17:28:36 arc1 kernel: mkfs.ext4       D    0  3312   3025 0x00004084
Mar 09 17:28:36 arc1 kernel: Call Trace:
Mar 09 17:28:36 arc1 kernel:  ? __schedule+0x2e8/0x7a0
Mar 09 17:28:36 arc1 kernel:  ? __wbt_done+0x30/0x30
Mar 09 17:28:36 arc1 kernel:  ? __wbt_done+0x30/0x30
Mar 09 17:28:36 arc1 kernel:  schedule+0x46/0xf0
Mar 09 17:28:36 arc1 kernel:  io_schedule+0x12/0x40
Mar 09 17:28:36 arc1 kernel:  rq_qos_wait+0x106/0x170
Mar 09 17:28:36 arc1 kernel:  ? karma_partition+0x240/0x240
Mar 09 17:28:36 arc1 kernel:  ? wbt_cleanup_cb+0x20/0x20
Mar 09 17:28:36 arc1 kernel:  wbt_wait+0xa1/0xe0
Mar 09 17:28:36 arc1 kernel:  __rq_qos_throttle+0x23/0x30
Mar 09 17:28:36 arc1 kernel:  blk_mq_make_request+0x14b/0x670
Mar 09 17:28:36 arc1 kernel:  generic_make_request+0xf2/0x350
Mar 09 17:28:36 arc1 kernel:  ? bvec_alloc+0x92/0xe0
Mar 09 17:28:36 arc1 kernel:  submit_bio+0x6e/0x1e0
Mar 09 17:28:36 arc1 kernel:  blk_next_bio+0x34/0x40
Mar 09 17:28:36 arc1 kernel:  __blkdev_issue_zero_pages+0x98/0x190
Mar 09 17:28:36 arc1 kernel:  blkdev_issue_zeroout+0x119/0x250
Mar 09 17:28:36 arc1 kernel:  blkdev_fallocate+0xd6/0x180
Mar 09 17:28:36 arc1 kernel:  vfs_fallocate+0x146/0x290
Mar 09 17:28:36 arc1 kernel:  ksys_fallocate+0x3a/0x70
Mar 09 17:28:36 arc1 kernel:  __x64_sys_fallocate+0x1a/0x20
Mar 09 17:28:36 arc1 kernel:  do_syscall_64+0x4e/0x150
Mar 09 17:28:36 arc1 kernel:  entry_SYSCALL_64_after_hwframe+0x44/0xa9
Mar 09 17:28:36 arc1 kernel: RIP: 0033:0x7f3a874e13ca
Mar 09 17:28:36 arc1 kernel: Code: Bad RIP value.
Mar 09 17:28:36 arc1 kernel: RSP: 002b:00007ffe18a2aac8 EFLAGS: 00000246 ORIG_RAX: 000000000000011d
Mar 09 17:28:36 arc1 kernel: RAX: ffffffffffffffda RBX: 0000562e497d4200 RCX: 00007f3a874e13ca

Unfortunately I just picked my machine back up, got it up to date and saw the problem, so I have no idea when the change operated. This is above my knowledge so if any info is needed, I'll provide.

Offline

#2 2020-03-10 07:45:12

seth
Member
From: Won't reply 2 private help req
Registered: 2012-09-03
Posts: 77,953

Re: Very slow/hanging IO

I'd check the "dmesg -w" while running dd for more and actual BUS/IO errors … and a different USB key 'cause this one's likely toast :-(

Offline

Board footer

Powered by FluxBB