On Sun, Dec 10, 2017 at 02:17:06AM +0100, Adam Borowski wrote: > Hi guys! > I have a μSD card that 100%-reproducibly causes the following when tested > with f3probe: > > [ 9241.126155] usb 2-1: new high-speed USB device number 3 using ehci-pci > [ 9241.287011] usb 2-1: New USB device found, idVendor=1976, idProduct=4082 > [ 9241.293846] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 > [ 9241.301121] usb 2-1: Product: USB Reader > [ 9241.305146] usb 2-1: Manufacturer: ChipsBnk > [ 9241.309429] usb 2-1: SerialNumber: 110074973765 > [ 9241.327255] usb-storage 2-1:1.0: USB Mass Storage device detected > [ 9241.333801] scsi host8: usb-storage 2-1:1.0 > [ 9241.338194] usbcore: registered new interface driver usb-storage > [ 9242.370935] scsi 8:0:0:0: Direct-Access ChipsBnk Multi-Reader 4082 PQ: 0 ANSI: 2 > [ 9242.379943] sd 8:0:0:0: Attached scsi generic sg2 type 0 > [ 9242.381523] sd 8:0:0:0: [sdc] 30679040 512-byte logical blocks: (15.7 GB/14.6 GiB) > [ 9242.382135] sd 8:0:0:0: [sdc] Write Protect is off > [ 9242.382137] sd 8:0:0:0: [sdc] Mode Sense: 0b 00 00 08 > [ 9242.382755] sd 8:0:0:0: [sdc] No Caching mode page found > [ 9242.382757] sd 8:0:0:0: [sdc] Assuming drive cache: write through > [ 9242.386877] sdc: > [ 9242.396000] sd 8:0:0:0: [sdc] Attached SCSI removable disk > f3probe /dev/sdc > [ 9276.697035] usb 2-1: reset high-speed USB device number 3 using ehci-pci > [ 9276.915066] sdc: > [ 9626.072637] usb usb2-port1: disabled by hub (EMI?), re-enabling... > [ 9626.078933] usb 2-1: USB disconnect, device number 3 > [ 9626.085727] scsi 8:0:0:0: rejecting I/O to offline device > [ 9626.091235] scsi 8:0:0:0: [sdc] killing request > [ 9626.095846] scsi 8:0:0:0: rejecting I/O to offline device > [ 9626.101318] scsi 8:0:0:0: [sdc] killing request > [ 9626.106007] scsi 8:0:0:0: [sdc] FAILED Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK > [ 9626.114400] scsi 8:0:0:0: [sdc] CDB: Read(10) 28 00 01 9e 2c b0 00 00 f0 00 > [ 9626.121430] print_req_error: I/O error, dev sdc, sector 27143344 > [ 9626.127523] scsi 8:0:0:0: [sdc] FAILED Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK > [ 9626.135918] scsi 8:0:0:0: [sdc] CDB: Read(10) 28 00 01 9e 2d a0 00 00 f0 00 > [ 9626.142918] print_req_error: I/O error, dev sdc, sector 27143584 > [ 9787.760554] INFO: task kworker/0:1:63 blocked for more than 120 seconds. > [ 9787.767381] Not tainted 4.15.0-rc2-debug-00490-gc09e9bbeb5d1 #1 > [ 9787.773947] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > [ 9787.781892] kworker/0:1 D 0 63 2 0x80000000 > [ 9787.787495] Workqueue: usb_hub_wq hub_event > [ 9787.791760] Call Trace: > [ 9787.794277] ? __schedule+0x1a5/0x6e0 > [ 9787.798028] schedule+0x23/0x80 > [ 9787.801259] blk_mq_freeze_queue_wait+0x31/0x80 > [ 9787.805919] ? wait_woken+0x80/0x80 > [ 9787.809487] blk_cleanup_queue+0x68/0x110 > [ 9787.813614] __scsi_remove_device+0x6f/0x150 > [ 9787.818045] scsi_forget_host+0x1b/0x60 > [ 9787.821964] scsi_remove_host+0x6d/0x100 > [ 9787.825997] usb_stor_disconnect+0x57/0xc0 [usb_storage] > [ 9787.831417] usb_unbind_interface+0x6c/0x270 > [ 9787.835787] device_release_driver_internal+0x195/0x260 > [ 9787.841125] bus_remove_device+0xd4/0x120 > [ 9787.845263] device_del+0x11a/0x320 > [ 9787.848802] ? usb_remove_ep_devs+0x16/0x30 > [ 9787.853073] usb_disable_device+0x7b/0x1d0 > [ 9787.857274] usb_disconnect+0xb6/0x220 > [ 9787.861145] hub_event+0x733/0x1300 > [ 9787.864698] process_one_work+0x1a7/0x340 > [ 9787.868811] worker_thread+0x26/0x3f0 > [ 9787.872630] ? create_worker+0x190/0x190 > [ 9787.876698] kthread+0x107/0x120 > [ 9787.879994] ? kthread_create_worker_on_cpu+0x40/0x40 > [ 9787.885143] ret_from_fork+0x1f/0x30 > [ 9787.888881] INFO: task f3probe:5269 blocked for more than 120 seconds. > [ 9787.895530] Not tainted 4.15.0-rc2-debug-00490-gc09e9bbeb5d1 #1 > [ 9787.902079] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > [ 9787.910094] f3probe D 0 5269 4476 0x00000000 > [ 9787.915683] Call Trace: > [ 9787.918229] ? __schedule+0x1a5/0x6e0 > [ 9787.921956] schedule+0x23/0x80 > [ 9787.925182] io_schedule+0xd/0x40 > [ 9787.928575] __blkdev_direct_IO_simple+0x1a2/0x2a0 > [ 9787.933482] ? bdget+0x110/0x110 > [ 9787.936800] blkdev_direct_IO+0x34c/0x390 > [ 9787.940962] ? current_time+0x11/0x60 > [ 9787.944716] ? generic_update_time+0x77/0xc0 > [ 9787.949098] ? current_time+0x11/0x60 > [ 9787.952863] generic_file_read_iter+0x9f/0x930 > [ 9787.957465] ? invalidate_mapping_pages+0x6d/0x2a0 > [ 9787.962360] ? lru_lazyfree_fn+0x2d0/0x2d0 > [ 9787.966573] ? release_pages+0x2a5/0x340 > [ 9787.970565] __vfs_read+0xcc/0x120 > [ 9787.974054] vfs_read+0x98/0x150 > [ 9787.977359] SyS_read+0x4b/0xb0 > [ 9787.980583] ? SyS_lseek+0x6e/0xc0 > [ 9787.984035] entry_SYSCALL_64_fastpath+0x17/0x70 > [ 9787.988783] RIP: 0033:0x7fa6ab981750 > [ 9787.992537] RSP: 002b:00007ffe29ce8568 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 > [ 9788.000294] RAX: ffffffffffffffda RBX: 00000000019e27fe RCX: 00007fa6ab981750 > [ 9788.007525] RDX: 0000000000100000 RSI: 00007fa675184200 RDI: 0000000000000003 > [ 9788.014858] RBP: 0000563803f9e4b0 R08: 00005638022efde0 R09: 0000000001d42000 > [ 9788.022126] R10: 0000000000000004 R11: 0000000000000246 R12: 00000000019e27ff > [ 9788.029370] R13: 00007fa61eff3010 R14: 0000000000000001 R15: 00007fa61ec4a010 > [ 9908.588627] INFO: task kworker/0:1:63 blocked for more than 120 seconds. > [ 9908.595451] Not tainted 4.15.0-rc2-debug-00490-gc09e9bbeb5d1 #1 > [ 9908.602076] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > [ 9908.610015] kworker/0:1 D 0 63 2 0x80000000 > [ 9908.615585] Workqueue: usb_hub_wq hub_event > [ 9908.619868] Call Trace: > [ 9908.622418] ? __schedule+0x1a5/0x6e0 > [ 9908.626189] schedule+0x23/0x80 > [ 9908.629463] blk_mq_freeze_queue_wait+0x31/0x80 > [ 9908.634117] ? wait_woken+0x80/0x80 > [ 9908.637704] blk_cleanup_queue+0x68/0x110 > [ 9908.641843] __scsi_remove_device+0x6f/0x150 > [ 9908.646232] scsi_forget_host+0x1b/0x60 > [ 9908.650159] scsi_remove_host+0x6d/0x100 > [ 9908.654210] usb_stor_disconnect+0x57/0xc0 [usb_storage] > [ 9908.659690] usb_unbind_interface+0x6c/0x270 > [ 9908.664089] device_release_driver_internal+0x195/0x260 > [ 9908.669392] bus_remove_device+0xd4/0x120 > [ 9908.673504] device_del+0x11a/0x320 > [ 9908.677063] ? usb_remove_ep_devs+0x16/0x30 > [ 9908.681398] usb_disable_device+0x7b/0x1d0 > [ 9908.685588] usb_disconnect+0xb6/0x220 > [ 9908.689444] hub_event+0x733/0x1300 > [ 9908.693056] process_one_work+0x1a7/0x340 > [ 9908.697165] worker_thread+0x26/0x3f0 > [ 9908.700883] ? create_worker+0x190/0x190 > [ 9908.704940] kthread+0x107/0x120 > [ 9908.708236] ? kthread_create_worker_on_cpu+0x40/0x40 > [ 9908.713464] ret_from_fork+0x1f/0x30 > [ 9908.717240] INFO: task f3probe:5269 blocked for more than 120 seconds. > [ 9908.723965] Not tainted 4.15.0-rc2-debug-00490-gc09e9bbeb5d1 #1 > [ 9908.730527] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > [ 9908.738539] f3probe D 0 5269 4476 0x00000000 > [ 9908.744162] Call Trace: > [ 9908.746698] ? __schedule+0x1a5/0x6e0 > [ 9908.750428] schedule+0x23/0x80 > [ 9908.753688] io_schedule+0xd/0x40 > [ 9908.757116] __blkdev_direct_IO_simple+0x1a2/0x2a0 > [ 9908.762020] ? bdget+0x110/0x110 > [ 9908.765345] blkdev_direct_IO+0x34c/0x390 > [ 9908.769466] ? current_time+0x11/0x60 > [ 9908.773216] ? generic_update_time+0x77/0xc0 > [ 9908.777578] ? current_time+0x11/0x60 > [ 9908.781315] generic_file_read_iter+0x9f/0x930 > [ 9908.785877] ? invalidate_mapping_pages+0x6d/0x2a0 > [ 9908.790810] ? lru_lazyfree_fn+0x2d0/0x2d0 > [ 9908.795037] ? release_pages+0x2a5/0x340 > [ 9908.799100] __vfs_read+0xcc/0x120 > [ 9908.802569] vfs_read+0x98/0x150 > [ 9908.805949] SyS_read+0x4b/0xb0 > [ 9908.809197] ? SyS_lseek+0x6e/0xc0 > [ 9908.812703] entry_SYSCALL_64_fastpath+0x17/0x70 > [ 9908.817396] RIP: 0033:0x7fa6ab981750 > [ 9908.821093] RSP: 002b:00007ffe29ce8568 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 > [ 9908.828831] RAX: ffffffffffffffda RBX: 00000000019e27fe RCX: 00007fa6ab981750 > [ 9908.836187] RDX: 0000000000100000 RSI: 00007fa675184200 RDI: 0000000000000003 > [ 9908.843449] RBP: 0000563803f9e4b0 R08: 00005638022efde0 R09: 0000000001d42000 > [ 9908.850706] R10: 0000000000000004 R11: 0000000000000246 R12: 00000000019e27ff > [ 9908.858042] R13: 00007fa61eff3010 R14: 0000000000000001 R15: 00007fa61ec4a010 > > with f3probe obviously stuck forever. There's no extra messages on actually > physically removing the SD card or the reader. > > With SD cards and USB sticks having floppy-like reliability, I/O failures > need to be considered a normal occurence, especially with no filesystem even > mounted. In this case, the card offlines itself, but the removal doesn't > complete. Is this a new thing? Do older kernels also fail the same way? And what do you mean by "removal doesn't complete"? If you physically remove and add it back, is it working again? thanks, greg k-h -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
