xfs
[Top] [All Lists]

xfs tries to write on readonly device on unmount

To: xfs@xxxxxxxxxxx
Subject: xfs tries to write on readonly device on unmount
From: Michael Prokop <mika@xxxxxxxx>
Date: Tue, 21 Jul 2009 12:51:20 +0200
User-agent: Mutt/1.5.13 (2006-08-11)
Hi,

This issue might be related to
http://oss.sgi.com/bugzilla/show_bug.cgi?id=413

A XFS partition is set to read-only mode (using 'blockdev --setro')
and mounted. As soon as I *un*mount the filesystem there seem to
happen write requests.

I've a Tableau Forensic Bridge¹ which avoids the write requests and
attached it to a Linux live-system running kernel 2.6.28 inside
VMware and Virtualbox. I can easily reproduce the problem.

Full debugging details:

# vol_id /dev/sdb2
ID_FS_USAGE=filesystem
ID_FS_TYPE=xfs
ID_FS_VERSION=
ID_FS_UUID=884331b1-0d0b-4314-abc8-46f7ddb96c68
ID_FS_UUID_ENC=884331b1-0d0b-4314-abc8-46f7ddb96c68
ID_FS_LABEL=
ID_FS_LABEL_ENC=
# blockdev --getro /dev/sdb2
1
# logger before-mounting
# sysctl -w vm.block_dump=1
vm.block_dump = 1
# mount /dev/sdb2 /mnt/test
mount: block device /dev/sdb2 is write-protected, mounting read-only
# logger finished-mounting-now-unmounting
# umount /mnt/test
# logger finished-unmounting

Quoting /var/log/syslog:

Jul 21 14:31:19 grml logger: before-mounting
[...]
Jul 21 14:31:31 grml kernel: [  535.624072] mount(5945): READ block 385408 on 
sdb2
Jul 21 14:31:31 grml kernel: [  535.676864] mount(5945): dirtied inode 11731 
(sdb2) on tmpfs
Jul 21 14:31:31 grml kernel: [  535.676942] mount(5945): READ block 0 on sdb2
Jul 21 14:31:31 grml kernel: [  535.676959] mount(5945): READ block 8 on sdb2
Jul 21 14:31:31 grml kernel: [  535.676968] mount(5945): READ block 16 on sdb2
Jul 21 14:31:31 grml kernel: [  535.676974] mount(5945): READ block 24 on sdb2
Jul 21 14:31:31 grml kernel: [  535.676979] mount(5945): READ block 32 on sdb2
Jul 21 14:31:31 grml kernel: [  535.676985] mount(5945): READ block 40 on sdb2
Jul 21 14:31:31 grml kernel: [  535.676991] mount(5945): READ block 48 on sdb2
Jul 21 14:31:31 grml kernel: [  535.676996] mount(5945): READ block 56 on sdb2
Jul 21 14:31:31 grml kernel: [  535.677003] mount(5945): READ block 64 on sdb2
Jul 21 14:31:31 grml kernel: [  535.677009] mount(5945): READ block 72 on sdb2
Jul 21 14:31:31 grml kernel: [  535.677014] mount(5945): READ block 80 on sdb2
Jul 21 14:31:31 grml kernel: [  535.677026] mount(5945): READ block 88 on sdb2
Jul 21 14:31:31 grml kernel: [  535.677033] mount(5945): READ block 96 on sdb2
Jul 21 14:31:31 grml kernel: [  535.677040] mount(5945): READ block 104 on sdb2
Jul 21 14:31:31 grml kernel: [  535.677045] mount(5945): READ block 112 on sdb2
Jul 21 14:31:31 grml kernel: [  535.677051] mount(5945): READ block 120 on sdb2
Jul 21 14:31:31 grml kernel: [  535.677056] mount(5945): READ block 128 on sdb2
Jul 21 14:31:31 grml kernel: [  535.740494] mount(5945): READ block 385408 on 
sdb2
Jul 21 14:31:31 grml kernel: [  535.790687] mount(5945): READ block 0 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790707] mount(5945): READ block 8 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790716] mount(5945): READ block 16 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790723] mount(5945): READ block 24 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790730] mount(5945): READ block 32 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790737] mount(5945): READ block 40 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790743] mount(5945): READ block 48 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790750] mount(5945): READ block 56 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790757] mount(5945): READ block 64 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790763] mount(5945): READ block 72 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790770] mount(5945): READ block 80 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790776] mount(5945): READ block 88 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790784] mount(5945): READ block 96 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790791] mount(5945): READ block 104 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790798] mount(5945): READ block 112 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790805] mount(5945): READ block 120 on sdb2
Jul 21 14:31:31 grml kernel: [  535.790812] mount(5945): READ block 128 on sdb2
Jul 21 14:31:31 grml kernel: [  535.867701] mount(5945): READ block 0 on sdb2
Jul 21 14:31:31 grml kernel: [  535.900281] Filesystem "sdb2": Disabling 
barriers, underlying device is readonly
Jul 21 14:31:31 grml kernel: [  535.900313] mount(5945): READ block 385552 on 
sdb2
Jul 21 14:31:31 grml kernel: [  535.930552] XFS mounting filesystem sdb2
Jul 21 14:31:31 grml kernel: [  535.931159] mount(5945): READ block 192816 on 
sdb2
Jul 21 14:31:31 grml kernel: [  535.953967] mount(5945): READ block 202415 on 
sdb2
Jul 21 14:31:31 grml kernel: [  535.987222] mount(5945): READ block 197615 on 
sdb2
Jul 21 14:31:31 grml kernel: [  536.007964] mount(5945): READ block 195215 on 
sdb2
Jul 21 14:31:31 grml kernel: [  536.041195] mount(5945): READ block 194015 on 
sdb2
Jul 21 14:31:31 grml kernel: [  536.066990] mount(5945): READ block 193415 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.134166] mount(5945): READ block 193115 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.180253] mount(5945): READ block 192965 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.251434] mount(5945): READ block 192890 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.321465] mount(5945): READ block 192853 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.391436] mount(5945): READ block 192834 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.461507] mount(5945): READ block 192825 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.491863] mount(5945): READ block 192829 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.521982] mount(5945): READ block 192831 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.548595] mount(5945): READ block 192832 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.581878] mount(5945): READ block 192833 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.612013] mount(5945): READ block 192816 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.638629] mount(5945): READ block 192818 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.671866] mount(5945): READ block 192820 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.701942] mount(5945): READ block 192822 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.728635] mount(5945): READ block 192824 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.756766] mount(5945): READ block 192826 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.781954] mount(5945): READ block 192828 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.817006] mount(5945): READ block 192830 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.848537] mount(5945): READ block 192832 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.872031] mount(5945): READ block 192816 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.905224] mount(5945): READ block 192832 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.935298] mount(5945): READ block 192831 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.956758] mount(5945): READ block 192832 on 
sdb2
Jul 21 14:31:32 grml kernel: [  536.991921] mount(5945): READ block 64 on sdb2
Jul 21 14:31:32 grml kernel: [  537.035209] Ending clean XFS mount for 
filesystem: sdb2
Jul 21 14:31:44 grml logger: finished-mounting-now-unmounting
Jul 21 14:31:50 grml kernel: [  554.547532] umount(5982): WRITE block 0 on sdb2
Jul 21 14:32:20 grml kernel: [  585.113445] usb 1-1: reset high speed USB 
device using ehci_hcd and address 2
Jul 21 14:32:21 grml kernel: [  585.917964] sd 2:0:0:0: [sdb] Result: 
hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Jul 21 14:32:21 grml kernel: [  585.917987] sd 2:0:0:0: [sdb] Sense Key : Data 
Protect [current]
Jul 21 14:32:21 grml kernel: [  585.918004] sd 2:0:0:0: [sdb] Add. Sense: Write 
protected
Jul 21 14:32:21 grml kernel: [  585.918022] end_request: I/O error, dev sdb, 
sector 385560
Jul 21 14:32:21 grml kernel: [  585.918135] xfs_force_shutdown(sdb2,0x1) called 
from line 420 of file fs/xfs/xfs_rw.c.  Return address = 0xc029a511
Jul 21 14:32:21 grml kernel: [  585.918172] Filesystem "sdb2": I/O Error 
Detected.  Shutting down filesystem: sdb2
Jul 21 14:32:21 grml kernel: [  585.918185] Please umount the filesystem, and 
rectify the problem(s)
Jul 21 14:32:21 grml kernel: [  585.918213] Filesystem "sdb2": xfs_log_force: 
error 5 returned.
Jul 21 14:32:21 grml kernel: [  585.918226] Filesystem "sdb2": xfs_log_force: 
error 5 returned.
Jul 21 14:32:21 grml kernel: [  585.918243] xfs_force_shutdown(sdb2,0x1) called 
from line 420 of file fs/xfs/xfs_rw.c.  Return address = 0xc029a511
Jul 21 14:32:21 grml kernel: [  585.918305] Filesystem "sdb2": xfs_log_force: 
error 5 returned.
Jul 21 14:32:21 grml kernel: [  585.918317] Filesystem "sdb2": xfs_log_force: 
error 5 returned.
Jul 21 14:32:21 grml kernel: [  585.918387] Filesystem "sdb2": xfs_log_force: 
error 5 returned.
Jul 21 14:32:21 grml kernel: [  585.918408] Filesystem "sdb2": xfs_log_force: 
error 5 returned.
Jul 21 14:32:21 grml kernel: [  585.918421] Filesystem "sdb2": xfs_log_force: 
error 5 returned.
Jul 21 14:32:21 grml kernel: [  585.923639] umount(5982): dirtied inode 15799 
(mtab.tmp) on tmpfs
Jul 21 14:32:21 grml kernel: [  585.923894] umount(5982): dirtied inode 15799 
(mtab.tmp) on tmpfs
Jul 21 14:33:03 grml logger: finished-unmounting

I couldn't reproduce the same problem with other filesystems.
Let me know if you need any further details.

Please Cc me on replies as I'm not subscribed to the mailinglist.

¹ http://www.tableau.com/index.php?pageid=products&category=forensic_bridges

regards,
-mika-
-- 
http://michael-prokop.at/  || http://adminzen.org/
http://grml-solutions.com/ || http://grml.org/

Attachment: signature.asc
Description: Digital signature

<Prev in Thread] Current Thread [Next in Thread>