[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

EFSCORRUPTED + xfs_force_shutdown using xfs over multipath

Hi,

We've been getting bad magic number problems repeatedly when using XFS
over a multipath md connected to a hardware raid (IBM DF4000). Our
kernel is 2.4.14-xfs.
This is all part of a failover cluster where the raid is connected to
two nodes and the md / xfs is moved to the pair node in case of
problems.

One of the scenarios which we've been able to document couple of times
is :

May 26 08:38:32 10.17.0.2 kernel: EFSCORRUPTED returned from file
xfs_btree.c line 200 
May 26 08:38:32 10.17.0.2 kernel: xfs_force_shutdown(md(9,1),0x8) called
from line 1020 of file xfs_trans.c.  Return address = 0xc01e3b39 
May 26 08:38:34 10.17.0.2 kernel: Corruption of in-memory data detected.
Shutting down filesystem: md(9,1) 
May 26 08:38:34 10.17.0.2 kernel: Please umount the filesystem, and
rectify the problem(s) 

Then we stop the md:
May 26 08:38:55 10.17.0.2 kernel: md: marking sb clean... 
May 26 08:38:55 10.17.0.2 kernel: md: updating md1 RAID superblock on
device 
May 26 08:38:55 10.17.0.2 kernel: md: scsi/host4/bus0/target0/lun1/part3
[events: 00000004]<6>(write) scsi/host4/bus0/target0/lun1/part3's sb
offset: 35153856 
May 26 08:38:55 10.17.0.2 kernel: md: (skipping alias
scsi/host2/bus0/target0/lun1/part3 ) 
May 26 08:38:55 10.17.0.2 kernel: md: md1 stopped. 
May 26 08:38:55 10.17.0.2 kernel: md:
unbind<scsi/host4/bus0/target0/lun1/part3,1> 
May 26 08:38:55 10.17.0.2 kernel: md:
export_rdev(scsi/host4/bus0/target0/lun1/part3) 
May 26 08:38:55 10.17.0.2 kernel: md:
unbind<scsi/host2/bus0/target0/lun1/part3,0> 
May 26 08:38:55 10.17.0.2 kernel: md:
export_rdev(scsi/host2/bus0/target0/lun1/part3) 

 start it again on the pair node:
ay 26 08:39:20 10.17.0.1 kernel: md: autorun ... 
May 26 08:39:20 10.17.0.1 kernel: md: considering
scsi/host4/bus0/target0/lun1/part3 ... 
May 26 08:39:20 10.17.0.1 kernel: md:  adding
scsi/host4/bus0/target0/lun1/part3 ... 
May 26 08:39:20 10.17.0.1 kernel: md:  adding
scsi/host2/bus0/target0/lun1/part3 ... 
May 26 08:39:20 10.17.0.1 kernel: md: created md1 
May 26 08:39:20 10.17.0.1 kernel: md:
bind<scsi/host2/bus0/target0/lun1/part3,1> 
May 26 08:39:20 10.17.0.1 kernel: md:
bind<scsi/host4/bus0/target0/lun1/part3,2> 
May 26 08:39:20 10.17.0.1 kernel: md: running:
<scsi/host4/bus0/target0/lun1/part3><scsi/host2/bus0/target0/lun1/part3>

May 26 08:39:20 10.17.0.1 kernel: md:
scsi/host4/bus0/target0/lun1/part3's event counter: 00000004 
May 26 08:39:20 10.17.0.1 kernel: md:
scsi/host2/bus0/target0/lun1/part3's event counter: 00000004 
May 26 08:39:20 10.17.0.1 kernel: md1: max total readahead window set to
124k 
May 26 08:39:20 10.17.0.1 kernel: md1: 1 data-disks, max readahead per
data-disk: 124k 
May 26 08:39:20 10.17.0.1 kernel: multipath: device
scsi/host4/bus0/target0/lun1/part3 operational as IO path 0 
May 26 08:39:20 10.17.0.1 kernel: multipath: making IO path
scsi/host2/bus0/target0/lun1/part3 a spare path (not in sync) 
May 26 08:39:20 10.17.0.1 kernel: (checking disk 0) 
May 26 08:39:20 10.17.0.1 kernel: multipath: array md1 active with 1 out
of 1 IO paths (1 spare IO paths) 
May 26 08:39:20 10.17.0.1 kernel: md: updating md1 RAID superblock on
device 
May 26 08:39:20 10.17.0.1 kernel: md: scsi/host4/bus0/target0/lun1/part3
[events: 00000005]<6>(write) scsi/host4/bus0/target0/lun1/part3's sb
offset: 35153856 
May 26 08:39:20 10.17.0.1 kernel: md: (skipping alias
scsi/host2/bus0/target0/lun1/part3 ) 
May 26 08:39:20 10.17.0.1 kernel: md: ... autorun DONE. 

 and try to mount.
May 26 08:39:20 10.17.0.1 kernel: XFS: bad magic number 
May 26 08:39:20 10.17.0.1 kernel: XFS: SB validate failed 

This of course repeated (because of failover scripts) until manual
intervention.

After starting only the md I tried:

# xfs_check /dev/md1
xfs_check: unexpected XFS SB magic number 0x7caffe04
bad superblock magic number 7caffe04, giving up


# xfs_repair /dev/md1
Phase 1 - find and verify superblock...
bad primary superblock - bad magic number !!!

attempting to find secondary superblock...
........................................................................
........................................................................
........................................................................
........................................................................
........................................................................
........................................................................
........................................................................
........................................................................
........................................................................
........................................................................
........................................................................
........................................................................
........................................................................
........................................................................
.found candidate secondary superblock...
verified secondary superblock...
writing modified primary superblock
sb root inode value 18446744073709551615 inconsistent with calculated
value 13835050015103385728
resetting superblock root inode pointer to 18446744069414584448
sb realtime bitmap inode 18446744073709551615 inconsistent with
calculated value 13835050015103385729
resetting superblock realtime bitmap ino pointer to 18446744069414584449
sb realtime summary inode 18446744073709551615 inconsistent with
calculated value 13835050015103385730
resetting superblock realtime summary ino pointer to
18446744069414584450
Phase 2 - using internal log
        - zero log...
ERROR: The filesystem has valuable metadata changes in a log which needs
to
be replayed.  Mount the filesystem to replay the log, and unmount it
before
re-running xfs_repair.  If you are unable to mount the filesystem, then
use
the -L option to destroy the log and attempt a repair.
Note that destroying the log may cause corruption -- please attempt a
mount
of the filesystem before doing this.


[root@node3-alpha ~]# mount /dev/md/1 /tmp/volumes/md1/
mount: wrong fs type, bad option, bad superblock on /dev/md/1,
       or too many mounted file systems
[root@node3-alpha ~]# mount /dev/md/1 /tmp/volumes/md1/ -t xfs
mount: wrong fs type, bad option, bad superblock on /dev/md/1,
       or too many mounted file systems


So I had to do xfs_repair -L to rectify the problem...


# xfs_repair -L /dev/md/1
Phase 1 - find and verify superblock...
sb root inode value 18446744073709551615 inconsistent with calculated
value 13835050015103385728
resetting superblock root inode pointer to 18446744069414584448
sb realtime bitmap inode 18446744073709551615 inconsistent with
calculated value 13835050015103385729
resetting superblock realtime bitmap ino pointer to 18446744069414584449
sb realtime summary inode 18446744073709551615 inconsistent with
calculated value 13835050015103385730
resetting superblock realtime summary ino pointer to
18446744069414584450
Phase 2 - using internal log
        - zero log...
ALERT: The filesystem has valuable metadata changes in a log which is
being
destroyed because the -L option was used.
        - scan filesystem freespace and inode maps...
bad magic # 0x7cbb54de for agi 0
bad version # -572753274 for agi 0
bad sequence # 1445784856 for agi 0
bad length # 1724231845 for agi 0, should be 262144
reset bad agi for ag 0
bad agbno 1975217499 in agfl, agno 0
bad agbno 634891646 in agfl, agno 0
bad agbno 3530327926 in agfl, agno 0
bad agbno 3572666895 in agfl, agno 0
bad agbno 1877303917 for inobt root, agno 0
root inode chunk not found
Phase 3 - for each AG...
        - scan and clear agi unlinked lists...
error following ag 0 unlinked list
        - process known inodes and perform inode discovery...
        - agno = 0
imap claims in-use inode 131 is free, correcting imap
imap claims in-use inode 132 is free, correcting imap
imap claims in-use inode 133 is free, correcting imap
imap claims in-use inode 134 is free, correcting imap
imap claims in-use inode 135 is free, correcting imap
imap claims in-use inode 136 is free, correcting imap
imap claims in-use inode 137 is free, correcting imap
imap claims in-use inode 138 is free, correcting imap
imap claims in-use inode 139 is free, correcting imap
imap claims in-use inode 140 is free, correcting imap
imap claims in-use inode 141 is free, correcting imap
imap claims in-use inode 142 is free, correcting imap
imap claims in-use inode 143 is free, correcting imap
        - agno = 1
        - agno = 2
        - agno = 3
        - agno = 4
        - agno = 5
        - agno = 6
        - agno = 7
        - agno = 8
        - agno = 9
        - agno = 10
        - agno = 11
        - agno = 12
        - agno = 13
        - agno = 14
        - agno = 15
        - agno = 16
        - agno = 17
        - agno = 18
        - agno = 19
        - agno = 20
        - agno = 21
        - agno = 22
        - agno = 23
        - agno = 24
        - agno = 25
        - agno = 26
        - agno = 27
        - agno = 28
        - agno = 29
        - agno = 30
        - agno = 31
        - agno = 32
        - agno = 33
        - process newly discovered inodes...
Phase 4 - check for duplicate blocks...
        - setting up duplicate extent list...
        - clear lost+found (if it exists) ...
        - check for inodes claiming duplicate blocks...
        - agno = 0
        - agno = 1
        - agno = 2
        - agno = 3
        - agno = 4
        - agno = 5
        - agno = 6
        - agno = 7
        - agno = 8
        - agno = 9
        - agno = 10
        - agno = 11
        - agno = 12
        - agno = 13
        - agno = 14
        - agno = 15
        - agno = 16
        - agno = 17
        - agno = 18
        - agno = 19
        - agno = 20
        - agno = 21
        - agno = 22
        - agno = 23
        - agno = 24
        - agno = 25
        - agno = 26
        - agno = 27
        - agno = 28
        - agno = 29
        - agno = 30
        - agno = 31
        - agno = 32
        - agno = 33
Phase 5 - rebuild AG headers and trees...
        - reset superblock...
Phase 6 - check inode connectivity...
        - resetting contents of realtime bitmap and summary inodes
        - ensuring existence of lost+found directory
        - traversing filesystem starting at / ... 
        - traversal finished ... 
        - traversing all unattached subtrees ... 
        - traversals finished ... 
        - moving disconnected inodes to lost+found ... 
Phase 7 - verify and correct link counts...
done
# mount /dev/md/1 /tmp/volumes/md1/ -t xfs
# umount /tmp/volumes/md1/

This, btw, happens without any significant load on the xfs filesystem.

I've seen reference in the mailing list to the fact that
xfs_force_shutdown leaves the filesystem in a corrupted state - this
seems to be the case here.

What release of xfs fixes this problem ?  We are considering an upgrade
to 2.4.18 + xfs 1.1 - will that improve our situation ? 

Also, does anyone have an idea what can be the cause to the xfs problem
in the first place ? Have problems been seen using xfs over multipath ? 

We are open to suggestions on how to gather more information on the xfs
problem.



Thanks, 
Yuval Yeret
Email: yuval@exanet.com
www.Exanet.com