On 17.12.2012 07:48, Dave Chinner wrote:
> On Sun, Dec 16, 2012 at 12:10:46PM +0100, Matthias Schniedermeyer wrote:
> > On 16.12.2012 11:30, Matthias Schniedermeyer wrote:
> > > On 16.12.2012 09:16, Dave Chinner wrote:
>
> > > Partition is 100GB at the beginning of a 1,5TB SATA HDD connected by
> > > USB3 enclosure:
> > > Machine has 4GB of memory and is running a vanilla 3.7.0 kernel.
> > >
> > > mkfs.xfs -l size=1024b -s size=4096 /dev/sdb1
>
> If you use the defaults, does the problem go away?
No changes.
> > > mount /dev/sdb1 /mnt
> > > mkdir /mnt/a
> > > cd /mnt/a
> > > for dat in `seq 1 40`; do dd if=/dev/zero of=$dat bs=1k count=900k ; done
> > >
> > > Then i started a timer and waited for 5 minutes.
> > > Then i yanked out the cable, my machine was writing to the 24th file at
> > > that point.
> > >
> > > umount /mnt
> > > <replug cable>
> > > mount /dev/sdb1 /mnt
> > > ls -l /mnt
> > > <In words: Nothing there, not even a>
>
> Can you provide the information I asked - what was there before the
> unmount,
With time reduced to 2 minutes and everything put in a script (see below).
After about 2 minutes:
ls -lR /mnt
/mnt:
total 0
drwxr-xr-x 2 root root 105 Dec 17 00:13 a
/mnt/a:
total 11186176
-rw-r--r-- 1 root root 943718400 Dec 17 00:11 1
-rw-r--r-- 1 root root 943718400 Dec 17 00:13 10
-rw-r--r-- 1 root root 943718400 Dec 17 00:13 11
-rw-r--r-- 1 root root 891450368 Dec 17 00:13 12
-rw-r--r-- 1 root root 943718400 Dec 17 00:11 2
-rw-r--r-- 1 root root 943718400 Dec 17 00:11 3
-rw-r--r-- 1 root root 943718400 Dec 17 00:12 4
-rw-r--r-- 1 root root 943718400 Dec 17 00:12 5
-rw-r--r-- 1 root root 943718400 Dec 17 00:12 6
-rw-r--r-- 1 root root 943718400 Dec 17 00:12 7
-rw-r--r-- 1 root root 943718400 Dec 17 00:12 8
-rw-r--r-- 1 root root 943718400 Dec 17 00:12 9
I yanked out the cable immediatly after the ls.
> what is there before recovery
xfs_logprint:
data device: 0x811
log device: 0x811 daddr: 104857632 length: 102400
cycle: 1 version: 2 lsn: 1,0 tail_lsn: 1,0
length of Log Record: 20 prev offset: -1 num ops: 1
uuid: b22d154a-b580-4d3a-bc09-ac0c62d39d39 format: little endian linux
h_size: 32768
----------------------------------------------------------------------------
Oper (0): tid: b0c0d0d0 len: 8 clientid: LOG flags: UNMOUNT
Unmount filesystem
============================================================================
xfs_logprint: skipped 4096 cleared blocks in range: 2 - 4097
xfs_logprint: skipped 98302 zeroed blocks in range: 4098 - 102399
xfs_logprint: physical end of log
============================================================================
xfs_logprint: logical end of log
============================================================================
mount /dev/sdb1 /mnt -oro,norecovery
ls -lR /mnt
/mnt:
total 0
So nothing.
> what is there after recovery?
Same. Nothing.
The syslog-message the Filesystem was clean. (See below)
> And depending on what occurred, send me the log file so I
> can see what was actually supposed to be replayed by log recovery?
Regarding to the 'event trace' from your other mail, i have no idea what
or how to do that.
This is the syslog from first mount till third mount.
Start:
Dec 17 00:11:26 localhost kernel: [ 204.152835] XFS (sdb1): Mounting Filesystem
Dec 17 00:11:26 localhost kernel: [ 204.233355] XFS (sdb1): Ending clean mount
Dec 17 00:11:33 localhost kernel: [ 211.471071] usb 3-1: reset SuperSpeed USB device number 2 using xhci_hcd
Dec 17 00:11:33 localhost kernel: [ 211.485718] usb 3-1: Parent hub missing LPM exit latency info. Power management will be impacted.
Dec 17 00:11:33 localhost kernel: [ 211.488182] xhci_hcd 0000:04:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff880113106100
Dec 17 00:11:33 localhost kernel: [ 211.489358] xhci_hcd 0000:04:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff880113106140
Dec 17 00:12:59 localhost kernel: [ 296.364776] usb 3-1: reset SuperSpeed USB device number 2 using xhci_hcd
Dec 17 00:12:59 localhost kernel: [ 296.379306] usb 3-1: Parent hub missing LPM exit latency info. Power management will be impacted.
Dec 17 00:12:59 localhost kernel: [ 296.381685] xhci_hcd 0000:04:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff880113106100
Dec 17 00:12:59 localhost kernel: [ 296.382906] xhci_hcd 0000:04:00.0: xHCI xhci_drop_endpoint called with disabled ep ffff880113106140
Disconnect:
Dec 17 00:13:28 localhost kernel: [ 325.548129] usb 3-1: USB disconnect, device number 2
Dec 17 00:13:28 localhost kernel: [ 325.549906] sd 12:0:0:0: [sdb] Unhandled error code
Dec 17 00:13:28 localhost kernel: [ 325.551073] sd 12:0:0:0: [sdb]
Dec 17 00:13:28 localhost kernel: [ 325.552230] Result: hostbyte=0x01 driverbyte=0x00
Dec 17 00:13:28 localhost kernel: [ 325.553399] sd 12:0:0:0: [sdb] CDB:
Dec 17 00:13:28 localhost kernel: [ 325.554530] cdb[0]=0x2a: 2a 00 01 51 fd 98 00 00 f0 00
Dec 17 00:13:28 localhost kernel: [ 325.555708] end_request: I/O error, dev sdb, sector 22150552
Dec 17 00:13:28 localhost kernel: [ 325.556971] sd 12:0:0:0: [sdb] Unhandled error code
Dec 17 00:13:28 localhost kernel: [ 325.558118] sd 12:0:0:0: [sdb]
Dec 17 00:13:28 localhost kernel: [ 325.559229] Result: hostbyte=0x01 driverbyte=0x00
Dec 17 00:13:28 localhost kernel: [ 325.560340] sd 12:0:0:0: [sdb] CDB:
Dec 17 00:13:28 localhost kernel: [ 325.561449] cdb[0]=0x2a: 2a 00 01 51 fe 88 00 00 f0 00
Dec 17 00:13:28 localhost kernel: [ 325.562628] end_request: I/O error, dev sdb, sector 22150792
Dec 17 00:13:28 localhost kernel: [ 325.562636] Buffer I/O error on device sdb1, logical block 2613279
Dec 17 00:13:28 localhost kernel: [ 325.562637] lost page write due to I/O error on sdb1
Dec 17 00:13:28 localhost kernel: [ 325.562638] Buffer I/O error on device sdb1, logical block 2613280
Dec 17 00:13:28 localhost kernel: [ 325.562638] lost page write due to I/O error on sdb1
Dec 17 00:13:28 localhost kernel: [ 325.562639] Buffer I/O error on device sdb1, logical block 2613281
Dec 17 00:13:28 localhost kernel: [ 325.562639] lost page write due to I/O error on sdb1
Dec 17 00:13:28 localhost kernel: [ 325.562640] Buffer I/O error on device sdb1, logical block 2613282
Dec 17 00:13:28 localhost kernel: [ 325.562640] lost page write due to I/O error on sdb1
Dec 17 00:13:28 localhost kernel: [ 325.562641] Buffer I/O error on device sdb1, logical block 2613283
Dec 17 00:13:28 localhost kernel: [ 325.562641] lost page write due to I/O error on sdb1
Dec 17 00:13:28 localhost kernel: [ 325.562642] Buffer I/O error on device sdb1, logical block 2613284
Dec 17 00:13:28 localhost kernel: [ 325.562642] lost page write due to I/O error on sdb1
Dec 17 00:13:28 localhost kernel: [ 325.562643] Buffer I/O error on device sdb1, logical block 2613285
Dec 17 00:13:28 localhost kernel: [ 325.562643] lost page write due to I/O error on sdb1
Dec 17 00:13:28 localhost kernel: [ 325.562644] Buffer I/O error on device sdb1, logical block 2613286
Dec 17 00:13:28 localhost kernel: [ 325.562644] lost page write due to I/O error on sdb1
Dec 17 00:13:28 localhost kernel: [ 325.562645] Buffer I/O error on device sdb1, logical block 2613287
Dec 17 00:13:28 localhost kernel: [ 325.562645] lost page write due to I/O error on sdb1
Dec 17 00:13:28 localhost kernel: [ 325.562646] Buffer I/O error on device sdb1, logical block 2613288
Dec 17 00:13:28 localhost kernel: [ 325.562646] lost page write due to I/O error on sdb1
Dec 17 00:13:28 localhost kernel: [ 325.647364] XFS (sdb1): metadata I/O error: block 0x6400022 ("xlog_iodone") error 5 numblks 64
Dec 17 00:13:28 localhost kernel: [ 325.648559] XFS (sdb1): xfs_do_force_shutdown(0x2) called from line 1074 of file /xssd/usr_src/linux/fs/xfs/xfs_log.c. Return address = 0xffffffff812a1e49
Dec 17 00:13:28 localhost kernel: [ 325.649804] XFS (sdb1): Log I/O Error Detected. Shutting down filesystem
Dec 17 00:13:28 localhost kernel: [ 325.651037] XFS (sdb1): Please umount the filesystem and rectify the problem(s)
Dec 17 00:13:28 localhost kernel: [ 325.652341] XFS (sdb1): xfs_log_force: error 5 returned.
Dec 17 00:13:28 localhost kernel: [ 325.653564] XFS (sdb1): xfs_do_force_shutdown(0x1) called from line 1160 of file /xssd/usr_src/linux/fs/xfs/xfs_buf.c. Return address = 0xffffffff8125198f
Dec 17 00:13:28 localhost kernel: [ 325.937819] XFS (sdb1): xfs_log_force: error 5 returned.
Dec 17 00:13:28 localhost kernel: [ 325.939105] XFS (sdb1): xfs_do_force_shutdown(0x1) called from line 1160 of file /xssd/usr_src/linux/fs/xfs/xfs_buf.c. Return address = 0xffffffff8125198f
Dec 17 00:13:28 localhost kernel: [ 325.940427] XFS (sdb1): xfs_log_force: error 5 returned.
Dec 17 00:13:28 localhost kernel: [ 325.941768] XFS (sdb1): xfs_log_force: error 5 returned.
Reconnect:
Dec 17 00:13:41 localhost kernel: [ 338.939079] usb 3-1: new SuperSpeed USB device number 3 using xhci_hcd
Dec 17 00:13:41 localhost kernel: [ 338.953410] usb 3-1: Parent hub missing LPM exit latency info. Power management will be impacted.
Dec 17 00:13:41 localhost kernel: [ 338.959394] usb 3-1: New USB device found, idVendor=174c, idProduct=5106
Dec 17 00:13:41 localhost kernel: [ 338.960791] usb 3-1: New USB device strings: Mfr=2, Product=3, SerialNumber=1
Dec 17 00:13:41 localhost kernel: [ 338.962135] usb 3-1: Product: AS2105
Dec 17 00:13:41 localhost kernel: [ 338.963470] usb 3-1: Manufacturer: ASMedia
Dec 17 00:13:41 localhost kernel: [ 338.964800] usb 3-1: SerialNumber: 5XW02D4M
Dec 17 00:13:41 localhost kernel: [ 338.966977] scsi13 : usb-storage 3-1:1.0
Dec 17 00:13:42 localhost kernel: [ 339.970156] scsi 13:0:0:0: Direct-Access ST315005 41AS CC32 PQ: 0 ANSI: 5
Dec 17 00:13:42 localhost kernel: [ 339.971635] sd 13:0:0:0: Attached scsi generic sg1 type 0
Dec 17 00:13:42 localhost kernel: [ 339.973202] sd 13:0:0:0: [sdb] 2930277168 512-byte logical blocks: (1.50 TB/1.36 TiB)
Dec 17 00:13:42 localhost kernel: [ 339.975256] sd 13:0:0:0: [sdb] Write Protect is off
Dec 17 00:13:42 localhost kernel: [ 339.976639] sd 13:0:0:0: [sdb] Mode Sense: 23 00 00 00
Dec 17 00:13:42 localhost kernel: [ 339.977358] sd 13:0:0:0: [sdb] No Caching mode page present
Dec 17 00:13:42 localhost kernel: [ 339.978700] sd 13:0:0:0: [sdb] Assuming drive cache: write through
Dec 17 00:13:42 localhost kernel: [ 339.981747] sd 13:0:0:0: [sdb] No Caching mode page present
Dec 17 00:13:42 localhost kernel: [ 339.983143] sd 13:0:0:0: [sdb] Assuming drive cache: write through
Dec 17 00:13:42 localhost kernel: [ 339.998266] sdb: sdb1
Dec 17 00:13:42 localhost kernel: [ 340.001383] sd 13:0:0:0: [sdb] No Caching mode page present
Dec 17 00:13:42 localhost kernel: [ 340.002734] sd 13:0:0:0: [sdb] Assuming drive cache: write through
Dec 17 00:13:42 localhost kernel: [ 340.004043] sd 13:0:0:0: [sdb] Attached SCSI disk
mount -oro,norecovery:
Dec 17 00:13:54 localhost kernel: [ 351.902543] XFS (sdb1): Mounting filesystem in no-recovery mode. Filesystem will be inconsistent.
mount:
Dec 17 00:14:02 localhost kernel: [ 359.860013] XFS (sdb1): Mounting Filesystem
Dec 17 00:14:02 localhost kernel: [ 359.908198] XFS (sdb1): Ending clean mount
- test.sh -
#!/bin/bash
mkfs.xfs -f /dev/sdb1
mount /dev/sdb1 /mnt
mkdir /mnt/a
(sleep 2m ; ls -lR /mnt)&
for dat in `seq 1 40`; do dd if=/dev/zero of=/mnt/a/$dat bs=1k count=900k ; done
ls -lR /mnt
umount /mnt
echo "Press Enter"
read ABC
xfs_logprint /dev/sdb1
mount /dev/sdb1 /mnt -oro,norecovery
ls -lR /mnt
umount /mnt
echo "Press Enter"
read ABC
mount /dev/sdb1 /mnt
ls -lR /mnt
umount /mnt
- test.sh -
--
Matthias
_______________________________________________
xfs mailing list
xfs@xxxxxxxxxxx
http://oss.sgi.com/mailman/listinfo/xfs
