You are not logged in.
I have a (32GB Platinum) USBstick with "ultra high performance" and EAN code 4027927775435. Apart from the packaging, the real life performance is below 2,9 IOPS random write at 4K block size.
The stick contains 2 partitions: 200 MB FAT for UEFI boot and the rest for storing backups using BTRFS snapshots. The stick is directly plugged in to the back of a server chassis. It runs kernel version 4.20.0.
# lsusb -t
/: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/8p, 480M
|__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
|__ Port 2: Dev 6, If 0, Class=Mass Storage, Driver=usb-storage, 480M
|__ Port 4: Dev 3, If 0, Class=Hub, Driver=hub/5p, 480M
|__ Port 4: Dev 4, If 0, Class=Human Interface Device, Driver=usbhid, 1.5M
|__ Port 4: Dev 4, If 1, Class=Human Interface Device, Driver=usbhid, 1.5MThat usbstick gives frequent errors on receiving new backup data via rsync including "reset high-speed USB device number on rsync write".
First I thought that the USBstick is faulty. Though the destructive badblocks write test doesn't show any error at all.
I reformatted that USBstick and the errors are still there. I used another stick plugged in the same port, without any errors.
An example of the rsync error messages:
[41429.221078] usb 1-1.1: reset high-speed USB device number 6 using ehci-pci
[41430.229722] sd 16:0:0:0: [sdc] 60555264 512-byte logical blocks: (31.0 GB/28.9 GiB)
[41656.117008] INFO: task rsync:19711 blocked for more than 120 seconds.
[41656.122023] Not tainted 4.20.0-arch1-1-ARCH #1
[41656.127095] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[41656.132327] rsync D 0 19711 19226 0x00000080
[41656.132332] Call Trace:
[41656.132343] ? __schedule+0x29b/0x8b0
[41656.132347] ? _raw_spin_unlock+0x16/0x30
[41656.132350] ? _raw_spin_lock+0x13/0x30
[41656.132353] schedule+0x32/0x90
[41656.132357] io_schedule+0x12/0x40
[41656.132365] wait_on_page_bit+0x110/0x200
[41656.132368] ? find_get_entry+0x80/0x180
[41656.132371] ? add_to_page_cache_lru+0xc0/0xc0
[41656.132410] prepare_pages+0x258/0x270 [btrfs]
[41656.132443] btrfs_buffered_write.isra.4+0x255/0x770 [btrfs]
[41656.132477] btrfs_file_write_iter+0x3e2/0x610 [btrfs]
[41656.132482] ? _copy_to_user+0x26/0x30
[41656.132485] ? cp_new_stat+0x150/0x180
[41656.132491] __vfs_write+0x136/0x1a0
[41656.132495] vfs_write+0xa9/0x1a0
[41656.132499] ksys_write+0x4f/0xb0
[41656.132503] do_syscall_64+0x5b/0x170
[41656.132507] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[41656.132510] RIP: 0033:0x7fb3bf5ea818
[41656.132518] Code: Bad RIP value.
[41656.132522] RSP: 002b:00007ffd621e9ae8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[41656.132525] RAX: ffffffffffffffda RBX: 000000000000002f RCX: 00007fb3bf5ea818
[41656.132527] RDX: 000000000000002f RSI: 000055fe30cd2930 RDI: 0000000000000001
[41656.132528] RBP: 000055fe30cd2930 R08: 00007fb3bf6be720 R09: 00007fb3bf4fcb80
[41656.132530] R10: 000000000000000a R11: 0000000000000246 R12: 00007fb3bf6bd5c0
[41656.132532] R13: 000000000000002f R14: 00007fb3bf6b85c0 R15: 000000000000002f
[41778.996637] INFO: task rsync:19711 blocked for more than 120 seconds.
[41779.001915] Not tainted 4.20.0-arch1-1-ARCH #1
[41779.007208] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[41779.012688] rsync D 0 19711 19226 0x00000080
[41779.012696] Call Trace:
[41779.012713] ? __schedule+0x29b/0x8b0
[41779.012720] ? _raw_spin_unlock+0x16/0x30
[41779.012725] ? _raw_spin_lock+0x13/0x30
[41779.012731] schedule+0x32/0x90
[41779.012742] io_schedule+0x12/0x40
[41779.012750] wait_on_page_bit+0x110/0x200
[41779.012756] ? find_get_entry+0x80/0x180
[41779.012762] ? add_to_page_cache_lru+0xc0/0xc0
[41779.012830] prepare_pages+0x258/0x270 [btrfs]
[41779.012894] btrfs_buffered_write.isra.4+0x255/0x770 [btrfs]
[41779.012961] btrfs_file_write_iter+0x3e2/0x610 [btrfs]
[41779.012970] ? _copy_to_user+0x26/0x30
[41779.012976] ? cp_new_stat+0x150/0x180
[41779.012987] __vfs_write+0x136/0x1a0
[41779.012995] vfs_write+0xa9/0x1a0
[41779.013022] ksys_write+0x4f/0xb0
[41779.013031] do_syscall_64+0x5b/0x170
[41779.013038] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[41779.013045] RIP: 0033:0x7fb3bf5ea818
[41779.013057] Code: Bad RIP value.
[41779.013061] RSP: 002b:00007ffd621e9ae8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[41779.013067] RAX: ffffffffffffffda RBX: 000000000000002f RCX: 00007fb3bf5ea818
[41779.013074] RDX: 000000000000002f RSI: 000055fe30cd2930 RDI: 0000000000000001
[41779.013077] RBP: 000055fe30cd2930 R08: 00007fb3bf6be720 R09: 00007fb3bf4fcb80
[41779.013080] R10: 000000000000000a R11: 0000000000000246 R12: 00007fb3bf6bd5c0
[41779.013083] R13: 000000000000002f R14: 00007fb3bf6b85c0 R15: 000000000000002f
[42147.635196] INFO: task rsync:19711 blocked for more than 120 seconds.
[42147.640781] Not tainted 4.20.0-arch1-1-ARCH #1
[42147.646437] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[42147.652408] rsync D 0 19711 19226 0x00000080
[42147.652414] Call Trace:
[42147.652429] ? __schedule+0x29b/0x8b0
[42147.652434] ? _raw_spin_unlock+0x16/0x30
[42147.652438] ? _raw_spin_lock+0x13/0x30
[42147.652443] schedule+0x32/0x90
[42147.652449] io_schedule+0x12/0x40
[42147.652455] wait_on_page_bit+0x110/0x200
[42147.652460] ? find_get_entry+0x80/0x180
[42147.652465] ? add_to_page_cache_lru+0xc0/0xc0
[42147.652522] prepare_pages+0x258/0x270 [btrfs]
[42147.652573] btrfs_buffered_write.isra.4+0x255/0x770 [btrfs]
[42147.652624] btrfs_file_write_iter+0x3e2/0x610 [btrfs]
[42147.652631] ? _copy_to_user+0x26/0x30
[42147.652636] ? cp_new_stat+0x150/0x180
[42147.652642] __vfs_write+0x136/0x1a0
[42147.652649] vfs_write+0xa9/0x1a0
[42147.652654] ksys_write+0x4f/0xb0
[42147.652661] do_syscall_64+0x5b/0x170
[42147.652667] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[42147.652672] RIP: 0033:0x7fb3bf5ea818
[42147.652682] Code: Bad RIP value.
[42147.652685] RSP: 002b:00007ffd621e9ae8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[42147.652690] RAX: ffffffffffffffda RBX: 000000000000001e RCX: 00007fb3bf5ea818
[42147.652693] RDX: 000000000000001e RSI: 000055fe30cd2930 RDI: 0000000000000001
[42147.652695] RBP: 000055fe30cd2930 R08: 00007fb3bf6be720 R09: 00007fb3bf4fcb80
[42147.652698] R10: 000000000000000a R11: 0000000000000246 R12: 00007fb3bf6bd5c0
[42147.652700] R13: 000000000000001e R14: 00007fb3bf6b85c0 R15: 000000000000001e
[42393.394263] INFO: task rsync:19711 blocked for more than 120 seconds.
[42393.400103] Not tainted 4.20.0-arch1-1-ARCH #1
[42393.406015] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[42393.412135] rsync D 0 19711 19226 0x00000080
[42393.412141] Call Trace:
[42393.412157] ? __schedule+0x29b/0x8b0
[42393.412163] schedule+0x32/0x90
[42393.412169] io_schedule+0x12/0x40
[42393.412176] wait_on_page_bit+0x110/0x200
[42393.412184] ? find_get_entry+0x80/0x180
[42393.412189] ? add_to_page_cache_lru+0xc0/0xc0
[42393.412246] prepare_pages+0x258/0x270 [btrfs]
[42393.412297] btrfs_buffered_write.isra.4+0x255/0x770 [btrfs]
[42393.412351] btrfs_file_write_iter+0x3e2/0x610 [btrfs]
[42393.412358] ? _copy_to_user+0x26/0x30
[42393.412364] ? cp_new_stat+0x150/0x180
[42393.412372] __vfs_write+0x136/0x1a0
[42393.412379] vfs_write+0xa9/0x1a0
[42393.412384] ksys_write+0x4f/0xb0
[42393.412391] do_syscall_64+0x5b/0x170
[42393.412397] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[42393.412403] RIP: 0033:0x7fb3bf5ea818
[42393.412413] Code: Bad RIP value.
[42393.412415] RSP: 002b:00007ffd621e9ae8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[42393.412423] RAX: ffffffffffffffda RBX: 000000000000004a RCX: 00007fb3bf5ea818
[42393.412425] RDX: 000000000000004a RSI: 000055fe30cd2930 RDI: 0000000000000001
[42393.412428] RBP: 000055fe30cd2930 R08: 00007fb3bf6be720 R09: 00007fb3bf4fcb80
[42393.412430] R10: 000000000000000a R11: 0000000000000246 R12: 00007fb3bf6bd5c0
[42393.412433] R13: 000000000000004a R14: 00007fb3bf6b85c0 R15: 000000000000004aAny suggestion to further isolate the root cause of this USBstick write issue?
Or is this USB stick just too slow?
Last edited by probackup-nl (2019-01-02 21:02:25)
Offline