Libparted warning Error fsyncing/closing...Remote I/O errror

[UncleVan]

I recently stumbled upon a very ghastly bug which is effectively preventing maintenance of USB hard disks. In O-Ton:

Code: Select all

Libparted warning  
Error fsyncing/closing /dev/sdb Remote I/O error

This occurs about 6-8 times while Gparted scans the devices; and about 2-4 times on every action I try - only for the external USB HDD.

Furthermore, when I force to apply any action - GPT/MSDOS Table, partitioning, Check, Format to etc - the work is actually done despite on the continuously appearing messages (clicking the "Ignore" button).
As a side effect afterwards it is not possible to write on an EXT fs with journaling, because the Journal appears to be damaged even after just mount-unmounting it - errors in the logs (s.b.)
On a "forced" (with "Ignore") fvat32 partition it is possible to write and read after remounting - probably because of the absence of any journal.

This impacts ONLY USB HDDs; flash sticks are not affected.

This is NOT hardware issue: I effectively excluded any error sources:

-) Every single USB HDD of mine which I ultimatively partitioned and formatted with Gparted is now affected
-) I tried a 2 years old (customized by me) SystemRescueCD with Gparted 0.13.0 and an old kernel: Everything working just perfectly !

I cant state when exactly this has been introduced, because I havent maintained external drives for a while.
This time it cought me by surprise so any help/confirmations are pretty urgent.

Thanls in advance !



Logs/Description:

Actual state: Machine: Thinkpad Edge 11"
========================================

Code: Select all

Kernel:     sys-kernel/gentoo-sources-3.16.5:3.16.5
Gparted:    sys-block/gparted-0.19.0:0
Libparted:  sys-block/parted-3.1-r1:0	
Status:     Error message

Test 1:
=============

Code: Select all

Kernel:     sys-kernel/gentoo-sources-3.14.16:3.14.16
Gparted:    sys-block/gparted-0.19.0:0
Libparted:  sys-block/parted-3.1-r1:0	
Status:     Error message

Test 2:
=============

Code: Select all

Kernel:     3.2.23 (with SysRescCD patches)
Gparted:    sys-block/gparted-0.8.0
Libparted:  sys-block/parted-2.3	
Status:     No errors

Messages:
=============

Gparted:

Code: Select all

"Libparted warning  
 Error fsyncing/closing /dev/sdb Remote I/O error"

DMESG (USB HDD fat32)

Attaching the hard disk

Code: Select all

[15943.225429] usb 2-1.2: Product: USB Mass Storage Device
[15943.225434] usb 2-1.2: Manufacturer: Myson Century, Inc.
[15943.225440] usb 2-1.2: SerialNumber: 100
[15943.226446] usb-storage 2-1.2:1.0: USB Mass Storage device detected
[15943.226592] scsi16 : usb-storage 2-1.2:1.0
[15944.230947] scsi 16:0:0:0: Direct-Access     TOSHIBA  MK1233GAS        AA01 PQ: 0 ANSI: 0 CCS
[15944.231938] sd 16:0:0:0: Attached scsi generic sg1 type 0
[15944.232514] sd 16:0:0:0: [sdb] 234441648 512-byte logical blocks: (120 GB/111 GiB)
[15944.233201] sd 16:0:0:0: [sdb] Write Protect is off
[15944.233208] sd 16:0:0:0: [sdb] Mode Sense: 00 14 00 00
[15944.233888] sd 16:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[15944.248756]  sdb: sdb1
[15944.251545] sd 16:0:0:0: [sdb] Attached SCSI disk

Gparted starting

Code: Select all

[16019.539247] end_request: critical target error, dev sdb, sector 0
[16020.951262] end_request: critical target error, dev sdb, sector 0
[16024.472283] end_request: critical target error, dev sdb, sector 0
[16025.449577] end_request: critical target error, dev sdb, sector 0

Creating MSDOS partition table

Code: Select all

[16169.310160] end_request: critical target error, dev sdb, sector 0
[16174.912308] end_request: critical target error, dev sdb, sector 0
[16176.058139] end_request: critical target error, dev sdb, sector 0
[16178.010162] end_request: critical target error, dev sdb, sector 0
[16178.769981] end_request: critical target error, dev sdb, sector 0
[16181.197321] end_request: critical target error, dev sdb, sector 0
[16181.914265] end_request: critical target error, dev sdb, sector 0
[16185.244798] end_request: critical target error, dev sdb, sector 0

Creating/Formatting ext3 partition

Code: Select all

[16423.304473] end_request: critical target error, dev sdb, sector 0
[16424.961748] end_request: critical target error, dev sdb, sector 0
[16425.476274] end_request: critical target error, dev sdb, sector 0
[16426.719267] end_request: critical target error, dev sdb, sector 0
[16427.568828] end_request: critical target error, dev sdb, sector 0
[16428.331389] end_request: critical target error, dev sdb, sector 0
[16429.096808] end_request: critical target error, dev sdb, sector 0
[16429.843857] end_request: critical target error, dev sdb, sector 0
[16430.986028] end_request: critical target error, dev sdb, sector 0
[16431.882192] end_request: critical target error, dev sdb, sector 0
[16432.692693] end_request: critical target error, dev sdb, sector 0
[16433.431130] end_request: critical target error, dev sdb, sector 0
[16434.735394] end_request: critical target error, dev sdb, sector 0
[16435.585442] end_request: critical target error, dev sdb, sector 0
[16554.071900] end_request: critical target error, dev sdb, sector 0
[16554.291163] end_request: critical target error, dev sdb, sector 0
[16567.173971] end_request: critical target error, dev sdb, sector 0
[16570.074119] end_request: critical target error, dev sdb, sector 0
[16578.777610] end_request: critical target error, dev sdb, sector 0
[16581.307466] end_request: critical target error, dev sdb, sector 0

************************
Gparted messages:

Code: Select all

Libparted warning  
 Error fsyncing/closing /dev/sdb Remote I/O error"

"Remote I/O error during write on /dev/sdb"
(quitted with "Ignore")

Gparted final Message

Code: Select all

"All operations successfully completed."

************************


Unplugging

Code: Select all

[code][16684.405299] usb 2-1.2: USB disconnect, device number 9
[16684.414659] sd 16:0:0:0: [sdb] Synchronizing SCSI cache
[16684.415410] sd 16:0:0:0: [sdb]  
[16684.415473] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK

[/code]
Plugging anew

Code: Select all

[16779.767262] usb 2-1.2: new high-speed USB device number 10 using ehci-pci
[16779.854828] usb 2-1.2: New USB device found, idVendor=04cf, idProduct=8818
[16779.854845] usb 2-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[16779.854854] usb 2-1.2: Product: USB Mass Storage Device
[16779.854861] usb 2-1.2: Manufacturer: Myson Century, Inc.
[16779.854868] usb 2-1.2: SerialNumber: 100
[16779.855780] usb-storage 2-1.2:1.0: USB Mass Storage device detected
[16779.856092] scsi18 : usb-storage 2-1.2:1.0
[16780.859651] scsi 18:0:0:0: Direct-Access     TOSHIBA  MK1233GAS        AA01 PQ: 0 ANSI: 0 CCS
[16780.860310] sd 18:0:0:0: Attached scsi generic sg1 type 0
[16780.860800] sd 18:0:0:0: [sdb] 234441648 512-byte logical blocks: (120 GB/111 GiB)
[16780.861421] sd 18:0:0:0: [sdb] Write Protect is off
[16780.861427] sd 18:0:0:0: [sdb] Mode Sense: 00 14 00 00
[16780.862062] sd 18:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[16780.873658]  sdb: sdb1
[16780.876454] sd 18:0:0:0: [sdb] Attached SCSI disk

Mounting

Code: Select all

[16840.645972] kjournald starting.  Commit interval 5 seconds
[16840.647067] EXT3-fs (sdb1): using internal journal
[16840.647076] EXT3-fs (sdb1): mounted filesystem with writeback data mode
[16846.466330] end_request: critical target error, dev sdb, sector 116922408
[16846.466345] quiet_error: 22 callbacks suppressed
[16846.466349] Buffer I/O error on device sdb1, logical block 14615045
[16846.466352] lost page write due to I/O error on sdb1
[16846.466372] Aborting journal on device sdb1.

Creating new Folder:

Code: Select all

[16998.455846] EXT3-fs (sdb1): error: ext3_journal_start_sb: Detected aborted journal
[16998.455854] EXT3-fs (sdb1): error: remounting filesystem read-only

************************
User Space error message
************************

Code: Select all

Failed to create directory "New Folder".
Error creating directory: Read-only file system.
Do you want to skip it?

Ejecting

Code: Select all

[17108.476266] EXT3-fs (sdb1): error: ext3_put_super: Couldn't clean up the journal

Unplugging

Code: Select all

[17174.122030] usb 2-1.2: USB disconnect, device number 10
[17174.123201] sd 18:0:0:0: [sdb] Synchronizing SCSI cache
[17174.123284] sd 18:0:0:0: [sdb]  
[17174.123290] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK

Plugging anew

Code: Select all

[17270.051969] usb 2-1.2: new high-speed USB device number 11 using ehci-pci
[17270.139465] usb 2-1.2: New USB device found, idVendor=04cf, idProduct=8818
[17270.139480] usb 2-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[17270.139488] usb 2-1.2: Product: USB Mass Storage Device
[17270.139495] usb 2-1.2: Manufacturer: Myson Century, Inc.
[17270.139502] usb 2-1.2: SerialNumber: 100
[17270.140448] usb-storage 2-1.2:1.0: USB Mass Storage device detected
[17270.140948] scsi19 : usb-storage 2-1.2:1.0
[17271.144463] scsi 19:0:0:0: Direct-Access     TOSHIBA  MK1233GAS        AA01 PQ: 0 ANSI: 0 CCS
[17271.145611] sd 19:0:0:0: [sdb] 234441648 512-byte logical blocks: (120 GB/111 GiB)
[17271.145962] sd 19:0:0:0: Attached scsi generic sg1 type 0
[17271.146274] sd 19:0:0:0: [sdb] Write Protect is off
[17271.146282] sd 19:0:0:0: [sdb] Mode Sense: 00 14 00 00
[17271.146961] sd 19:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[17271.155547]  sdb: sdb1
[17271.157989] sd 19:0:0:0: [sdb] Attached SCSI disk

Mounting anew

Code: Select all

[17271.157989] sd 19:0:0:0: [sdb] Attached SCSI disk
[17372.921048] end_request: critical target error, dev sdb, sector 0
[17372.921088] JBD: recovery failed
[17372.921103] EXT3-fs (sdb1): error loading journal

************************
User Space error message

Code: Select all

Failed to mount "BUG"
Error mounting /dev/sdb1 at /run/media/root/BUG: Command-line `mount -t "ext3" -o "uhelper=udisks2,nodev,nosuid" "/dev/sdb1" "/run/media/root/BUG"' exited with non-zero exit status 32: mount: wrong fs type, bad option, bad superblock on /dev/sdb1,
       missing codepage or helper program, or other error

       In some cases useful info is found in syslog - try
       dmesg | tail or so.

************************

Unplugging

Code: Select all

[17565.069653] usb 2-1.2: USB disconnect, device number 11
[17565.072829] sd 19:0:0:0: [sdb] Synchronizing SCSI cache
[17565.072917] sd 19:0:0:0: [sdb]  
[17565.072923] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK

Some Kernel Log: (greped on "sdb")
=============================

1.: USB HDD, ext3
Maintaning with Gparted:

Code: Select all

Nov 17 21:56:55 thinkkiste kernel: [845793.197050] sd 104:0:0:0: [sdb] 195371568 512-byte logical blocks: (100 GB/93.1 GiB)
Nov 17 21:56:55 thinkkiste kernel: [845793.197679] sd 104:0:0:0: [sdb] Write Protect is off
Nov 17 21:56:55 thinkkiste kernel: [845793.197688] sd 104:0:0:0: [sdb] Mode Sense: 00 14 00 00
Nov 17 21:56:55 thinkkiste kernel: [845793.198301] sd 104:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Nov 17 21:56:55 thinkkiste kernel: [845793.334051]  sdb:
Nov 17 21:56:55 thinkkiste kernel: [845793.336604] sd 104:0:0:0: [sdb] Attached SCSI disk
Nov 17 21:56:55 thinkkiste kernel: [845793.583780]  sdb:
Nov 17 21:57:45 thinkkiste kernel: [845843.009941]  sdb: sdb1
Nov 17 21:57:46 thinkkiste kernel: [845844.111913] end_request: critical target error, dev sdb, sector 0
Nov 17 21:57:46 thinkkiste kernel: [845844.124373]  sdb: sdb1
Nov 17 21:57:53 thinkkiste kernel: [845851.558603] end_request: critical target error, dev sdb, sector 0
Nov 17 21:57:56 thinkkiste kernel: [845853.840450] end_request: critical target error, dev sdb, sector 0
Nov 17 21:57:59 thinkkiste kernel: [845857.359579] end_request: critical target error, dev sdb, sector 0
Nov 17 21:58:01 thinkkiste kernel: [845859.051805] end_request: critical target error, dev sdb, sector 0
Nov 17 21:58:02 thinkkiste kernel: [845860.359195] end_request: critical target error, dev sdb, sector 0
Nov 17 21:58:22 thinkkiste kernel: [845880.178214] end_request: critical target error, dev sdb, sector 0
Nov 17 21:58:25 thinkkiste kernel: [845883.273272] end_request: critical target error, dev sdb, sector 0
Nov 17 21:58:26 thinkkiste kernel: [845883.811418] end_request: critical target error, dev sdb, sector 0
Nov 17 21:58:26 thinkkiste kernel: [845884.348769] end_request: critical target error, dev sdb, sector 0
Nov 17 21:58:27 thinkkiste kernel: [845884.805926] end_request: critical target error, dev sdb, sector 0
Nov 17 21:58:27 thinkkiste kernel: [845885.260358] end_request: critical target error, dev sdb, sector 0
Nov 17 21:58:28 thinkkiste kernel: [845885.897013] end_request: critical target error, dev sdb, sector 0
Nov 17 21:58:28 thinkkiste kernel: [845886.282288] end_request: critical target error, dev sdb, sector 0
Nov 17 21:58:28 thinkkiste kernel: [845886.636695] end_request: critical target error, dev sdb, sector 0
Nov 17 21:58:29 thinkkiste kernel: [845887.216044] end_request: critical target error, dev sdb, sector 0
Nov 17 22:00:09 thinkkiste kernel: [845987.233503] end_request: critical target error, dev sdb, sector 0
Nov 17 22:00:09 thinkkiste kernel: [845987.236095] end_request: critical target error, dev sdb, sector 0
Nov 17 22:00:20 thinkkiste kernel: [845997.684161] end_request: critical target error, dev sdb, sector 0
Nov 17 22:00:21 thinkkiste kernel: [845998.720614] end_request: critical target error, dev sdb, sector 0
Nov 17 22:00:25 thinkkiste kernel: [846003.084062] end_request: critical target error, dev sdb, sector 0
Nov 17 22:00:27 thinkkiste kernel: [846004.801320] end_request: critical target error, dev sdb, sector 0
Nov 17 22:00:42 thinkkiste kernel: [846019.921420] end_request: critical target error, dev sdb, sector 0
Nov 17 22:00:43 thinkkiste kernel: [846021.598403] end_request: critical target error, dev sdb, sector 0
Nov 17 22:03:28 thinkkiste kernel: [846185.707270] end_request: critical target error, dev sdb, sector 0
Nov 17 22:03:28 thinkkiste kernel: [846185.709758] end_request: critical target error, dev sdb, sector 0
Nov 17 22:03:28 thinkkiste kernel: [846185.719849] end_request: critical target error, dev sdb, sector 0
Nov 17 22:03:48 thinkkiste kernel: [846206.420769] end_request: critical target error, dev sdb, sector 0
Nov 17 22:03:50 thinkkiste kernel: [846208.123016] end_request: critical target error, dev sdb, sector 0
Nov 17 22:03:53 thinkkiste kernel: [846211.400479] end_request: critical target error, dev sdb, sector 0
Nov 17 22:03:55 thinkkiste kernel: [846213.032370] end_request: critical target error, dev sdb, sector 0
Nov 17 22:03:59 thinkkiste kernel: [846216.818109]  sdb: sdb1
Nov 17 22:03:59 thinkkiste kernel: [846216.833918]  sdb: sdb1
Nov 17 22:04:07 thinkkiste kernel: [846225.639581] sd 104:0:0:0: [sdb] Synchronizing SCSI cache
Nov 17 22:04:07 thinkkiste kernel: [846225.639702] sd 104:0:0:0: [sdb]  

First Mount
Nov 17 22:04:15 thinkkiste kernel: [846233.557481] sd 105:0:0:0: [sdb] 195371568 512-byte logical blocks: (100 GB/93.1 GiB)
Nov 17 22:04:15 thinkkiste kernel: [846233.558124] sd 105:0:0:0: [sdb] Write Protect is off
Nov 17 22:04:15 thinkkiste kernel: [846233.558131] sd 105:0:0:0: [sdb] Mode Sense: 00 14 00 00
Nov 17 22:04:15 thinkkiste kernel: [846233.558877] sd 105:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Nov 17 22:04:16 thinkkiste kernel: [846233.701449]  sdb: sdb1
Nov 17 22:04:16 thinkkiste kernel: [846233.704224] sd 105:0:0:0: [sdb] Attached SCSI disk
Nov 17 22:04:19 thinkkiste kernel: [846237.276963] EXT3-fs (sdb1): using internal journal
Nov 17 22:04:19 thinkkiste kernel: [846237.276976] EXT3-fs (sdb1): mounted filesystem with writeback data mode
Nov 17 22:04:19 thinkkiste udisksd[4356]: Mounted /dev/sdb1 at /run/media/root/c9e116e4-fc31-4ad6-bc85-79081a61908e on behalf of uid 0
Nov 17 22:04:24 thinkkiste kernel: [846242.372286] end_request: critical target error, dev sdb, sector 97261608
Nov 17 22:04:24 thinkkiste kernel: [846242.372304] Buffer I/O error on device sdb1, logical block 12157445
Nov 17 22:04:24 thinkkiste kernel: [846242.372307] lost page write due to I/O error on sdb1
Nov 17 22:04:24 thinkkiste kernel: [846242.372324] Aborting journal on device sdb1.
Nov 17 22:04:56 thinkkiste kernel: [846273.773560] sd 105:0:0:0: [sdb] Synchronizing SCSI cache
Nov 17 22:04:56 thinkkiste kernel: [846273.773643] sd 105:0:0:0: [sdb]  
Nov 17 22:04:56 thinkkiste kernel: [846273.831317] EXT3-fs (sdb1): error: ext3_put_super: Couldn't clean up the journal
Nov 17 22:04:56 thinkkiste kernel: [846273.831327] EXT3-fs (sdb1): error: remounting filesystem read-only

Mounting afterwards

Code: Select all

Nov 17 22:05:11 thinkkiste kernel: [846289.370291] sd 106:0:0:0: [sdb] 195371568 512-byte logical blocks: (100 GB/93.1 GiB)
Nov 17 22:05:11 thinkkiste kernel: [846289.370932] sd 106:0:0:0: [sdb] Write Protect is off
Nov 17 22:05:11 thinkkiste kernel: [846289.370939] sd 106:0:0:0: [sdb] Mode Sense: 00 14 00 00
Nov 17 22:05:11 thinkkiste kernel: [846289.371674] sd 106:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Nov 17 22:05:11 thinkkiste kernel: [846289.515371]  sdb: sdb1
Nov 17 22:05:11 thinkkiste kernel: [846289.518200] sd 106:0:0:0: [sdb] Attached SCSI disk
Nov 17 22:05:19 thinkkiste kernel: [846297.311059] end_request: critical target error, dev sdb, sector 0
Nov 17 22:05:19 thinkkiste kernel: [846297.311151] EXT3-fs (sdb1): error loading journal
Nov 17 22:05:27 thinkkiste kernel: [846304.746704] end_request: critical target error, dev sdb, sector 0
Nov 17 22:05:27 thinkkiste kernel: [846304.746735] EXT3-fs (sdb1): error loading journal
Nov 17 22:05:32 thinkkiste kernel: [846310.638757] sd 106:0:0:0: [sdb] Synchronizing SCSI cache
Nov 17 22:05:32 thinkkiste kernel: [846310.638850] sd 106:0:0:0: [sdb]  

2.: USB HDD, NTFS:
Mounting

Code: Select all

Nov 17 22:19:56 thinkkiste kernel: [847174.705766] sd 115:0:0:0: [sdb] 234441648 512-byte logical blocks: (120 GB/111 GiB)
Nov 17 22:19:56 thinkkiste kernel: [847174.706420] sd 115:0:0:0: [sdb] Write Protect is off
Nov 17 22:19:56 thinkkiste kernel: [847174.706441] sd 115:0:0:0: [sdb] Mode Sense: 00 14 00 00
Nov 17 22:19:56 thinkkiste kernel: [847174.707141] sd 115:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Nov 17 22:19:56 thinkkiste kernel: [847174.716507]  sdb: sdb1
Nov 17 22:19:56 thinkkiste kernel: [847174.719145] sd 115:0:0:0: [sdb] Attached SCSI disk
Nov 17 22:20:07 thinkkiste ntfs-3g[18307]: Mounted /dev/sdb1 (Read-Write, label "DATALUX", NTFS 3.1)
Nov 17 22:20:07 thinkkiste ntfs-3g[18307]: Mount options: rw,nodev,nosuid,uhelper=udisks2,allow_other,nonempty,relatime,fsname=/dev/sdb1,blkdev,blksize=4096
Nov 17 22:20:07 thinkkiste udisksd[4356]: Mounted /dev/sdb1 at /run/media/root/DATALUX on behalf of uid 0
Nov 17 22:20:29 thinkkiste ntfs-3g[18307]: Unmounting /dev/sdb1 (DATALUX)
Nov 17 22:20:29 thinkkiste ntfs-3g[18307]: Failed to sync device /dev/sdb1: Remote I/O error
Nov 17 22:20:29 thinkkiste ntfs-3g[18307]: Failed to close volume /dev/sdb1: Remote I/O error
Nov 17 22:20:29 thinkkiste kernel: [847207.105225] end_request: critical target error, dev sdb, sector 0
Nov 17 22:20:29 thinkkiste udisksd[4356]: Unmounted /dev/sdb1 on behalf of uid 0
Nov 17 22:20:53 thinkkiste kernel: [847231.555194] sd 115:0:0:0: [sdb] Synchronizing SCSI cache
Nov 17 22:20:53 thinkkiste kernel: [847231.555307] sd 115:0:0:0: [sdb]  

3.: USB HDD, fat32

Code: Select all

Nov 17 22:11:58 thinkkiste kernel: [846696.715319] sd 112:0:0:0: [sdb] 234441648 512-byte logical blocks: (120 GB/111 GiB)
Nov 17 22:11:58 thinkkiste kernel: [846696.715936] sd 112:0:0:0: [sdb] Write Protect is off
Nov 17 22:11:58 thinkkiste kernel: [846696.715945] sd 112:0:0:0: [sdb] Mode Sense: 00 14 00 00
Nov 17 22:11:58 thinkkiste kernel: [846696.716572] sd 112:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Nov 17 22:11:59 thinkkiste kernel: [846696.817463]  sdb: sdb1
Nov 17 22:11:59 thinkkiste kernel: [846696.820346] sd 112:0:0:0: [sdb] Attached SCSI disk
Nov 17 22:12:15 thinkkiste kernel: [846712.841368] FAT-fs (sdb1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
Nov 17 22:12:15 thinkkiste udisksd[4356]: Mounted /dev/sdb1 at /run/media/root/DATALUX on behalf of uid 0
Nov 17 22:12:26 thinkkiste udisksd[4356]: Unmounted /dev/sdb1 on behalf of uid 0
Nov 17 22:12:44 thinkkiste kernel: [846742.256112] FAT-fs (sdb1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
Nov 17 22:12:44 thinkkiste udisksd[4356]: Mounted /dev/sdb1 at /run/media/root/DATALUX on behalf of uid 0
Nov 17 22:13:07 thinkkiste udisksd[4356]: Unmounted /dev/sdb1 on behalf of uid 0
Nov 17 22:13:10 thinkkiste kernel: [846768.408764] sd 112:0:0:0: [sdb] Synchronizing SCSI cache
Nov 17 22:13:10 thinkkiste kernel: [846768.408849] sd 112:0:0:0: [sdb]  

4.: USB Flash, ext3

Code: Select all

Nov 17 23:58:30 thinkkiste kernel: [ 1639.035767] sd 5:0:0:0: [sdb] 15753215 512-byte logical blocks: (8.06 GB/7.51 GiB)
Nov 17 23:58:30 thinkkiste kernel: [ 1639.036473] sd 5:0:0:0: [sdb] Write Protect is off
Nov 17 23:58:30 thinkkiste kernel: [ 1639.036479] sd 5:0:0:0: [sdb] Mode Sense: 45 00 00 08
Nov 17 23:58:30 thinkkiste kernel: [ 1639.038007] sd 5:0:0:0: [sdb] No Caching mode page found
Nov 17 23:58:30 thinkkiste kernel: [ 1639.038015] sd 5:0:0:0: [sdb] Assuming drive cache: write through
Nov 17 23:58:30 thinkkiste kernel: [ 1639.045312]  sdb: sdb1 sdb2 sdb3
Nov 17 23:58:30 thinkkiste kernel: [ 1639.049599] sd 5:0:0:0: [sdb] Attached SCSI removable disk
Nov 17 23:58:35 thinkkiste kernel: [ 1644.133466] EXT3-fs (sdb3): using internal journal
Nov 17 23:58:35 thinkkiste kernel: [ 1644.133479] EXT3-fs (sdb3): mounted filesystem with writeback data mode
Nov 17 23:58:35 thinkkiste udisksd[3855]: Mounted /dev/sdb3 at /run/media/root/PERSIST on behalf of uid 0
Nov 17 23:59:25 thinkkiste kernel: [ 1693.719852]  sdb: sdb1 sdb2 sdb3

5.: USB Flash, fat32

Code: Select all

Nov 17 22:24:47 thinkkiste kernel: [847465.336610] sd 118:0:0:0: [sdb] 1970176 512-byte logical blocks: (1.00 GB/962 MiB)
Nov 17 22:24:47 thinkkiste kernel: [847465.337453] sd 118:0:0:0: [sdb] Write Protect is off
Nov 17 22:24:47 thinkkiste kernel: [847465.337465] sd 118:0:0:0: [sdb] Mode Sense: 23 00 00 00
Nov 17 22:24:47 thinkkiste kernel: [847465.338306] sd 118:0:0:0: [sdb] No Caching mode page found
Nov 17 22:24:47 thinkkiste kernel: [847465.338316] sd 118:0:0:0: [sdb] Assuming drive cache: write through
Nov 17 22:24:47 thinkkiste kernel: [847465.342765]  sdb: sdb1
Nov 17 22:24:47 thinkkiste kernel: [847465.345561] sd 118:0:0:0: [sdb] Attached SCSI removable disk
Nov 17 22:24:56 thinkkiste udisksd[4356]: Mounted /dev/sdb1 at /run/media/root/UDISK 20X on behalf of uid 0
Nov 17 22:25:05 thinkkiste udisksd[4356]: Unmounted /dev/sdb1 on behalf of uid 0
Nov 17 22:25:05 thinkkiste kernel: [847482.869163] sdb: detected capacity change from 1008730112 to 0

[UncleVan]

For some reason EXT3/4 can not start journaling. NTFS causes errors too (because of journaling ?), but not FAT32.

Only USB hard disks with EXT3/EXT4/NTFS are affected, but NOT USB sticks or SD cards regardless of the file system.

Any suggestions ? - Thanks in advance !

Here dmesg from a session:

Code: Select all

[34434.054279] sd 48:0:0:0: [sdb] Attached SCSI disk
[34526.440883] kjournald starting.  Commit interval 5 seconds
[34526.441552] EXT3-fs (sdb2): using internal journal
[34526.441558] EXT3-fs (sdb2): mounted filesystem with writeback data mode

[34545.095054] end_request: critical target error, dev sdb, sector 172472408
[34545.095070] Buffer I/O error on device sdb2, logical block 7668235
[34545.095076] lost page write due to I/O error on sdb2
[34545.095139] Aborting journal on device sdb2.

[34550.467618] EXT3-fs (sdb2): error: ext3_put_super: Couldn't clean up the journal
[34550.467629] EXT3-fs (sdb2): error: remounting filesystem read-only

[34572.736428] end_request: critical target error, dev sdb, sector 0
[34572.736468] JBD: recovery failed
[34572.736483] EXT3-fs (sdb2): error loading journal

[34638.806624] usb 2-1.2: USB disconnect, device number 27
[34638.809086] sd 48:0:0:0: [sdb] Synchronizing SCSI cache
[34638.809186] sd 48:0:0:0: [sdb]  
[34638.809193] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK

[UncleVan]

I revive this thread cause I believe I found the reason for this bug: The culprit is called FUA and appears to be broken somewhen after sys-kernel/gentoo-sources 3.2.23 since this one was the last I could find to work properly.

FUA stands for "Force Unit Access" and does exactly what it means: it forces write requests all the way to the persistent storage - HDDs - in an immediate manner, thus "passing by" the write cache of the device. FUA commands are used as a part of the "write barriers" logic for some file systems, which deal - exactly, with the Journaling !
http://lwn.net/Articles/400541/
According to the above, FUA and FLUSH commands are issued by the fs itself, but executed by the block layer.

I was able to verify my assumption by simply switching off journaling on an ext3 fs

Code: Select all

tune2fs -O ^has_journal /dev/sdb1

turning it effectively into an ext2. Then I used this USB HDD whithout any problems for huge amounts of data written and read.

I suppose NTFS - in the ntfs-3g implementation - is "forcing" the device access too, thus causing errors, but didn't find any work-around yet.

Gparted/Libparted still spitting their "Remote I/O Error"s - obviosly for the same reason - FUAs.

There is a bug filed at https://bugzilla.kernel.org/show_bug.cgi?id=89511 by Jun Itou ; the responsible seems to be Alan Stern , but nothing has been done since 2015-01-11 02:22:47 UTC .

TODO: Find out which USB HDD Controller Chips are affected and do some comparative USB montraces of the old and new kernel.

Please let me know if someone experiences same bug.