Buffer I/O error on device (USB - XFS

voku · 11-02-2009, 03:19 AM

Hi, I have a problem with a raid, it is connected with USB 2.0 to the server [Debian - Lenny - Linux version 2.6.29-bpo.2-686 (Debian 2.6.29-5~bpo50+1)] but now the raid crash or the XFS or USB?????

this is the log, from the crash...

Nov 1 20:15:36 backup kernel: [968189.112015] usb 5-3: reset high speed USB device using ehci_hcd and address 2
Nov 1 20:16:21 backup kernel: [968234.112016] usb 5-3: reset high speed USB device using ehci_hcd and address 2
Nov 1 20:16:37 backup kernel: [968249.224016] usb 5-3: device descriptor read/64, error -110
Nov 1 20:16:52 backup kernel: [968264.440015] usb 5-3: device descriptor read/64, error -110
Nov 1 20:16:52 backup kernel: [968264.656015] usb 5-3: reset high speed USB device using ehci_hcd and address 2
Nov 1 20:17:07 backup kernel: [968279.768015] usb 5-3: device descriptor read/64, error -110
Nov 1 20:17:22 backup kernel: [968294.984014] usb 5-3: device descriptor read/64, error -110
Nov 1 20:17:23 backup kernel: [968295.200015] usb 5-3: reset high speed USB device using ehci_hcd and address 2
Nov 1 20:17:33 backup kernel: [968305.608022] usb 5-3: device not accepting address 2, error -110
Nov 1 20:17:33 backup kernel: [968305.720017] usb 5-3: reset high speed USB device using ehci_hcd and address 2
Nov 1 20:17:44 backup kernel: [968316.128011] usb 5-3: device not accepting address 2, error -110
Nov 1 20:17:44 backup kernel: [968316.128075] sd 0:0:0:0: Device offlined - not ready after error recovery
Nov 1 20:17:44 backup kernel: [968316.128086] sd 0:0:0:0: [sdb] Unhandled error code
Nov 1 20:17:44 backup kernel: [968316.128088] sd 0:0:0:0: [sdb] Result: hostbyte=DID_ABORT driverbyte=DRIVER_OK,SUGGEST_OK
Nov 1 20:17:44 backup kernel: [968316.128094] end_request: I/O error, dev sdb, sector 1092964410
Nov 1 20:17:44 backup kernel: [968316.128136] sd 0:0:0:0: rejecting I/O to offline device
Nov 1 20:17:44 backup kernel: [968316.128173] I/O error in filesystem ("dm-6") meta-data dev dm-6 block 0x41254e98 ("xfs_trans_read_buf") error 5 buf count 4096
Nov 1 20:17:44 backup kernel: [968316.128279] Device dm-6, XFS metadata write error block 0x0 in dm-6
Nov 1 20:17:44 backup kernel: [968316.128509] usb 5-3: USB disconnect, address 2
Nov 1 20:17:44 backup kernel: [968316.155819] Buffer I/O error on device dm-6, logical block 67861407
Nov 1 20:17:44 backup kernel: [968316.155847] lost page write due to I/O error on dm-6
Nov 1 20:17:44 backup kernel: [968316.155856] Buffer I/O error on device dm-6, logical block 67861408
Nov 1 20:17:44 backup kernel: [968316.155878] lost page write due to I/O error on dm-6
Nov 1 20:17:44 backup kernel: [968316.155885] Buffer I/O error on device dm-6, logical block 71088645
Nov 1 20:17:44 backup kernel: [968316.155908] lost page write due to I/O error on dm-6
Nov 1 20:17:44 backup kernel: [968316.155914] Buffer I/O error on device dm-6, logical block 71088646
Nov 1 20:17:44 backup kernel: [968316.155937] lost page write due to I/O error on dm-6
Nov 1 20:17:44 backup kernel: [968316.155942] Buffer I/O error on device dm-6, logical block 71088647
Nov 1 20:17:44 backup kernel: [968316.155964] lost page write due to I/O error on dm-6
Nov 1 20:17:44 backup kernel: [968316.155970] Buffer I/O error on device dm-6, logical block 71088648
Nov 1 20:17:44 backup kernel: [968316.155992] lost page write due to I/O error on dm-6
Nov 1 20:17:44 backup kernel: [968316.155997] Buffer I/O error on device dm-6, logical block 71088649
Nov 1 20:17:44 backup kernel: [968316.156037] lost page write due to I/O error on dm-6
Nov 1 20:17:44 backup kernel: [968316.156043] Buffer I/O error on device dm-6, logical block 71088650
Nov 1 20:17:44 backup kernel: [968316.156065] lost page write due to I/O error on dm-6
Nov 1 20:17:44 backup kernel: [968316.156071] Buffer I/O error on device dm-6, logical block 71088651
Nov 1 20:17:44 backup kernel: [968316.156093] lost page write due to I/O error on dm-6
Nov 1 20:17:44 backup kernel: [968316.156098] Buffer I/O error on device dm-6, logical block 71088652
Nov 1 20:17:44 backup kernel: [968316.156120] lost page write due to I/O error on dm-6
Nov 1 20:17:44 backup kernel: [968316.245038] usb 5-3: new high speed USB device using ehci_hcd and address 3
Nov 1 20:17:47 backup kernel: [968319.244085] I/O error in filesystem ("dm-6") meta-data dev dm-6 block 0x40003a01 ("xlog_iodone") error 5 buf count 3584
Nov 1 20:17:47 backup kernel: [968319.244134] xfs_force_shutdown(dm-6,0x2) called from line 1055 of file /build/buildd/linux-2.6-2.6.29/debian/build/source_i386_none/fs/xfs/xfs_log.c. Return address = 0xf88c59aa
Nov 1 20:17:47 backup kernel: [968319.244159] Filesystem "dm-6": Log I/O Error Detected. Shutting down filesystem: dm-6
Nov 1 20:17:47 backup kernel: [968319.244196] Please umount the filesystem, and rectify the problem(s)
Nov 1 20:17:55 backup kernel: [968327.912016] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:17:59 backup kernel: [968331.356016] usb 5-3: device descriptor read/64, error -110
Nov 1 20:18:14 backup kernel: [968346.572015] usb 5-3: device descriptor read/64, error -110
Nov 1 20:18:14 backup kernel: [968346.788015] usb 5-3: new high speed USB device using ehci_hcd and address 4
Nov 1 20:18:29 backup kernel: [968361.900015] usb 5-3: device descriptor read/64, error -110
Nov 1 20:18:31 backup kernel: [968363.912016] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:18:45 backup kernel: [968377.116015] usb 5-3: device descriptor read/64, error -110
Nov 1 20:18:45 backup kernel: [968377.332013] usb 5-3: new high speed USB device using ehci_hcd and address 5
Nov 1 20:18:55 backup kernel: [968387.740013] usb 5-3: device not accepting address 5, error -110
Nov 1 20:18:55 backup kernel: [968387.852014] usb 5-3: new high speed USB device using ehci_hcd and address 6
Nov 1 20:19:06 backup kernel: [968398.260011] usb 5-3: device not accepting address 6, error -110
Nov 1 20:19:06 backup kernel: [968398.260049] hub 5-0:1.0: unable to enumerate USB device on port 3
Nov 1 20:19:06 backup kernel: [968398.528011] usb 2-1: new full speed USB device using uhci_hcd and address 2
Nov 1 20:19:07 backup kernel: [968399.912015] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:19:21 backup kernel: [968413.640018] usb 2-1: device descriptor read/64, error -110
Nov 1 20:19:36 backup kernel: [968428.856013] usb 2-1: device descriptor read/64, error -110
Nov 1 20:19:36 backup kernel: [968429.072012] usb 2-1: new full speed USB device using uhci_hcd and address 3
Nov 1 20:19:43 backup kernel: [968435.912015] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:19:52 backup kernel: [968444.184013] usb 2-1: device descriptor read/64, error -110
Nov 1 20:20:07 backup kernel: [968459.400015] usb 2-1: device descriptor read/64, error -110
Nov 1 20:20:07 backup kernel: [968459.616013] usb 2-1: new full speed USB device using uhci_hcd and address 4
Nov 1 20:20:17 backup kernel: [968470.024011] usb 2-1: device not accepting address 4, error -110
Nov 1 20:20:18 backup kernel: [968470.136012] usb 2-1: new full speed USB device using uhci_hcd and address 5
Nov 1 20:20:55 backup kernel: [968507.912019] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:21:31 backup kernel: [968543.912016] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:22:07 backup kernel: [968579.912022] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:22:43 backup kernel: [968615.912015] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:23:19 backup kernel: [968651.912014] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:23:55 backup kernel: [968687.912015] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:24:31 backup kernel: [968723.912015] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:25:07 backup kernel: [968759.912015] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:25:43 backup kernel: [968795.912017] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:26:19 backup kernel: [968831.912014] Filesystem "dm-6": xfs_log_force: error 5 returned.
Nov 1 20:26:55 backup kernel: [968867.912014] Filesystem "dm-6": xfs_log_force: error 5 returned.
[...]

lsusb

Nov 2 09:46:46 backup kernel: [1016858.388013] usb 2-1: device descriptor read/64, error -110
Nov 2 09:47:01 backup kernel: [1016873.604014] usb 2-1: device descriptor read/64, error -110
Nov 2 09:47:01 backup kernel: [1016873.820013] usb 2-1: new full speed USB device using uhci_hcd and address 11
Nov 2 09:47:16 backup kernel: [1016888.932019] usb 2-1: device descriptor read/64, error -110
Nov 2 09:47:32 backup kernel: [1016904.148014] usb 2-1: device descriptor read/64, error -110
Nov 2 09:47:32 backup kernel: [1016904.364012] usb 2-1: new full speed USB device using uhci_hcd and address 12
Nov 2 09:47:42 backup kernel: [1016914.772012] usb 2-1: device not accepting address 12, error -110
Nov 2 09:47:42 backup kernel: [1016914.884012] usb 2-1: new full speed USB device using uhci_hcd and address 13
Nov 2 09:47:53 backup kernel: [1016925.292021] usb 2-1: device not accepting address 13, error -110
Nov 2 09:47:53 backup kernel: [1016925.292057] hub 2-0:1.0: unable to enumerate USB device on port 1

after I have reset the raid-device... I see this in the logfile

Nov 2 10:05:08 backup kernel: [1017960.536017] usb 1-3: new high speed USB device using ehci_hcd and address 6
Nov 2 10:05:08 backup kernel: [1017960.668938] usb 1-3: New USB device found, idVendor=ffff, idProduct=5182
Nov 2 10:05:08 backup kernel: [1017960.668942] usb 1-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Nov 2 10:05:08 backup kernel: [1017960.668946] usb 1-3: Product: USB Mass Storage Device
Nov 2 10:05:08 backup kernel: [1017960.668949] usb 1-3: Manufacturer: Areca
Nov 2 10:05:08 backup kernel: [1017960.668951] usb 1-3: SerialNumber: 001B4D00D9BC
Nov 2 10:05:08 backup kernel: [1017960.669075] usb 1-3: configuration #1 chosen from 1 choice
Nov 2 10:05:08 backup kernel: [1017960.671657] scsi2 : SCSI emulation for USB Mass Storage devices
Nov 2 10:05:08 backup kernel: [1017960.673230] usb-storage: device found at 6
Nov 2 10:05:08 backup kernel: [1017960.673235] usb-storage: waiting for device to settle before scanning
Nov 2 10:05:13 backup kernel: [1017965.672239] usb-storage: device scan complete
Nov 2 10:05:13 backup kernel: [1017965.672705] scsi 2:0:0:0: Direct-Access backup-RAID1 R001 PQ: 0 ANSI: 5
Nov 2 10:05:13 backup kernel: [1017965.673830] sd 2:0:0:0: [sdc] Very big device. Trying to use READ CAPACITY(16).
Nov 2 10:05:13 backup kernel: [1017965.674340] sd 2:0:0:0: [sdc] 5859374592 512-byte hardware sectors: (2.99 TB/2.72 TiB)
Nov 2 10:05:13 backup kernel: [1017965.674701] sd 2:0:0:0: [sdc] Write Protect is off
Nov 2 10:05:13 backup kernel: [1017965.674707] sd 2:0:0:0: [sdc] Mode Sense: bf 00 00 08
Nov 2 10:05:13 backup kernel: [1017965.674712] sd 2:0:0:0: [sdc] Assuming drive cache: write through
Nov 2 10:05:13 backup kernel: [1017965.675472] sd 2:0:0:0: [sdc] Very big device. Trying to use READ CAPACITY(16).
Nov 2 10:05:13 backup kernel: [1017965.675976] sd 2:0:0:0: [sdc] 5859374592 512-byte hardware sectors: (2.99 TB/2.72 TiB)
Nov 2 10:05:13 backup kernel: [1017965.677465] sd 2:0:0:0: [sdc] Write Protect is off
Nov 2 10:05:13 backup kernel: [1017965.677472] sd 2:0:0:0: [sdc] Mode Sense: bf 00 00 08
Nov 2 10:05:13 backup kernel: [1017965.677476] sd 2:0:0:0: [sdc] Assuming drive cache: write through
Nov 2 10:05:13 backup kernel: [1017965.677508] sdc: sdc1
Nov 2 10:05:13 backup kernel: [1017965.709032] sd 2:0:0:0: [sdc] Attached SCSI disk
Nov 2 10:05:13 backup kernel: [1017965.709177] sd 2:0:0:0: Attached scsi generic sg3 type 0

but I can't mount the device anymore...

mount /dev/mapper/raid /backup

Nov 2 10:05:27 backup kernel: [1017979.524589] XFS: SB read failed
Nov 2 10:08:05 backup kernel: [1018137.669221] __ratelimit: 34 callbacks suppressed
Nov 2 10:08:05 backup kernel: [1018137.669226] Buffer I/O error on device dm-6, logical block 268435440
Nov 2 10:08:05 backup kernel: [1018137.669271] Buffer I/O error on device dm-6, logical block 268435440
Nov 2 10:08:05 backup kernel: [1018137.669320] Buffer I/O error on device dm-6, logical block 0
Nov 2 10:08:05 backup kernel: [1018137.669351] Buffer I/O error on device dm-6, logical block 1
Nov 2 10:08:05 backup kernel: [1018137.669380] Buffer I/O error on device dm-6, logical block 2
Nov 2 10:08:05 backup kernel: [1018137.669408] Buffer I/O error on device dm-6, logical block 3
Nov 2 10:08:05 backup kernel: [1018137.669436] Buffer I/O error on device dm-6, logical block 4
Nov 2 10:08:05 backup kernel: [1018137.669465] Buffer I/O error on device dm-6, logical block 5
Nov 2 10:08:05 backup kernel: [1018137.669493] Buffer I/O error on device dm-6, logical block 6
Nov 2 10:08:05 backup kernel: [1018137.669522] Buffer I/O error on device dm-6, logical block 7

Cocoabean · 11-03-2009, 02:56 PM

Voku, your disk is probably deteriorating, buffer I/O errors are indicative of physical drive problems from what I have seen. I would recommend trying GNU ddrescue to attempt to recover your data. It will read the drive/partition at a block level and attempt to read damaged ones multiple times. I use it at work quite frequently, it usually works, it only failed me on my own dead laptop drive. Anyways, I wish you the best of luck in your data recovery efforts.