external USB drive: blk_update_request: I/O error and the USB drive gets another /dev/sd node

[f18m]

Hi, I found a quite-reproducible problem (happens quite often!) with the following setup:

• HW: Raspberry model B+, powered by its own 5V, 2A power supply
• USB HUB 3.0 (Trascend TS-HUB3K), powered by its own 12V, 1.5A power supply (15W)
• 2 external hard disks (the problem happens also with just 1 hard disk!)
• root@rasptorrent:~# cat /etc/os-release PRETTY_NAME="Raspbian GNU/Linux 7 (wheezy)" NAME="Raspbian GNU/Linux" VERSION_ID="7" VERSION="7 (wheezy)" ID=raspbian ID_LIKE=debian ANSI_COLOR="1;31" HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
• root@rasptorrent:~# uname -a Linux rasptorrent 3.18.5+ #744 PREEMPT Fri Jan 30 18:19:07 GMT 2015 armv6l GNU/Linux

(did "rpi-update" on Jan 31 2015)

HOW TO REPRODUCE: just producing traffic on the USB external drives at some point produces:

[ 1116.317108] sd 1:0:0:0: [sdb]  
[ 1116.317199] Result: hostbyte=0x07 driverbyte=0x00
[ 1116.317220] sd 1:0:0:0: [sdb] CDB: 
[ 1116.317233] cdb[0]=0x28: 28 00 13 7b 13 08 00 00 f0 00
[ 1116.317297] blk_update_request: I/O error, dev sdb, sector 326832904

(several times, for different sectors)

and the USB device (e.g., /dev/sdb1) is destroyed and a new dev node is created (e.g., /dev/sdc1).

The dwc_otg driver seems latest one:

root@rasptorrent:~# dmesg | grep dwc_otg
[    0.000000] Kernel command line: dma.dmachans=0x7f35 bcm2708_fb.fbwidth=1824 bcm2708_fb.fbheight=984 bcm2708.boardrev=0x10 bcm2708.serial=0xee394e21 smsc95xx.macaddr=B8:27:EB:39:4E:21 bcm2708_fb.fbswap=1 bcm2708.disk_led_gpio=47 bcm2708.disk_led_active_low=0 sdhci-bcm2708.emmc_clock_freq=250000000 vc_mem.mem_base=0x1ec00000 vc_mem.mem_size=0x20000000  dwc_otg.lpm_enable=0 console=ttyAMA0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 elevator=deadline rootwait
[    1.583112] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    2.027416] WARN::dwc_otg_hcd_init:1047: FIQ DMA bounce buffers: virt = 0xdbc14000 dma = 0x5bc14000 len=9024
[    2.054741] dwc_otg: Microframe scheduler enabled
[    2.087234] dwc_otg bcm2708_usb: DWC OTG Controller
[    2.097477] dwc_otg bcm2708_usb: new USB bus registered, assigned bus number 1
[    2.110137] dwc_otg bcm2708_usb: irq 32, io mem 0x00000000
[    2.173907] usb usb1: Manufacturer: Linux 3.18.5+ dwc_otg_hcd
[    2.215058] dwc_otg: FIQ enabled
[    2.215085] dwc_otg: NAK holdoff enabled
[    2.215098] dwc_otg: FIQ split-transaction FSM enabled
[    2.696903] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    3.257234] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    3.617035] usb 1-1.2: new low-speed USB device number 4 using dwc_otg
[    4.117189] usb 1-1.3: new low-speed USB device number 5 using dwc_otg
[    4.647235] usb 1-1.5: new high-speed USB device number 6 using dwc_otg
[    5.287832] usb 1-1.5.2: new high-speed USB device number 7 using dwc_otg
[    5.757505] usb 1-1.5.4: new high-speed USB device number 8 using dwc_otg
[ 1116.837726] usb 1-1.5.4: new high-speed USB device number 9 using dwc_otg

and it seems that "FIQ enabled", "NAK holdoff enabled" " FIQ split-transaction FSM enabled" features are there.

I'm going to attach the dmsg and lsusb outputs. Please let me know if I can try some fix.

[f18m]

DMESG OUTPUT:

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 3.18.5+ (dc4@dc4-XPS13-9333) (gcc version 4.8.3 20140303 (prerelease) (crosstool-NG linaro-1.13.1+bzr2650 - Linaro GCC 2014.03) ) #744 PREEMPT Fri Jan 30 18:19:07 GMT 2015
[    0.000000] CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
[    0.000000] Machine model: Raspberry Pi Model B+
[    0.000000] cma: Reserved 8 MiB at 0x1b800000
[    0.000000] Memory policy: Data cache writeback
[    0.000000] On node 0 totalpages: 114688
[    0.000000] free_area_init_node: node 0, pgdat c084d794, node_mem_map db474000
[    0.000000]   Normal zone: 896 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 114688 pages, LIFO batch:31
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 113792
[    0.000000] Kernel command line: dma.dmachans=0x7f35 bcm2708_fb.fbwidth=1824 bcm2708_fb.fbheight=984 bcm2708.boardrev=0x10 bcm2708.serial=0xee394e21 smsc95xx.macaddr=B8:27:EB:39:4E:21 bcm2708_fb.fbswap=1 bcm2708.disk_led_gpio=47 bcm2708.disk_led_active_low=0 sdhci-bcm2708.emmc_clock_freq=250000000 vc_mem.mem_base=0x1ec00000 vc_mem.mem_size=0x20000000  dwc_otg.lpm_enable=0 console=ttyAMA0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 elevator=deadline rootwait
[    0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[    0.000000] Memory: 437208K/458752K available (5926K kernel code, 358K rwdata, 1876K rodata, 340K init, 734K bss, 21544K reserved)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xffc00000 - 0xffe00000   (2048 kB)
[    0.000000]     vmalloc : 0xdc800000 - 0xff000000   ( 552 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xdc000000   ( 448 MB)
[    0.000000]     modules : 0xbf000000 - 0xc0000000   (  16 MB)
[    0.000000]       .text : 0xc0008000 - 0xc07a6a60   (7803 kB)
[    0.000000]       .init : 0xc07a7000 - 0xc07fc000   ( 340 kB)
[    0.000000]       .data : 0xc07fc000 - 0xc085582c   ( 359 kB)
[    0.000000]        .bss : 0xc085582c - 0xc090d0c8   ( 735 kB)
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] Preemptible hierarchical RCU implementation.
[    0.000000] NR_IRQS:522
[    0.000025] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483648000ns
[    0.000076] Switching to timer-based delay loop, resolution 1000ns
[    0.000360] Console: colour dummy device 80x30
[    0.001434] console [tty1] enabled
[    0.001481] Calibrating delay loop (skipped), value calculated using timer frequency.. 2.00 BogoMIPS (lpj=10000)
[    0.001556] pid_max: default: 32768 minimum: 301
[    0.001934] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.002000] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.003011] Initializing cgroup subsys memory
[    0.003101] Initializing cgroup subsys devices
[    0.003159] Initializing cgroup subsys freezer
[    0.003213] Initializing cgroup subsys net_cls
[    0.003263] Initializing cgroup subsys blkio
[    0.003387] CPU: Testing write buffer coherency: ok
[    0.003502] ftrace: allocating 19476 entries in 58 pages
[    0.111287] Setting up static identity map for 0x55c8f8 - 0x55c954
[    0.114119] devtmpfs: initialized
[    0.131804] VFP support v0.3: implementor 41 architecture 1 part 20 variant b rev 5
[    0.134975] pinctrl core: initialized pinctrl subsystem
[    0.137561] NET: Registered protocol family 16
[    0.143094] DMA: preallocated 4096 KiB pool for atomic coherent allocations
[    0.171058] cpuidle: using governor ladder
[    0.201120] cpuidle: using governor menu
[    0.201635] bcm2708.uart_clock = 3000000
[    0.204744] No ATAGs?
[    0.204808] hw-breakpoint: found 6 breakpoint and 1 watchpoint registers.
[    0.204872] hw-breakpoint: maximum watchpoint size is 4 bytes.
[    0.204936] mailbox: Broadcom VideoCore Mailbox driver
[    0.205100] bcm2708_vcio: mailbox at f200b880
[    0.205244] bcm_power: Broadcom power driver
[    0.205291] bcm_power_open() -> 0
[    0.205321] bcm_power_request(0, 8)
[    0.706070] bcm_mailbox_read -> 00000080, 0
[    0.706118] bcm_power_request -> 0
[    0.706314] Serial: AMBA PL011 UART driver
[    0.706548] dev:f1: ttyAMA0 at MMIO 0x20201000 (irq = 83, base_baud = 0) is a PL011 rev3
[    1.100981] console [ttyAMA0] enabled
[    1.174063] SCSI subsystem initialized
[    1.178165] usbcore: registered new interface driver usbfs
[    1.183985] usbcore: registered new interface driver hub
[    1.189490] usbcore: registered new device driver usb
[    1.196691] Switched to clocksource stc
[    1.228389] FS-Cache: Loaded
[    1.231704] CacheFiles: Loaded
[    1.251999] NET: Registered protocol family 2
[    1.257961] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
[    1.265140] TCP bind hash table entries: 4096 (order: 2, 16384 bytes)
[    1.271925] TCP: Hash tables configured (established 4096 bind 4096)
[    1.278443] TCP: reno registered
[    1.281713] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    1.287641] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    1.294341] NET: Registered protocol family 1
[    1.299428] RPC: Registered named UNIX socket transport module.
[    1.305398] RPC: Registered udp transport module.
[    1.310240] RPC: Registered tcp transport module.
[    1.314972] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.322690] bcm2708_dma: DMA manager at f2007000
[    1.327722] vc-mem: phys_addr:0x00000000 mem_base=0x1ec00000 mem_size:0x20000000(512 MiB)
[    1.337670] futex hash table entries: 256 (order: -1, 3072 bytes)
[    1.343941] audit: initializing netlink subsys (disabled)
[    1.349654] audit: type=2000 audit(1.100:1): initialized
[    1.370529] VFS: Disk quotas dquot_6.5.2
[    1.374867] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    1.384394] FS-Cache: Netfs 'nfs' registered for caching
[    1.391568] NFS: Registering the id_resolver key type
[    1.396884] Key type id_resolver registered
[    1.401099] Key type id_legacy registered
[    1.406560] msgmni has been set to 869
[    1.412973] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    1.420993] io scheduler noop registered
[    1.424978] io scheduler deadline registered (default)
[    1.430715] io scheduler cfq registered
[    1.437339] BCM2708FB: allocated DMA memory 5bc00000
[    1.442409] BCM2708FB: allocated DMA channel 0 @ f2007000
[    1.473055] Console: switching to colour frame buffer device 228x61
[    1.498788] bcm2708-dmaengine bcm2708-dmaengine: Load BCM2835 DMA engine driver
[    1.506854] uart-pl011 dev:f1: no DMA platform data
[    1.512675] vc-cma: Videocore CMA driver
[    1.516879] vc-cma: vc_cma_base      = 0x00000000
[    1.521706] vc-cma: vc_cma_size      = 0x00000000 (0 MiB)
[    1.527338] vc-cma: vc_cma_initial   = 0x00000000 (0 MiB)
[    1.547180] brd: module loaded
[    1.558029] loop: module loaded
[    1.561762] vchiq: vchiq_init_state: slot_zero = 0xdb800000, is_master = 0
[    1.570138] Loading iSCSI transport class v2.0-870.
[    1.576868] usbcore: registered new interface driver smsc95xx
[    1.583112] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    1.789445] Core Release: 2.80a
[    1.792719] Setting default values for core params
[    1.797772] Finished setting default values for core params
[    2.003690] Using Buffer DMA mode
[    2.007164] Periodic Transfer Interrupt Enhancement - disabled
[    2.013136] Multiprocessor Interrupt Enhancement - disabled
[    2.018869] OTG VER PARAM: 0, OTG VER FLAG: 0
[    2.023343] Dedicated Tx FIFOs mode
[    2.027416] WARN::dwc_otg_hcd_init:1047: FIQ DMA bounce buffers: virt = 0xdbc14000 dma = 0x5bc14000 len=9024
[    2.037560] FIQ FSM acceleration enabled for :
[    2.037560] Non-periodic Split Transactions
[    2.037560] Periodic Split Transactions
[    2.037560] High-Speed Isochronous Endpoints
[    2.054741] dwc_otg: Microframe scheduler enabled
[    2.054912] WARN::hcd_init:473: FIQ at 0xc0400a24
[    2.065113] WARN::hcd_init:474: FIQ ASM at 0xc0400cfc length 36
[    2.076407] WARN::hcd_init:500: MPHI regs_base at 0xdc806000
[    2.087234] dwc_otg bcm2708_usb: DWC OTG Controller
[    2.097477] dwc_otg bcm2708_usb: new USB bus registered, assigned bus number 1
[    2.110137] dwc_otg bcm2708_usb: irq 32, io mem 0x00000000
[    2.120825] Init: Port Power? op_state=1
[    2.130042] Init: Power Port (0)
[    2.138990] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    2.151265] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.163881] usb usb1: Product: DWC OTG Controller
[    2.173907] usb usb1: Manufacturer: Linux 3.18.5+ dwc_otg_hcd
[    2.184898] usb usb1: SerialNumber: bcm2708_usb
[    2.195898] hub 1-0:1.0: USB hub found
[    2.205094] hub 1-0:1.0: 1 port detected
[    2.215058] dwc_otg: FIQ enabled
[    2.215085] dwc_otg: NAK holdoff enabled
[    2.215098] dwc_otg: FIQ split-transaction FSM enabled
[    2.215163] Module dwc_common_port init
[    2.215816] usbcore: registered new interface driver usb-storage
[    2.227818] mousedev: PS/2 mouse device common for all mice
[    2.239604] bcm2835-cpufreq: min=700000 max=700000
[    2.250362] sdhci: Secure Digital Host Controller Interface driver
[    2.261929] sdhci: Copyright(c) Pierre Ossman
[    2.271713] DMA channels allocated for the MMC driver
[    2.316781] Load BCM2835 MMC driver
[    2.331254] sdhci-pltfm: SDHCI platform and OF driver helper
[    2.350706] ledtrig-cpu: registered to indicate activity on CPUs
[    2.362406] hidraw: raw HID events driver (C) Jiri Kosina
[    2.376761] usbcore: registered new interface driver usbhid
[    2.389630] usbhid: USB HID core driver
[    2.401417] TCP: cubic registered
[    2.411491] Indeed it is in host mode hprt0 = 00021501
[    2.424006] Initializing XFRM netlink socket
[    2.446855] NET: Registered protocol family 17
[    2.457035] Key type dns_resolver registered
[    2.473343] mmc0: host does not support reading read-only switch, assuming write-enable
[    2.498564] registered taskstats version 1
[    2.517234] vc-sm: Videocore shared memory driver
[    2.527782] mmc0: new high speed SDHC card at address 0007
[    2.546787] [vc_sm_connected_init]: start
[    2.566845] mmcblk0: mmc0:0007 SD8GB 7.42 GiB 
[    2.579315] [vc_sm_connected_init]: end - returning 0
[    2.590437]  mmcblk0: p1 p2
[    2.630942] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    2.645141] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    2.659651] devtmpfs: mounted
[    2.669330] Freeing unused kernel memory: 340K (c07a7000 - c07fc000)
[    2.696903] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    2.709582] Indeed it is in host mode hprt0 = 00001101
[    2.927400] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
[    2.939831] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    2.954401] hub 1-1:1.0: USB hub found
[    2.965038] hub 1-1:1.0: 5 ports detected
[    3.257234] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    3.387483] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[    3.408612] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.427754] smsc95xx v1.0.4
[    3.503670] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-bcm2708_usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:39:4e:21
[    3.617035] usb 1-1.2: new low-speed USB device number 4 using dwc_otg
[    3.744260] usb 1-1.2: New USB device found, idVendor=046d, idProduct=c018
[    3.767621] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    3.789276] usb 1-1.2: Product: USB Optical Mouse
[    3.805242] usb 1-1.2: Manufacturer: Logitech
[    3.833914] input: Logitech USB Optical Mouse as /devices/platform/bcm2708_usb/usb1/1-1/1-1.2/1-1.2:1.0/0003:046D:C018.0001/input/input0
[    3.855465] hid-generic 0003:046D:C018.0001: input,hidraw0: USB HID v1.11 Mouse [Logitech USB Optical Mouse] on usb-bcm2708_usb-1.2/input0
[    4.117189] usb 1-1.3: new low-speed USB device number 5 using dwc_otg
[    4.270704] usb 1-1.3: New USB device found, idVendor=045e, idProduct=009d
[    4.296993] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    4.326322] usb 1-1.3: Product: Microsoft Wireless Optical Desktop\xffffffc2\xffffffae\xffffffae 2.10
[    4.354791] usb 1-1.3: Manufacturer: Microsoft
[    4.647235] usb 1-1.5: new high-speed USB device number 6 using dwc_otg
[    4.761830] udevd[158]: starting version 175
[    4.787363] usb 1-1.5: New USB device found, idVendor=8564, idProduct=4000
[    4.822461] usb 1-1.5: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    4.856935] usb 1-1.5: Product: USB2.0 Hub
[    4.890417] usb 1-1.5: Manufacturer: Transcend
[    4.920048] hub 1-1.5:1.0: USB hub found
[    4.957035] hub 1-1.5:1.0: 4 ports detected
[    5.287832] usb 1-1.5.2: new high-speed USB device number 7 using dwc_otg
[    5.408179] usb 1-1.5.2: New USB device found, idVendor=2537, idProduct=1068
[    5.446947] usb 1-1.5.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    5.496958] usb 1-1.5.2: Product: NS1068
[    5.526923] usb 1-1.5.2: Manufacturer: Norelsys
[    5.556917] usb 1-1.5.2: SerialNumber: 0123456789ABCDE
[    5.592224] usb-storage 1-1.5.2:1.0: USB Mass Storage device detected
[    5.647044] scsi host0: usb-storage 1-1.5.2:1.0
[    5.757505] usb 1-1.5.4: new high-speed USB device number 8 using dwc_otg
[    5.888236] usb 1-1.5.4: New USB device found, idVendor=2537, idProduct=1066
[    5.927005] usb 1-1.5.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    5.966909] usb 1-1.5.4: Product: NS1066
[    6.007013] usb 1-1.5.4: Manufacturer: Norelsys
[    6.037053] usb 1-1.5.4: SerialNumber: 0123456789ABCDE
[    6.071937] usb-storage 1-1.5.4:1.0: USB Mass Storage device detected
[    6.127431] scsi host1: usb-storage 1-1.5.4:1.0
[    6.619889] usbcore: registered new interface driver uas
[    7.933893] input: Microsoft Microsoft Wireless Optical Desktop\xffffffc2\xffffffae\xffffffae 2.10 as /devices/platform/bcm2708_usb/usb1/1-1/1-1.3/1-1.3:1.0/0003:045E:009D.0002/input/input1
[    8.204413] scsi 0:0:0:0: Direct-Access     ATA      WDC WD5000LPVT-0 1A01 PQ: 0 ANSI: 6
[    8.234695] sd 0:0:0:0: [sda] 976773168 512-byte logical blocks: (500 GB/465 GiB)
[    8.264555] sd 0:0:0:0: [sda] Write Protect is off
[    8.290614] sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00
[    8.291629] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[    8.308739] microsoft 0003:045E:009D.0002: input,hidraw1: USB HID v1.11 Keyboard [Microsoft Microsoft Wireless Optical Desktop\xffffffc2\xffffffae\xffffffae 2.10] on usb-bcm2708_usb-1.3/input0
[    8.685652] scsi 1:0:0:0: Direct-Access     NORELSYS 106X             1C   PQ: 0 ANSI: 6
[    8.716642] input: Microsoft Microsoft Wireless Optical Desktop\xffffffc2\xffffffae\xffffffae 2.10 as /devices/platform/bcm2708_usb/usb1/1-1/1-1.3/1-1.3:1.1/0003:045E:009D.0003/input/input2
[    8.741224] sd 1:0:0:0: [sdb] 976773168 512-byte logical blocks: (500 GB/465 GiB)
[    8.758748] sd 1:0:0:0: [sdb] Write Protect is off
[    8.787000] sd 1:0:0:0: [sdb] Mode Sense: 43 00 00 00
[    8.788025] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[    8.957960] microsoft 0003:045E:009D.0003: input,hidraw2: USB HID v1.11 Mouse [Microsoft Microsoft Wireless Optical Desktop\xffffffc2\xffffffae\xffffffae 2.10] on usb-bcm2708_usb-1.3/input1
[    9.317102] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    9.397799] sd 1:0:0:0: Attached scsi generic sg1 type 0
[    9.803564] random: nonblocking pool is initialized
[   10.100864]  sda: sda1 sda2 < sda5 >
[   10.130787] sd 0:0:0:0: [sda] Attached SCSI disk
[   10.305753]  sdb: sdb1
[   10.341365] sd 1:0:0:0: [sdb] Attached SCSI disk
[   13.401277] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[   13.904700] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[   25.040344] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[   26.556616] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xC5E1
[   32.233069] Adding 102396k swap on /var/swap.  Priority:-1 extents:2 across:2134012k SSFS
[   33.159676] EXT4-fs (sda5): Ignoring removed nobh option
[   33.193807] EXT4-fs (sda5): barriers disabled
[   33.220421] EXT4-fs (sda5): warning: maximal mount count reached, running e2fsck is recommended
[   33.226166] EXT4-fs (sda5): mounted filesystem with writeback data mode. Opts: data=writeback,barrier=0,nobh,errors=remount-ro
[   36.867342] fuse init (API version 7.23)
[ 1116.317108] sd 1:0:0:0: [sdb]  
[ 1116.317199] Result: hostbyte=0x07 driverbyte=0x00
[ 1116.317220] sd 1:0:0:0: [sdb] CDB: 
[ 1116.317233] cdb[0]=0x28: 28 00 13 7b 13 08 00 00 f0 00
[ 1116.317297] blk_update_request: I/O error, dev sdb, sector 326832904
[ 1116.416456] usb 1-1.5.4: USB disconnect, device number 8
[ 1116.417966] sd 1:0:0:0: [sdb]  
[ 1116.418006] Result: hostbyte=0x07 driverbyte=0x00
[ 1116.418025] sd 1:0:0:0: [sdb] CDB: 
[ 1116.418038] cdb[0]=0x28: 28 00 13 7b 13 f8 00 00 10 00
[ 1116.418095] blk_update_request: I/O error, dev sdb, sector 326833144
[ 1116.437068] sd 1:0:0:0: [sdb]  
[ 1116.437110] Result: hostbyte=0x01 driverbyte=0x00
[ 1116.437138] sd 1:0:0:0: [sdb] CDB: 
[ 1116.437153] cdb[0]=0x28: 28 00 13 7b 14 08 00 00 f0 00
[ 1116.437210] blk_update_request: I/O error, dev sdb, sector 326833160
[ 1116.437477] sd 1:0:0:0: [sdb]  
[ 1116.437503] Result: hostbyte=0x01 driverbyte=0x00
[ 1116.437523] sd 1:0:0:0: [sdb] CDB: 
[ 1116.437535] cdb[0]=0x28: 28 00 13 7b 14 f8 00 00 10 00
[ 1116.437586] blk_update_request: I/O error, dev sdb, sector 326833400
[ 1116.837726] usb 1-1.5.4: new high-speed USB device number 9 using dwc_otg
[ 1116.938716] usb 1-1.5.4: New USB device found, idVendor=2537, idProduct=1066
[ 1116.938756] usb 1-1.5.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1116.938774] usb 1-1.5.4: Product: NS1066
[ 1116.938791] usb 1-1.5.4: Manufacturer: Norelsys
[ 1116.938808] usb 1-1.5.4: SerialNumber: 0123456789ABCDE
[ 1116.947231] usb-storage 1-1.5.4:1.0: USB Mass Storage device detected
[ 1116.957029] scsi host2: usb-storage 1-1.5.4:1.0
[ 1118.488809] scsi 2:0:0:0: Direct-Access     NORELSYS 106X             1C   PQ: 0 ANSI: 6
[ 1118.493957] sd 2:0:0:0: [sdc] 976773168 512-byte logical blocks: (500 GB/465 GiB)
[ 1118.494854] sd 2:0:0:0: [sdc] Write Protect is off
[ 1118.494893] sd 2:0:0:0: [sdc] Mode Sense: 43 00 00 00
[ 1118.495731] sd 2:0:0:0: [sdc] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[ 1118.509937] sd 2:0:0:0: Attached scsi generic sg1 type 0
[ 1118.611201]  sdc: sdc1
[ 1118.615762] sd 2:0:0:0: [sdc] Attached SCSI disk
[ 1170.189495] Buffer I/O error on dev sdb1, logical block 15543735, async page read
[ 1170.327858] Buffer I/O error on dev sdb1, logical block 15543735, async page read
[ 1173.386466] Buffer I/O error on dev sdb1, logical block 15543735, async page read
[ 1173.478796] Buffer I/O error on dev sdb1, logical block 15543735, async page read
[ 1176.531657] Buffer I/O error on dev sdb1, logical block 15543735, async page read
[ 1176.624954] Buffer I/O error on dev sdb1, logical block 15543735, async page read
[ 1179.680094] Buffer I/O error on dev sdb1, logical block 87877518, async page read
[ 1179.777933] Buffer I/O error on dev sdb1, logical block 87877518, async page read
[ 1181.891037] Buffer I/O error on dev sdb1, logical block 87877518, async page read
[ 1181.911066] Buffer I/O error on dev sdb1, logical block 87877518, async page read
[ 1181.931217] Buffer I/O error on dev sdb1, logical block 87877518, async page read

[f18m]

LSUSB OUTPUT:

Bus 001 Device 002: ID 0424:9514 Standard Microsystems Corp. 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. 
Bus 001 Device 004: ID 046d:c018 Logitech, Inc. Optical Wheel Mouse
Bus 001 Device 005: ID 045e:009d Microsoft Corp. Wireless Optical Desktop 3.0
Bus 001 Device 006: ID 8564:4000  
Bus 001 Device 007: ID 2537:1068  
Bus 001 Device 009: ID 2537:1066  

[P33M]

Is there a firmware revision where this behaviour first started? I.e. can you identify which revision of firmware is the first bad one?

[f18m]

Unfortunately no. I have my raspberry only since a few days. Before buying the powered USB hub, it gave the same problem (back then it was using a raspbmc distribution with kernel 3.12 but the errors in dmesg were similar/identical). Moreover, after /dev/sd node recreation I could also hear the typical noise of the external hard drive having problems starting up... for this reason I thought the problems were due to insufficient power and thus I bought the USB hub.

Now the problem in dmesg is similar/identical but it doesn't really seem a power issue: the hard disk stay on even when attached just to the USB hub and additionally, after the /dev/sd node recreation the hard disk emits no noise...

An additional thing: both the hard disk work just fine under Windows (and also under Linux on my workstation) even under heavy load... I think it must be something with dwc_otg driver...

[f18m]

Another note: I also tried to power everything from the USB hub (15W should be enough for the 2 external HDD and the raspberry) using a micro USB cable that goes from the hub to the raspberry micro-USB connection. The same problem happens.

Moreover, it also happens apparently randomly even when writing small files on the disk periodically (I have a script that writes 512B every 30 seconds)... for example just now I see:

(....all init messages.....)
[   38.667175] fuse init (API version 7.23)
[19013.716559] sd 0:0:0:0: [sda]
[19013.716599] Result: hostbyte=0x07 driverbyte=0x00
[19013.716618] sd 0:0:0:0: [sda] CDB:
[19013.716631] cdb[0]=0x28: 28 00 04 27 27 7c 00 00 f0 00
[19013.716688] blk_update_request: I/O error, dev sda, sector 69674876
[19013.806554] sd 0:0:0:0: [sda]
[19013.806596] Result: hostbyte=0x07 driverbyte=0x00
[19013.806615] sd 0:0:0:0: [sda] CDB:
[19013.806628] cdb[0]=0x28: 28 00 04 27 28 6c 00 00 10 00
[19013.806682] blk_update_request: I/O error, dev sda, sector 69675116
[19013.865329] usb 1-1.5.2: USB disconnect, device number 7
[19013.866655] sd 0:0:0:0: [sda]
[19013.866691] Result: hostbyte=0x01 driverbyte=0x00
[19013.866712] sd 0:0:0:0: [sda] CDB:
[19013.866724] cdb[0]=0x28: 28 00 04 27 28 7c 00 00 f0 00
[19013.866779] blk_update_request: I/O error, dev sda, sector 69675132
[19013.866944] sd 0:0:0:0: [sda]
[19013.866970] Result: hostbyte=0x01 driverbyte=0x00
[19013.866988] sd 0:0:0:0: [sda] CDB:
[19013.866998] cdb[0]=0x28: 28 00 04 27 29 6c 00 00 10 00
[19013.867047] blk_update_request: I/O error, dev sda, sector 69675372

that is, in idle conditions, after from second 38 to second 19013 no problem, then suddenly the USB failure.

[f18m]

Tried with another hard disk (again, over USB). I left it idle (mounted on the filesystem but without read/writes from userspace) for ~3days: no problem. Then I started writing/reading:

[90665.519028] sd 0:0:0:0: [sda]
[90665.519069] Result: hostbyte=0x07 driverbyte=0x00
[90665.519088] sd 0:0:0:0: [sda] CDB:
[90665.519101] cdb[0]=0x28: 28 00 27 25 b9 38 00 00 f0 00
[90665.519167] blk_update_request: I/O error, dev sda, sector 656783672
[90665.618980] sd 0:0:0:0: [sda]
[90665.619022] Result: hostbyte=0x07 driverbyte=0x00
[90665.619041] sd 0:0:0:0: [sda] CDB:
[90665.619053] cdb[0]=0x28: 28 00 27 25 ba 28 00 00 10 00
[90665.619110] blk_update_request: I/O error, dev sda, sector 656783912
[90665.628528] usb 1-1.5.3: USB disconnect, device number 7
[90665.639075] sd 0:0:0:0: [sda]
[90665.639117] Result: hostbyte=0x01 driverbyte=0x00
[90665.639136] sd 0:0:0:0: [sda] CDB:
[90665.639151] cdb[0]=0x28: 28 00 27 25 ba 38 00 00 f0 00
[90665.639209] blk_update_request: I/O error, dev sda, sector 656783928
[90665.639486] EXT4-fs warning (device sda5): ext4_end_bio:317: I/O error -5 writing to inode 2616323 (offset 173670400 size 32768 starting block 119737000)
[90665.639525] Buffer I/O error on device sda5, logical block 5320096
[90665.639549] Buffer I/O error on device sda5, logical block 5320097
[90665.639569] Buffer I/O error on device sda5, logical block 5320098
[90665.639587] Buffer I/O error on device sda5, logical block 5320099
[90665.639605] Buffer I/O error on device sda5, logical block 5320100
[90665.639621] Buffer I/O error on device sda5, logical block 5320101
[90665.639638] Buffer I/O error on device sda5, logical block 5320102
[90665.639657] Buffer I/O error on device sda5, logical block 5320103
[90665.639711] EXT4-fs warning (device sda5): ext4_end_bio:317: I/O error -5 writing to inode 2616323 (offset 175374336 size 32768 starting block 119737416)
[90665.639736] Buffer I/O error on device sda5, logical block 5320512
[90665.639757] Buffer I/O error on device sda5, logical block 5320513
[90665.639823] EXT4-fs warning (device sda5): ext4_end_bio:317: I/O error -5 writing to inode 2616323 (offset 196313088 size 32768 starting block 119742528)
[90665.639899] EXT4-fs warning (device sda5): ext4_end_bio:317: I/O error -5 writing to inode 2616323 (offset 223379456 size 32768 starting block 119749136)

By the way I'm a C/C++ developer... if you could point me to the right point of the code writing those

"sd 0:0:0:0: [sda]\nResult: hostbyte=0x07 driverbyte=0x00"

I could help you with understanding the failure reason perhaps (althought I don't know much about USB driver routines!)...

[f18m]

Actually I found that this bug is possibly related to the following long-standing issue in Linux kernel:

https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=625922

[MeeGeeVee]

I have a similar issue

Running crashplan on a raspberry pi

Raspberry PI B with own powersupply - booting from SDCard Seagate Expansion 2TB USB hard drive 1 - Powered by RPI NTFS partition was reformatted and did a full scandisk in windows (without errors : chkdsk /F /R /X without error)

USB drive disconnecting as device 4 and reconnecting as 5 First on Linux RPI 3.12.28+ Now on Linux version 3.18.8+

Details: First running on : Linux RPI 3.12.28+ #709 PREEMPT Mon Sep 8 15:28:00 BST 2014 armv6l

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 3.12.28+ (dc4@dc4-XPS13-9333) (gcc version 4.8.3 20140303 (prerelease) (crosstool-NG linaro-1.13.1+bzr2650 - Linaro GCC 2014.03) ) #709 PREEMPT Mon Sep 8 15:28:00 BST 2014
 ...
    2.395822] Freeing unused kernel memory: 140K (c05bd000 - c05e0000)
[    2.428097] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    2.436572] Indeed it is in host mode hprt0 = 00001101
[    2.648426] usb 1-1: New USB device found, idVendor=0424, idProduct=9512
[    2.657030] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    2.666672] hub 1-1:1.0: USB hub found
[    2.672437] hub 1-1:1.0: 3 ports detected
[    2.958257] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    3.078587] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[    3.087064] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.114979] smsc95xx v1.0.4
[    3.183817] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-bcm2708_usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:4e:3e:35
[    3.308275] usb 1-1.3: new high-speed USB device number 4 using dwc_otg
[    3.421303] usb 1-1.3: New USB device found, idVendor=0bc2, idProduct=2312
[    3.437809] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    3.455266] usb 1-1.3: Product: Expansion
[    3.468109] usb 1-1.3: Manufacturer: Seagate 
[    3.474056] usb 1-1.3: SerialNumber: NA49AKKC
[    3.494274] usb-storage 1-1.3:1.0: USB Mass Storage device detected
[    3.516889] scsi0 : usb-storage 1-1.3:1.0
[    3.973285] udevd[156]: starting version 175
[    4.751726] scsi 0:0:0:0: Direct-Access     Seagate  Expansion        0636 PQ: 0 ANSI: 6
[    4.789472] sd 0:0:0:0: [sda] 3907029167 512-byte logical blocks: (2.00 TB/1.81 TiB)
[    4.818478] sd 0:0:0:0: [sda] Write Protect is off
[    4.824932] sd 0:0:0:0: [sda] Mode Sense: 2b 00 10 08
[    4.838110] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, supports DPO and FUA
[    4.891840]  sda: sda1 sda2 sda3 sda4
[    4.915313] sd 0:0:0:0: [sda] Attached SCSI disk
[    5.078484] bcm2708_spi bcm2708_spi.0: master is unqueued, this is deprecated
[    5.258377] bcm2708_spi bcm2708_spi.0: SPI Controller at 0x20204000 (irq 80)
[    6.139475] bcm2708-i2s bcm2708-i2s.0: Failed to create debugfs directory
...
[31672.472087] usb 1-1.3: USB disconnect, device number 4
[31672.479681] sd 0:0:0:0: [sda] Unhandled error code
[31672.479722] sd 0:0:0:0: [sda]  
[31672.479736] Result: hostbyte=0x01 driverbyte=0x00
[31672.479749] sd 0:0:0:0: [sda] CDB: 
[31672.479760] cdb[0]=0x2a: 2a 00 24 0b cb 98 00 00 f0 00
[31672.479805] end_request: I/O error, dev sda, sector 604752792
[31672.479827] Buffer I/O error on device sda1, logical block 75593843
[31672.479840] lost page write due to I/O error on sda1
[31672.479871] Buffer I/O error on device sda1, logical block 75593844
[31672.479884] lost page write due to I/O error on sda1
[31672.479903] Buffer I/O error on device sda1, logical block 75593845
[31672.479915] lost page write due to I/O error on sda1
[31672.479933] Buffer I/O error on device sda1, logical block 75593846
[31672.479944] lost page write due to I/O error on sda1
[31672.479964] Buffer I/O error on device sda1, logical block 75593847
[31672.479976] lost page write due to I/O error on sda1
[31672.479994] Buffer I/O error on device sda1, logical block 75593848
[31672.480006] lost page write due to I/O error on sda1
[31672.480023] Buffer I/O error on device sda1, logical block 75593849
[31672.480034] lost page write due to I/O error on sda1
[31672.480051] Buffer I/O error on device sda1, logical block 75593850
[31672.480063] lost page write due to I/O error on sda1
[31672.480081] Buffer I/O error on device sda1, logical block 75593851
[31672.480094] lost page write due to I/O error on sda1
[31672.480112] Buffer I/O error on device sda1, logical block 75593852
[31672.480123] lost page write due to I/O error on sda1
[31672.488629] sd 0:0:0:0: [sda] Unhandled error code
[31672.488669] sd 0:0:0:0: [sda]  
[31672.488683] Result: hostbyte=0x01 driverbyte=0x00
[31672.488700] sd 0:0:0:0: [sda] CDB: 
[31672.488710] cdb[0]=0x2a: 2a 00 24 0b cc 88 00 00 f0 00
[31672.488759] end_request: I/O error, dev sda, sector 604753032
[31672.641346] end_request: I/O error, dev sda, sector 0
[31673.423312] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[31673.423571] sd 0:0:0:0: [sda]  
[31673.423652] Result: hostbyte=0x01 driverbyte=0x00
[31673.665251] usb 1-1.3: new high-speed USB device number 5 using dwc_otg
[31673.769460] usb 1-1.3: New USB device found, idVendor=0bc2, idProduct=2312
[31673.769498] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[31673.769515] usb 1-1.3: Product: Expansion
[31673.769528] usb 1-1.3: Manufacturer: Seagate 
[31673.769541] usb 1-1.3: SerialNumber: NA49AKKC
[31673.773335] usb-storage 1-1.3:1.0: USB Mass Storage device detected
[31673.785103] scsi1 : usb-storage 1-1.3:1.0
[31674.960786] scsi 1:0:0:0: Direct-Access     Seagate  Expansion        0636 PQ: 0 ANSI: 6
[31674.964487] sd 1:0:0:0: Attached scsi generic sg0 type 0
[31674.965575] sd 1:0:0:0: [sdb] 3907029167 512-byte logical blocks: (2.00 TB/1.81 TiB)
[31674.967022] sd 1:0:0:0: [sdb] Write Protect is off
[31674.967066] sd 1:0:0:0: [sdb] Mode Sense: 2b 00 10 08
[31674.968097] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, supports DPO and FUA
[31674.990402]  sdb: sdb1 sdb2 sdb3 sdb4
[31674.994879] sd 1:0:0:0: [sdb] Attached SCSI disk
[31683.364606] quiet_error: 50 callbacks suppressed
[31683.364643] Buffer I/O error on device sda1, logical block 61321656
[31683.395719] Buffer I/O error on device sda1, logical block 61321656
[31683.400650] Buffer I/O error on device sda1, logical block 61321656
[31683.401815] Buffer I/O error on device sda1, logical block 61321656
[31683.403078] Buffer I/O error on device sda1, logical block 61321656
[31683.405692] Buffer I/O error on device sda1, logical block 61321656
[31683.406435] Buffer I/O error on device sda1, logical block 61321656
[31683.426127] Buffer I/O error on device sda1, logical block 61321656
[31683.427185] Buffer I/O error on device sda1, logical block 61321656
[31683.429573] Buffer I/O error on device sda1, logical block 61321656
[31690.220191] quiet_error: 6 callbacks suppressed
[31690.220229] Buffer I/O error on device sda1, logical block 61321656

Did an RpI-update to get lastest firmware Linux version 3.18.8+

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 3.18.8+ (dc4@dc4-XPS13-9333) (gcc version 4.8.3 20140303 (prerelease) (crosstool-NG linaro-1.13.1+bzr2650 - Linaro GCC 2014.03) ) #763 PREEMPT Sat Feb 28 18:24:36 GMT 2015
[    0.000000] CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
[    0.000000] Machine model: Raspberry Pi Model B
...
[    2.032382] dwc_otg bcm2708_usb: DWC OTG Controller
[    2.038970] dwc_otg bcm2708_usb: new USB bus registered, assigned bus number 1
[    2.047948] dwc_otg bcm2708_usb: irq 32, io mem 0x00000000
[    2.055128] Init: Port Power? op_state=1
[    2.060635] Init: Power Port (0)
[    2.065807] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    2.074242] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.083127] usb usb1: Product: DWC OTG Controller
[    2.089468] usb usb1: Manufacturer: Linux 3.18.8+ dwc_otg_hcd
[    2.096848] usb usb1: SerialNumber: bcm2708_usb
[    2.103972] hub 1-0:1.0: USB hub found
[    2.109565] hub 1-0:1.0: 1 port detected
[    2.115740] dwc_otg: FIQ enabled
[    2.115766] dwc_otg: NAK holdoff enabled
[    2.115779] dwc_otg: FIQ split-transaction FSM enabled
[    2.115837] Module dwc_common_port init
[    2.116395] usbcore: registered new interface driver usb-storage
[    2.124441] mousedev: PS/2 mouse device common for all mice
[    2.132551] bcm2835-cpufreq: min=700000 max=700000
[    2.139409] sdhci: Secure Digital Host Controller Interface driver
[    2.147315] sdhci: Copyright(c) Pierre Ossman
[    2.153533] DMA channels allocated for the MMC driver
[    2.194628] Load BCM2835 MMC driver
[    2.201659] sdhci-pltfm: SDHCI platform and OF driver helper
[    2.217379] ledtrig-cpu: registered to indicate activity on CPUs
[    2.225450] hidraw: raw HID events driver (C) Jiri Kosina
[    2.237085] usbcore: registered new interface driver usbhid
[    2.246444] usbhid: USB HID core driver
[    2.254441] TCP: cubic registered
[    2.260642] Initializing XFRM netlink socket
[    2.268795] NET: Registered protocol family 17
[    2.275188] Key type dns_resolver registered
[    2.282817] registered taskstats version 1
[    2.288915] vc-sm: Videocore shared memory driver
[    2.295360] [vc_sm_connected_init]: start
[    2.302188] [vc_sm_connected_init]: end - returning 0
[    2.310790] Waiting for root device /dev/mmcblk0p2...
[    2.317968] Indeed it is in host mode hprt0 = 00021501
[    2.329261] mmc0: host does not support reading read-only switch, assuming write-enable
[    2.356589] mmc0: new high speed SDHC card at address abdf
[    2.374679] mmcblk0: mmc0:abdf SE08G 7.28 GiB 
[    2.385865]  mmcblk0: p1 p2
[    2.449400] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    2.461059] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    2.471093] devtmpfs: mounted
[    2.477002] Freeing unused kernel memory: 340K (c0791000 - c07e6000)
[    2.524884] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    2.533390] Indeed it is in host mode hprt0 = 00001101
[    2.745259] usb 1-1: New USB device found, idVendor=0424, idProduct=9512
[    2.757886] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    2.772879] hub 1-1:1.0: USB hub found
[    2.781141] hub 1-1:1.0: 3 ports detected
[    3.065007] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    3.175373] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[    3.184344] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.214457] smsc95xx v1.0.4
[    3.295211] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-bcm2708_usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:4e:3e:35
[    3.404934] usb 1-1.3: new high-speed USB device number 4 using dwc_otg
[    3.536699] usb 1-1.3: New USB device found, idVendor=0bc2, idProduct=2312
[    3.554755] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    3.564121] usb 1-1.3: Product: Expansion
[    3.584802] usb 1-1.3: Manufacturer: Seagate 
[    3.591102] usb 1-1.3: SerialNumber: NA49AKKC
[    3.613659] usb 1-1.3: The driver for the USB controller dwc_otg_hcd does not support scatter-gather which is
[    3.643193] usb 1-1.3: required by the UAS driver. Please try an other USB controller if you wish to use UAS.
[    3.667239] usb-storage 1-1.3:1.0: USB Mass Storage device detected
[    3.689720] usb-storage 1-1.3:1.0: Quirks match for vid 0bc2 pid 2312: 2000000
[    3.713619] scsi host0: usb-storage 1-1.3:1.0
[    4.277697] udevd[160]: starting version 175
[    4.716141] scsi 0:0:0:0: Direct-Access     Seagate  Expansion        0636 PQ: 0 ANSI: 6
[    4.751315] sd 0:0:0:0: [sda] 3907029167 512-byte logical blocks: (2.00 TB/1.81 TiB)
[    4.782848] sd 0:0:0:0: [sda] Write Protect is off
[    4.810156] sd 0:0:0:0: [sda] Mode Sense: 2b 00 10 08
[    4.811154] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, supports DPO and FUA
[    4.941307] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    6.960562]  sda: sda1 sda2 sda3 sda4
[    6.985092] sd 0:0:0:0: [sda] Attached SCSI disk
[    7.604701] random: nonblocking pool is initialized
[   10.991558] Adding 1048572k swap on /dev/sda3.  Priority:-1 extents:1 across:1048572k FS
[   11.164822] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[   17.721979] FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[   17.845014] fuse init (API version 7.23)
[   23.100890] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[   24.521869] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0x4DE1
[22340.046505] usb 1-1.3: USB disconnect, device number 4
[22340.055841] sd 0:0:0:0: [sda]  
[22340.055876] Result: hostbyte=0x01 driverbyte=0x00
[22340.055894] sd 0:0:0:0: [sda] CDB: 
[22340.055907] cdb[0]=0x2a: 2a 00 27 dd 64 50 00 00 f0 00
[22340.055966] blk_update_request: I/O error, dev sda, sector 668820560
[22340.055991] Buffer I/O error on dev sda1, logical block 83602314, lost async page write
[22340.056035] Buffer I/O error on dev sda1, logical block 83602315, lost async page write
[22340.056063] Buffer I/O error on dev sda1, logical block 83602316, lost async page write
[22340.056092] Buffer I/O error on dev sda1, logical block 83602317, lost async page write
[22340.056120] Buffer I/O error on dev sda1, logical block 83602318, lost async page write
[22340.056145] Buffer I/O error on dev sda1, logical block 83602319, lost async page write
[22340.056169] Buffer I/O error on dev sda1, logical block 83602320, lost async page write
[22340.056194] Buffer I/O error on dev sda1, logical block 83602321, lost async page write
[22340.056222] Buffer I/O error on dev sda1, logical block 83602322, lost async page write
[22340.056247] Buffer I/O error on dev sda1, logical block 83602323, lost async page write
[22340.066347] sd 0:0:0:0: [sda]  
[22340.066388] Result: hostbyte=0x01 driverbyte=0x00
[22340.066407] sd 0:0:0:0: [sda] CDB: 
[22340.066420] cdb[0]=0x2a: 2a 00 27 dd 65 40 00 00 f0 00
[22340.066480] blk_update_request: I/O error, dev sda, sector 668820800
[22341.211466] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[22341.211804] sd 0:0:0:0: [sda]  
[22341.211830] Result: hostbyte=0x01 driverbyte=0x00
[22341.455565] usb 1-1.3: new high-speed USB device number 5 using dwc_otg
[22341.558879] usb 1-1.3: New USB device found, idVendor=0bc2, idProduct=2312
[22341.558921] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[22341.558942] usb 1-1.3: Product: Expansion
[22341.558959] usb 1-1.3: Manufacturer: Seagate 
[22341.558975] usb 1-1.3: SerialNumber: NA49AKKC
[22341.563203] usb 1-1.3: The driver for the USB controller dwc_otg_hcd does not support scatter-gather which is
[22341.563241] usb 1-1.3: required by the UAS driver. Please try an other USB controller if you wish to use UAS.
[22341.563265] usb-storage 1-1.3:1.0: USB Mass Storage device detected
[22341.569042] usb-storage 1-1.3:1.0: Quirks match for vid 0bc2 pid 2312: 2000000
[22341.572599] scsi host1: usb-storage 1-1.3:1.0
[22341.817079] usbcore: registered new interface driver uas
[22342.759341] scsi 1:0:0:0: Direct-Access     Seagate  Expansion        0636 PQ: 0 ANSI: 6
[22342.764744] sd 1:0:0:0: [sdb] 3907029167 512-byte logical blocks: (2.00 TB/1.81 TiB)
[22342.765235] sd 1:0:0:0: Attached scsi generic sg0 type 0
[22342.765735] sd 1:0:0:0: [sdb] Write Protect is off
[22342.765772] sd 1:0:0:0: [sdb] Mode Sense: 2b 00 10 08
[22342.766749] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, supports DPO and FUA
[22342.787645]  sdb: sdb1 sdb2 sdb3 sdb4
[22342.793223] sd 1:0:0:0: [sdb] Attached SCSI disk
[22348.173746] buffer_io_error: 60 callbacks suppressed
[22348.173789] Buffer I/O error on dev sda1, logical block 786449, async page read
[22348.174803] Buffer I/O error on dev sda1, logical block 786449, async page read
[22348.178741] Buffer I/O error on dev sda1, logical block 786449, async page read
[22348.180791] Buffer I/O error on dev sda1, logical block 786449, async page read
[22350.133189] Buffer I/O error on dev sda1, logical block 786449, async page read
[22350.134229] Buffer I/O error on dev sda1, logical block 786449, async page read
[22350.138038] Buffer I/O error on dev sda1, logical block 786449, async page read
[22350.140092] Buffer I/O error on dev sda1, logical block 786449, async page read
[22352.270635] Buffer I/O error on dev sda1, logical block 61321656, async page read
[22352.272957] Buffer I/O error on dev sda1, logical block 61321656, async page read
[22836.221680] buffer_io_error: 38 callbacks suppressed
[22836.221723] Buffer I/O error on dev sda1, logical block 242143488, async page read
[22836.254434] Buffer I/O error on dev sda1, logical block 61321656, async page read
[22836.255735] Buffer I/O error on dev sda1, logical block 61321656, async page read
[22836.263045] Buffer I/O error on dev sda1, logical block 786449, async page read

I'm not a linux guru, but trying my best to understand things , and solve where possible. All your assistance is more then welcome

[Razican]

I confirm that this happens with Raspbery Pi 2 B running: Linux 3.18.11-v7+ #777 SMP PREEMPT Sat Apr 11 17:30:37 BST 2015 armv7l GNU/Linux

I have a RAID attached via USB 3.0 (limited to 2.0 by RPi hardware) And it seems to happen under heavy traffic load. Is a 2x2TB in RAID 0 (total of 4TB drive). It fails when checking torrent downloads.

[MeeGeeVee]

In my case it was 100% power related.

I was able to test the drive and generate different load conditions with the command 'badblocks' and tuning of the parameters -d -c- b ( fe: sudo badblocks -e 100 -v /dev/sda1 -s -c 32 -d 50). As a result the drive failed on different blocks or not at all. This was an indication that the individual blocks were ok.

Changing the powersupply of the RPI (2A) did not help neither.

After buying a USB3 Y-cable to power the drive from another USB port, all got solved and my drive is still running fine for weeks now. http://www.ebay.com/sch/i.html?_from=R40&_nkw=usb3+y-cable

Hope this helps your case too.

[Razican]

In my case, the USB RAID is self-powered, so the power should not be any problem.

[MeeGeeVee]

Worth to try some badblocks tests to see if you can reproduce a failure? "sudo badblocks -e 100 -v /dev/sda1 -s" will test at maximum speed. If failure should occur each time in different blocks it would put the hard drive out of the scope.

[Razican]

After checking it with badblocks, after about 6 hours of checking it stopped after this error message:

[21989.512626] usb 1-1.5: reset high-speed USB device number 4 using dwc_otg
[21989.603287] usb 1-1.5: USB disconnect, device number 4
[21989.620170] scsi 0:0:0:0: rejecting I/O to offline device
[21989.625727] scsi 0:0:0:0: [sda] killing request
[21989.630473] scsi 0:0:0:0: [sda]  
[21989.633890] Result: hostbyte=0x01 driverbyte=0x00
[21989.638692] scsi 0:0:0:0: [sda] CDB: 
[21989.642420] cdb[0]=0x88: 88 00 00 00 00 00 50 d4 47 80 00 00 00 80 00 00
[21989.649557] blk_update_request: I/O error, dev sda, sector 1356089216
[21989.656584] Buffer I/O error on dev sda1, logical block 169478128, async page read
[21989.664568] Buffer I/O error on dev sda1, logical block 169478128, async page read
[21989.672388] Buffer I/O error on dev sda1, logical block 169478128, async page read
[21989.680280] Buffer I/O error on dev sda1, logical block 169478128, async page read
[21989.688367] Buffer I/O error on dev sda1, logical block 169478129, async page read
[21989.696346] Buffer I/O error on dev sda1, logical block 169478129, async page read
[21989.704281] Buffer I/O error on dev sda1, logical block 169478129, async page read
[21989.717096] Buffer I/O error on dev sda1, logical block 169478129, async page read
[21989.730112] Buffer I/O error on dev sda1, logical block 169478130, async page read
[21989.742960] Buffer I/O error on dev sda1, logical block 169478130, async page read
[21991.573600] usb 1-1.5: new high-speed USB device number 5 using dwc_otg
[21991.695072] usb 1-1.5: New USB device found, idVendor=152d, idProduct=0539
[21991.703942] usb 1-1.5: New USB device strings: Mfr=1, Product=2, SerialNumber=5
[21991.713205] usb 1-1.5: Product: USB to ATA/ATAPI Bridge
[21991.720824] usb 1-1.5: Manufacturer: JMicron
[21991.727026] usb 1-1.5: SerialNumber: 239C7E548FFF
[21991.738885] usb-storage 1-1.5:1.0: USB Mass Storage device detected
[21991.747727] scsi host1: usb-storage 1-1.5:1.0
[21992.754883] scsi 1:0:0:0: Direct-Access     Sharkoon  H/W RAID0            PQ: 0 ANSI: 5
[21992.767773] sd 1:0:0:0: Attached scsi generic sg0 type 0
[21992.778207] sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
[21992.788120] sd 1:0:0:0: [sdb] 7813857280 512-byte logical blocks: (4.00 TB/3.63 TiB)
[21992.800149] sd 1:0:0:0: [sdb] Write Protect is off
[21992.806690] sd 1:0:0:0: [sdb] Mode Sense: 28 00 00 00
[21992.807146] sd 1:0:0:0: [sdb] No Caching mode page found
[21992.814189] sd 1:0:0:0: [sdb] Assuming drive cache: write through
[21992.823579] sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
[21993.203112]  sdb: sdb1
[21993.209125] sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
[21993.221187] sd 1:0:0:0: [sdb] Attached SCSI disk
[28490.293973] buffer_io_error: 90 callbacks suppressed
[28490.301253] Buffer I/O error on dev sda1, logical block 36, async page read

The last two were me trying to do a ls in the mounted /dev/sda1, that now is called /dev/sdb1, so it won't work.

[f18m]

By the way I still haven't solved this problem. Just FYI: I see the same problem on both Raspberry PI model B+ and on my BeagleBone.

The hard disks triggering this problem are miscellaneous:

• WDC WD5000LPVT (500 GB) enclosed in USB3 enclosure (reports itself as Norelsys NS1068)
• Toshiba MQ01ABD050 (500 GB) enclosed in USB3 enclosure (reports itself as Norelsys NS106X)
• Toshiba MQ01UBD100 (1 TB) with its own Toshiba USB3 enclosure

It may help if you write down the manufacturers and model names of the hard disks that trigger this problem (the "Result: hostbyte=* driverbyte=*" error message). Thanks!

[f18m]

Another comment: on my desktop computer running Ubuntu Trusty 14.04 no problem are reported when transferring large files between the disks reported above.

[analyser-]

I'm not sure if it is related, however I'll share anyway, since it can help someone.

When I was assembling my rpi file server, with two external hard drives plugged into an usb hub, both in those cheap enclosures, I was not be able to use them till I've used a power source of 5.3 V (to the usb hub), instead 5.0 V. So, I strongly recommend trying a higher voltage power source.

[Blindfreddy]

I have the same error using a WD 2TB USB3 disk, refer https://www.google.de/url?url=https://github.com/raspberrypi/linux/issues/885&rct=j&q=&esrc=s&sa=U&ei=qz82VZIhwaewAYDNgKAN&ved=0CBoQFjAB&sig2=OFhTaepwrroA5QRZuaWnUQ&usg=AFQjCNEzwcQ-hGcApolnu3RnIxP6Et4JdA

HDD: DetailsHDD D iManufacturer 1 Western Digital iProduct 2 My Passport 0748

I actually have two Pi's, each with same model USB HDD. 1st on is a Model B, 2nd one a Model 2B. Works fine on the older Model B, but the problem occurs on the newer Model 2 B.

Kernel and Firmware on older Model B uname -a Linux rpi1 3.18.7+ #755 PREEMPT Thu Feb 12 17:14:31 GMT 2015 armv6l GNU/Linux sudo /opt/vc/bin/vcgencmd version Feb 14 2015 22:17:16 Copyright (c) 2012 Broadcom version 7789db485409720b0e523a3d6b86b12ed56fd152 (clean) (release)

Kernel and Firmware on newer Model 2 B uname -a Linux rpi4 3.18.11-v7+ #780 SMP PREEMPT Mon Apr 20 14:59:10 BST 2015 armv7l GNU/Linux

sudo /opt/vc/bin/vcgencmd version Apr 20 2015 15:02:24 Copyright (c) 2012 Broadcom version 423cbd6f9f4f6097643cb90ddfd2c2e4c01ef3fd (clean) (release)

[MeeGeeVee]

BlindFreddy : As stated before I'm not a specialist and my incident was power related. Reading your case I can only assist you to suggest some validations if your case isn't power related too. Interestiging in that you have 2 RPI and 2 drives.

• Are you able to change the drives from one RPI to each other.
• Are you able to switch the power supply from one RPI to another
• I believe Western Digital Passport drive gets the power from the USB, are you able to use a y-cable to power the failing drive externally (http://www.ebay.com/sch/i.html?_from=R40&_nkw=usb3+y-cable).
• Does 'sudo badblocks -e 100 -v /dev/sda1 -s' runs fine or fails each time at the same point ?

The result of the test should perhaps show it the issue remains related to HD, RPI/OS version or power supply .

[Razican]

I don't think it's a power related error, since it worked perfectly in Raspberry Pi B, but it's not working in Raspberry Pi 2 B. In any case, I might be able to try it again in Raspberry Pi B this weekend.

[Blindfreddy]

Yes, I can try it out using Pi B and Pi 2B and the two drives. I cannot try external power y-cable - don't have one and also, since it has the drive has been working flawelessly on Pi B using internal power for well over a year, I think it is reasonable to expect it to work on Pi 2B.

[popcornmix]

Pi2 can use more power that Pi1, so I don't think you can infer a power supply that is good for Pi1 is necessarily good for Pi2.

[Razican]

But in my case, the HDD RAID is self powered.

[pelwell]

FYI, Adafruit have released a tutorial on adding an external HDD to a Pi, and they say:

The Raspberry Pi doesn't have enough power to run most external hard drives or SSDs, so unless you have a drive with its own power supply, you'll probably need a powered USB hub.

[f18m]

In my case, I'm using a powered USB hub (certified for USB 3.0, so that the hub comes with a 15W power adapter)... all these issues make me feel that it's not really a power supply issue.

Perhaps to be sure the only way would be attaching an oscope to the USB lines and see directly if the signal strength over USB D+ and D- lines is good enough or not.

Honestly, I suspect some driver issue, either on Linux driver side or in the hard disk / USB adaptor firmware. Probably Windows is capable of handling such situation (indeed most vendors only test their hard drives with Windows only), but Linux no.

Just my 2cents, Francesco M.

2015-04-24 14:17 GMT+02:00 Phil Elwell notifications@github.com:

FYI, Adafruit have released a tutorial on adding an external HDD to a Pi, and they say:

The Raspberry Pi doesn't have enough power to run most external hard drives or SSDs, so unless you have a drive with its own power supply, you'll probably need a powered USB hub.

— Reply to this email directly or view it on GitHub https://github.com/raspberrypi/linux/issues/777#issuecomment-95914629.

[igniz-]

Hi all, I'm having this very same problem but not on a raspberry, just a regular intel computer. My HDD is attached to a SATA-to-USB adaptor and it shows this exact same behaviour. It actually started after an update to the system, including a Kernel update, so the problem must be there, since no hardware was changed, and I even tested two different linux distros (opensuse 13.2 & ubuntu 15.04) both does exaclty the same. Today I will try a regression to an older linux distro an see if the problem "solves" just to be sure of this. Hope this narrows the source of the problem a litte.

Regards!

[Razican]

I can confirm (almost 100% sure) that it is not power related. I have bought a 5V 2A PSU for the Raspberry Pi 2 and a powered USB hub to connect the storage there. As I said before the storage is self powered, so there is no doubt that all has enough power. But it continues to fail. This time after more than 2 hours of use, but it disconects the device and adds it as a new drive (even if UUID is the same).

In my change to the USB hub I also ran into #824. In any case I could do a workaround for that (changing the root delay, as said in the issue comments). The thing is that as we have seen, under heavy load, the device simply disapears from /dev.

Here is, again the dmesg:

[ 7991.378571] sd 0:0:0:0: [sda]  
[ 7991.381813] Result: hostbyte=0x00 driverbyte=0x08
[ 7991.386578] sd 0:0:0:0: [sda]  
[ 7991.389753] Sense Key : 0x3 [current] 
[ 7991.393605] sd 0:0:0:0: [sda]  
[ 7991.396781] ASC=0x3 ASCQ=0x0
[ 7991.399702] sd 0:0:0:0: [sda] CDB: 
[ 7991.403251] cdb[0]=0x88: 88 00 00 00 00 00 f5 d5 a1 f0 00 00 00 f0 00 00
[ 7991.410232] blk_update_request: I/O error, dev sda, sector 4124418544
[ 8022.335762] usb 1-1.5.4: reset high-speed USB device number 5 using dwc_otg
[ 8022.417011] usb 1-1.5.4: USB disconnect, device number 5
[ 8022.435619] sd 0:0:0:0: [sda]  
[ 8022.438833] Result: hostbyte=0x01 driverbyte=0x00
[ 8022.443595] sd 0:0:0:0: [sda] CDB: 
[ 8022.447166] cdb[0]=0x88: 88 00 00 00 00 00 f5 d5 a2 e0 00 00 00 10 00 00
[ 8022.454133] blk_update_request: I/O error, dev sda, sector 4124418784
[ 8022.465193] sd 0:0:0:0: [sda]  
[ 8022.468442] Result: hostbyte=0x01 driverbyte=0x00
[ 8022.473207] sd 0:0:0:0: [sda] CDB: 
[ 8022.476761] cdb[0]=0x88: 88 00 00 00 00 00 f5 d5 a2 f0 00 00 00 f0 00 00
[ 8022.483721] blk_update_request: I/O error, dev sda, sector 4124418800
[ 8024.296853] usb 1-1.5.4: new high-speed USB device number 6 using dwc_otg
[ 8024.330635] Buffer I/O error on dev sda1, logical block 539903643, async page read
[ 8024.341511] Buffer I/O error on dev sda1, logical block 539903643, async page read
[ 8024.352686] Buffer I/O error on dev sda1, logical block 539903643, async page read
[ 8024.363942] Buffer I/O error on dev sda1, logical block 539903643, async page read
[ 8024.375431] Buffer I/O error on dev sda1, logical block 539903643, async page read
[ 8024.387017] Buffer I/O error on dev sda1, logical block 539903643, async page read
[ 8024.398615] Buffer I/O error on dev sda1, logical block 539903643, async page read
[ 8024.410269] Buffer I/O error on dev sda1, logical block 539903643, async page read
[ 8024.418369] usb 1-1.5.4: New USB device found, idVendor=152d, idProduct=0539
[ 8024.418379] usb 1-1.5.4: New USB device strings: Mfr=1, Product=2, SerialNumber=5
[ 8024.418386] usb 1-1.5.4: Product: USB to ATA/ATAPI Bridge
[ 8024.418392] usb 1-1.5.4: Manufacturer: JMicron
[ 8024.418398] usb 1-1.5.4: SerialNumber: 239C7E548FFF
[ 8024.419830] usb-storage 1-1.5.4:1.0: USB Mass Storage device detected
[ 8024.420271] scsi host1: usb-storage 1-1.5.4:1.0
[ 8024.478674] Buffer I/O error on dev sda1, logical block 539903643, async page read
[ 8024.490996] Buffer I/O error on dev sda1, logical block 539903643, async page read
[ 8025.417797] scsi 1:0:0:0: Direct-Access     Sharkoon  H/W RAID0            PQ: 0 ANSI: 5
[ 8025.431029] sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
[ 8025.442048] sd 1:0:0:0: [sdb] 7813857280 512-byte logical blocks: (4.00 TB/3.63 TiB)
[ 8025.454605] sd 1:0:0:0: [sdb] Write Protect is off
[ 8025.461347] sd 1:0:0:0: [sdb] Mode Sense: 28 00 00 00
[ 8025.462178] sd 1:0:0:0: [sdb] No Caching mode page found
[ 8025.469414] sd 1:0:0:0: [sdb] Assuming drive cache: write through
[ 8025.479051] sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
[ 8025.494139] sd 1:0:0:0: Attached scsi generic sg0 type 0
[ 8025.968816]  sdb: sdb1
[ 8025.978257] sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
[ 8025.993777] sd 1:0:0:0: [sdb] Attached SCSI disk

[Blindfreddy]

Some news: I can no longer reproduce the error. I have not updated the config on the Model 2B, yet the problem is no longer occurring. I did fix some errors in the filesystem, so maybe that is the root cause of the buffer I/O errors. Here is what I did:

1. Attached USB HDD to 'old' Model B Pi (powered by Pi), then ran fsck without flags which reported clean fs (ext4).
2. Still connected to old Pi, ran fsck -v -f to generate I/O load - this was known to cause the buffer I/O errors on the new Model 2B Pi; as expected, no buffer I/O errors on the 'old' Model B, but interestingly, there were several problems with the fs despite it having previously reported to be clean....; fixed the errors, reran fsck -v -f, no errors. Refer details below.
3. Discconnected USB HDD and connected to 'new' Model 2B Pi and again ran fsck -v -f: no errors, no more buffer I/O errors.
4. Ran a very large rsync job (1TB data) across LAN from the 2nd, identical USB HDD connected to a third Pi (Model B), no errors. See attached dmesg output.

So I cannot reproduce the error anymore. Only change is to have a properly clean FS. Perhaps someone else can run fsck with -f and then try to reproduce the error.

fsck output from point 2. above:

fsck from util-linux 2.20.1 e2fsck 1.42.5 (29-Jul-2012) Pass 1: Checking inodes, blocks, and sizes Pass 2: Checking directory structure Entry '#34705188' in /lost+found (12) has deleted/unused inode 34705188. Clear? yes Pass 3: Checking directory connectivity Pass 4: Checking reference counts Pass 5: Checking group summary information Inode bitmap differences: -34705188 Fix? yes Free inodes count wrong for group #4236 (7628, counted=7629). Fix? yes Free inodes count wrong (98690663, counted=98690664). Fix? yes

/dev/sda1: * FILE SYSTEM WAS MODIFIED *

 7403928 inodes used (6.98%, out of 106094592)
  188820 non-contiguous files (2.6%)
    9418 non-contiguous directories (0.1%)
         # of inodes with ind/dind/tind blocks: 2999026/2997395/2997945
         Extent depth histogram: 1454181/9001/7

371609074 blocks used (87.57%, out of 424369023) 0 bad blocks 773 large files

 1527971 regular files
  214931 directories
 1452884 character device files
 1334802 block device files
 1533953 fifos
    2409 links
    9582 symbolic links (8937 fast symbolic links)
 1329796 sockets

---

 7406328 files

[Razican]

I tried to switch to my old Pi B and I got the same error. I get the same error with the powered USB hub.

[cageyz]

same problem with my Pi 2 B and WD disk(powered)

[cageyz]

I have solved this problem. The ns1066 chipset (used by orico 6518US3) has some compatibility issues so that when I changed the disk dock to orico 6518S3(which uses ASM1153E chipset), there is no disconnection anymore. Leave ns1066 far away from Raspberry PI.

[kursion]

For me it was a power issue. The RPi was power by my labtop. I couldn't mount my External HDD. Finally I used my Samsung charger and it worked instantly.

[popcornmix]

@f18m any change with latest 4.0 kernel? (from rpi-update)

[Ealdwulf]

I can reproduce this issue (Buffer I/O error on dev sda, logical block XXXX, async page read) by using dd to flash an sd card with one of these: http://www.amazon.co.uk/Integral-MicroSD-USB-Card-Reader/dp/B001JPPQS6 That's on kernel 3.18-ck1-v7. If I get a chance to check on v4, I'll update. It doesn't happen every time, but when it does the symptom is that dd slows to a crawl (20kb/s)

[mujss]

I had exactly the same problem. The setup was that the raspberry pi would connect to 2 external HDDs and the drives were shared over the network. Most often when data to the HDDs were read or written to, i would get these errors and the HDD would be no longer mounted. The fix then would be to reboot the pi. I had done lots of googling for a number of days and changed USB cables, changed powered USB hub, changed HDDs but no luck. What eventually worked for me was when i created a cron job on the pi to read the HDD every minute. And now 26 days later, i havent seen that happen again.

/1 * * * \ ls /media/USBHDD1/

[dcramps]

Seeing a very similar issue on one of my drives.

[ 741.577436] usb 1-1.5: USB disconnect, device number 6 [ 741.588838] sd 1:0:0:0: [sdb] UNKNOWN(0x2003) Result: hostbyte=0x01 driverbyte=0x00 [ 741.588876] sd 1:0:0:0: [sdb] CDB: opcode=0x28 28 00 39 5d 6a c0 00 00 f0 00 [ 741.588895] blk_update_request: I/O error, dev sdb, sector 962423488 [ 741.589075] sd 1:0:0:0: [sdb] UNKNOWN(0x2003) Result: hostbyte=0x01 driverbyte=0x00 [ 741.589094] sd 1:0:0:0: [sdb] CDB: opcode=0x28 28 00 39 5d 6b b0 00 00 10 00 [ 741.589105] blk_update_request: I/O error, dev sdb, sector 962423728 [ 741.996670] usb 1-1.5: new high-speed USB device number 8 using dwc_otg [ 742.024710] Buffer I/O error on dev sdb1, logical block 44, async page read [ 742.026325] Buffer I/O error on dev sdb1, logical block 44, async page read [ 742.027198] Buffer I/O error on dev sdb1, logical block 44, async page read [ 742.028831] Buffer I/O error on dev sdb1, logical block 44, async page read [ 742.029558] Buffer I/O error on dev sdb1, logical block 44, async page read [ 742.031026] Buffer I/O error on dev sdb1, logical block 44, async page read [ 742.031721] Buffer I/O error on dev sdb1, logical block 44, async page read [ 742.097779] usb 1-1.5: New USB device found, idVendor=2537, idProduct=1066 [ 742.097802] usb 1-1.5: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [ 742.097813] usb 1-1.5: Product: NS1066 [ 742.097824] usb 1-1.5: Manufacturer: Norelsys [ 742.097835] usb 1-1.5: SerialNumber: 0123456789ABCDE [ 742.098643] usb-storage 1-1.5:1.0: USB Mass Storage device detected [ 742.099025] scsi host3: usb-storage 1-1.5:1.0 [ 743.631380] scsi 3:0:0:0: Direct-Access NORELSYS 106X AB51 PQ: 0 ANSI: 6 [ 743.636549] sd 3:0:0:0: [sdd] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB) [ 743.636914] sd 3:0:0:0: Attached scsi generic sg1 type 0 [ 743.638483] sd 3:0:0:0: [sdd] Write Protect is off [ 743.638508] sd 3:0:0:0: [sdd] Mode Sense: 43 00 00 00 [ 743.646199] sd 3:0:0:0: [sdd] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA [ 743.665058] sdd: sdd1 sdd2 [ 743.667688] sd 3:0:0:0: [sdd] Attached SCSI disk

This is happening when there is a lot of activity on the drive. Drive is in a USB enclosure, self powered. Pi is powered by a 5V/2A adapter.

[PeterPablo]

You might want to try adding max_usb_current=1 to your /boot/config.txt (context).

[M-Tomohiro]

I think cause is heat. Do you set heatsink on CPU and LAN9514? LAN9514 is USB and Ethernet controller.

[JamesH65]

Neither of those devices requires a heatsink.

[jackpgao]

same question. model 2 B with USB 3.0 HUB. The problem is the USB3.0. 2.0 works well.

[tehfink]

Also seeing this issue with a rpi model 2B & USB 3 self-powered hub, and 4GB USB seagate drive.

[humbledude]

I uses 2 external disks and only one disk has the same problem. Problem is occur on IPTime 3035 external disk case + HDD. It has external power adapter, so I connected the disk directly to rpi. I recently bought rpi3 and this issue was not reproduced on my previous rpi1 B+ I guess this could be related to heat, its hot summer here and it seems to be reproduced after some time after reboot.

[123285.840778] usb 1-1.5: reset high-speed USB device number 5 using dwc_otg
[123286.223323] sd 0:0:0:0: [sdb] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[123286.223363] sd 0:0:0:0: [sdb] tag#0 CDB: opcode=0x28 28 00 4d 00 09 08 00 00 08 00
[123286.223390] blk_update_request: I/O error, dev sdb, sector 1291847944

[dminca]

Having the same issue on a virused USB Flash Kingston DT101 G2 (16GiB). I think the virus affected its boot sectors and now the Kernel is unable to read the size of the device in order to mount it properly.

lsusb output (dimmed):

Bus 001 Device 012: ID 0951:1665 Kingston Technology Digital DataTraveler SE9 64GB

dmesg -T output:

# connect the usb
[Sun Apr  2 14:51:35 2017] usb 1-1.2: new high-speed USB device number 12 using ehci-pci
[Sun Apr  2 14:51:35 2017] usb-storage 1-1.2:1.0: USB Mass Storage device detected
[Sun Apr  2 14:51:35 2017] scsi host6: usb-storage 1-1.2:1.0
[Sun Apr  2 14:51:37 2017] scsi 6:0:0:0: Direct-Access     GENERIC  USB Mass Storage 1.00 PQ: 0 ANSI: 4 CCS
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: Attached scsi generic sg2 type 0
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: [sdb] Read Capacity(10) failed: Result: hostbyte=0x00 driverbyte=0x08
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: [sdb] Sense Key : 0x6 [current]
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: [sdb] ASC=0x28 ASCQ=0x0
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: [sdb] 0 512-byte logical blocks: (0 B/0 B)
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: [sdb] 0-byte physical blocks
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: [sdb] Write Protect is off
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: [sdb] Mode Sense: 45 00 00 00
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: [sdb] Read Capacity(10) failed: Result: hostbyte=0x00 driverbyte=0x08
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: [sdb] Sense Key : 0x6 [current]
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: [sdb] ASC=0x28 ASCQ=0x0
[Sun Apr  2 14:51:37 2017] sd 6:0:0:0: [sdb] Attached SCSI removable disk

# disconnect the usb
[Sun Apr  2 14:51:44 2017] usb 1-1.2: USB disconnect, device number 12

Since it didn't read the size, he didn't even attach the filesystem /dev/sdX:

• Read Capacity(10) failed: Result: hostbyte=0x00 driverbyte=0x08 - couldn't guess the capacity of the Flash USB
• [sdb] 0 512-byte logical blocks: (0 B/0 B) - no size, couldn't mount it.

output of lsblk:

NAME              MAJ:MIN RM   SIZE RO TYPE MOUNTPOINT
sda                 8:0    0 232.9G  0 disk
└─sda1              8:1    0 232.9G  0 part
  ├─root--vg-boot 254:0    0   3.1G  0 lvm  /boot
  ├─root--vg-root 254:1    0    50G  0 lvm  /
  ├─root--vg-swap 254:2    0   500M  0 lvm  [SWAP]
  └─root--vg-home 254:3    0   150G  0 lvm  /home
sr0                11:0    1  1024M  0 rom

---

CONCLUSION boot sectors affected, USB Flash is bricked. :wastebasket: :recycle:

[adde88]

Hi from the OpenWRT community! ✋ I was curious to if a solution was found to this problem? I'm having the exact same problem on my device on kernel versions: 3.18.20 to 3.18.36 ! It seems to be related to the SD-card. Replacing my SD-card with a USB-thumb drive (mounted exactly similar), "fixes" the problem. But i miss my SD-card. 😭

When it happens very similar error-messages as above shows, and the sd-card disconnects from the device, and then re-appears a second later with a new identifier each time (/dev/sda -> /dev/sdb - /dev/sdc) Running badblocks on the sd-card will also trigger it each time. Very often when simply reading/writing to the device it happens, but never on standby.

I know this thread is about Raspberry Pi, not OpenWRT. But i had to ask if you guys found a solution, because i'm pretty desperate to get this fixed. 😃

[P33M]

For everyone experiencing random device disconnects, what happens if you put a USB hub between the Pi and the device in question?

[ben-ba]

Same problem here with OSMC (up to date) RaspberryPi 3 USB 2.0 Hub (Hama 1 to 4 - https://de.hama.com/00078472/hama-usb-20-hub-14-with-power-supply-black-cardboard-box?srcLang=0&targetLang=1 )

Details about the usb hub, maybe to identify the chipset. Also have a look at the max power of 100mA, the drives have a max power up to 500mA. Maybe this would explain, why some hubs works (especially some chipsets) and others not, and why sometimes it seems, that a better power supply would do the trick also.:

osmc@osmc:~$ lsusb -D /dev/bus/usb/001/030 Device: ID 1a40:0101 Terminus Technology Inc. 4-Port HUB Couldn't open device, some information will be missing Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 2.00 bDeviceClass 9 Hub bDeviceSubClass 0 Unused bDeviceProtocol 1 Single TT bMaxPacketSize0 64 idVendor 0x1a40 Terminus Technology Inc. idProduct 0x0101 4-Port HUB bcdDevice 1.11 iManufacturer 0 iProduct 1 iSerial 0 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 25 bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xe0 Self Powered Remote Wakeup MaxPower 100mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 9 Hub bInterfaceSubClass 0 Unused bInterfaceProtocol 0 Full speed (or root) hub iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0001 1x 1 bytes bInterval 12 osmc@osmc:~$

osmc@osmc:~$ sudo lsusb -t /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=dwc_otg/1p, 480M | Port 1: Dev 2, If 0, Class=Hub, Driver=hub/5p, 480M | Port 1: Dev 3, If 0, Class=Vendor Specific Class, Driver=smsc95xx, 480M | Port 3: Dev 30, If 0, Class=Hub, Driver=hub/4p, 480M | Port 3: Dev 33, If 0, Class=Mass Storage, Driver=usb-storage, 480M |__ Port 4: Dev 34, If 0, Class=Mass Storage, Driver=usb-storage, 480M

two usb drives on hub, both WD MyPassport, 4TB, one (sda1) NTFS, the other one (sbb1) is ext4 formatted.

/dev/sda1 /media/6080669B80667804 fuseblk rw,nosuid,nodev,relatime,user_id=0,group_id=0,default_permissions,allow_other,blksize=4096 0 0 /dev/sdb1 /media/MyPassport2 ext4 rw,noatime,data=ordered 0 0

Getting trouble when i rsync all data (nearly 4TB) from the "NTFS" drive to the "ext4" drive, dmsg output:

[ +0,001428] sd 17:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16). [ +0,001299] sd 17:0:0:0: [sdb] Attached SCSI disk [ +1,116244] buffer_io_error: 3498 callbacks suppressed [ +0,000016] Buffer I/O error on dev sdc1, logical block 38374017, async page read [ +0,000207] Buffer I/O error on dev sdc1, logical block 38374049, async page read [ +0,000109] Buffer I/O error on dev sdc1, logical block 38374017, async page read [ +0,003382] Buffer I/O error on dev sdc1, logical block 38374081, async page read [ +0,000358] Buffer I/O error on dev sdc1, logical block 38374113, async page read [ +0,000115] Buffer I/O error on dev sdc1, logical block 38374081, async page read [ +0,005591] Buffer I/O error on dev sdc1, logical block 38374145, async page read [ +0,000228] Buffer I/O error on dev sdc1, logical block 38374177, async page read [ +0,000840] Buffer I/O error on dev sdc1, logical block 38374145, async page read [ +0,002943] Buffer I/O error on dev sdc1, logical block 38374209, async page read [ +0,160145] scsi 16:0:0:1: Attached scsi generic sg3 type 13 [ +0,047971] sda: sda1 [ +0,001202] sd 16:0:0:0: [sda] Very big device. Trying to use READ CAPACITY(16). [ +0,001244] sd 16:0:0:0: [sda] Attached SCSI disk [ +4,783473] buffer_io_error: 3893 callbacks suppressed [ +0,000017] Buffer I/O error on dev sdc1, logical block 38520130, async page read [ +0,006422] Buffer I/O error on dev sdc1, logical block 38520194, async page read [ +0,000415] Buffer I/O error on dev sdc1, logical block 38520226, async page read [ +0,000144] Buffer I/O error on dev sdc1, logical block 38520194, async page read [ +0,004098] Buffer I/O error on dev sdc1, logical block 38520258, async page read [ +0,000234] Buffer I/O error on dev sdc1, logical block 38520290, async page read [ +0,000098] Buffer I/O error on dev sdc1, logical block 38520258, async page read [ +0,003047] Buffer I/O error on dev sdc1, logical block 38520322, async page read [ +0,000409] Buffer I/O error on dev sdc1, logical block 38520354, async page read [ +0,000153] Buffer I/O error on dev sdc1, logical block 38520322, async page read

u see now sdc1 because the target drive, with ext4 get auto remounted as read only.

a manually remount did the trick for a few hours copying data...

all my drive in detail:

osmc@osmc:~$ parted -l Model: WD My Passport 259D (scsi) Disk /dev/sda: 4001GB Sector size (logical/physical): 512B/4096B Partition Table: gpt Disk Flags:

Number Start End Size File system Name Flags 1 1049kB 4001GB 4001GB ntfs My Passport msftdata

Model: WD My Passport 25E2 (scsi) Disk /dev/sdb: 4001GB Sector size (logical/physical): 512B/4096B Partition Table: gpt Disk Flags:

Number Start End Size File system Name Flags 1 1049kB 4001GB 4001GB ext4 MyPassport2

Model: SD SL64G (sd/mmc) Disk /dev/mmcblk0: 63,9GB Sector size (logical/physical): 512B/512B Partition Table: msdos Disk Flags:

Number Start End Size Type File system Flags 1 1049kB 256MB 255MB primary fat32 lba 2 257MB 63,9GB 63,6GB primary ext4

osmc@osmc:~$

[JamesH65]

@p33m Is this covered by other USB issues? Can it be closed?

[M-Tomohiro]

hi, I explain about my case.

１ｓｔ:"environment" raspberry pi 2 model B. SSD connect to USB port. OS ubuntu for raspberry pi.

Test case is copy 50GB(1000 files) to SSD from PC. error : Buffer I/O error on dev sdxx.

2nd:"environment" raspberry pi 2 model B.(not 1st device, it mean the i have two raspberry pi. ) SSD connect to USB port.(device is same as １ｓｔ) OS ubuntu for raspberry pi.(device is same as １ｓｔ)

Test case is copy 50GB(1000 files) to SSD from PC. It worked very well.

Different point is raspberry pi only. other all environment same as 1st. So, In my understanding it is a problem of raspberry pi HW.

[JamesH65]

@p33m @M-Tomohiro Any further progress on this one?

[M-Tomohiro]

@JamesH65 Yes, there is no progress.

[Dreaky255]

Same issue for me, and solved. It was a power issue : My raspberry and hard drive (2Tb) were both powered through an usb hub-powered (2.5A). I had a DC power switch (jack) to the hub to easily power on and off my raspberry. The switch was actually too resistent to let pass enough power to the whole thing. It was working with a 1TB hard drive, but not with my brand new 2TB. After deleting the switch and directly powering the hub with the DC adaptor, problem has disappeared.

Hope it helps some of you.

Sry for my poor english.