xfs
[Top] [All Lists]

xfs_repair segfaulting, and probably xfs_metadata looping

To: xfs@xxxxxxxxxxx
Subject: xfs_repair segfaulting, and probably xfs_metadata looping
From: Eberhard Moenkeberg <emoenke@xxxxxxx>
Date: Sun, 15 Feb 2009 23:27:33 +0100 (CET)
Cc: Frank Funke <ffunke1@xxxxxxx>
Hi,

I have a "damaged" xfs filesystem, and xfs_repair is segfaulting.

It originates from a Lacie NAS appliance which uses a CPU from 

  XScale-IOP8032x Family [69052e20] revision 0 (ARMv5TE)

and during boot the Lacie box is telling:

  Machine: Intel IQ31244

The SCSI controller seems to be Intel IOP3XX, it has 4 SATA drives 500 GB

  SAMSUNG HD501LJ Rev: CR10

This Lacie box uses linux software raid, and I found that the creation of 
the damaged raid array had happened with this command:
 
  mdadm --create /dev/md1 --force --verbose --level=10 --raid-devices=4 
/dev/sda3 /dev/sdb3 /dev/sdc3 /dev/sdd3

which seems to have given this success:

  mdadm: layout defaults to n1
  mdadm: chunk size defaults to 64K
  mdadm: size set to 488123392K
  mdadm: array /dev/md1 started.

(found in log files of the system).

The system got exposed to excessive heat and stopped to work.
The customer took out his disks and sent the box to repair.
After return, the system does not find the data.

I have cloned the disks with dd to SAN LUNs and tried to get the 
filesystem back, under a i386 linux system (SUSE SLES10 SP2).

The raid set did not get recognized, so I gave the (formerly found) raid 
create command:

  mdadm --create /dev/md1 --force --verbose --level=10 --raid-devices=4 
    /dev/mapper/LACIE1-part3 /dev/mapper/LACIE2-part3 
    /dev/mapper/LACIE3-part3 /dev/mapper/LACIE4-part3

with this output:

mdadm: layout defaults to n1
mdadm: chunk size defaults to 64K
mdadm: size set to 488123392K
mdadm: array /dev/md1 started.

After this, /dev/md1 was in state "resyncing" for several hours.

When the resync had finished, I tried to mount - no filesystem found.

Then I inspected a "good" xfs filesystem with dd and hexdump, and I found 
the "good" start pattern within the damaged filesystem at an offset:

0ae0000  58 46 53 42 00 00 10 00 00 00 00 00 0e 8c 0b 00  XFSB............

Within the Lacie box, the data devices are served to the outside by IPStor 
software. I know from our other environment that IPStor places its own 
headers on top of the LUNs, so the part which gets presented to the 
outside begins after an offset.

So I tried to use loop mounting with this offset: 

  losetup -o 11403264 /dev/loop1 /dev/md1
  mount -txfs /dev/loop1 /X

This seemed to bring success:

Feb 13 21:26:18 ftp-i kernel: Filesystem "loop1": Disabling barriers, not 
supported by the underlying device
Feb 13 21:26:18 ftp-i kernel: XFS mounting filesystem loop1
Feb 13 21:26:18 ftp-i kernel: Starting XFS recovery on filesystem: loop1 
(logdev: internal)
Feb 13 21:26:18 ftp-i kernel: XFS resetting qflags for filesystem loop1
Feb 13 21:26:19 ftp-i kernel: Ending XFS recovery on filesystem: loop1 (logdev: 
internal)

But obviously the filesystem needs a repair:

ftp-i:2 21:27:38 /Y # df /X
Filesystem           1K-blocks      Used Available Use% Mounted on
/dev/loop1           976104448 485436352 490668096  50% /X
ftp-i:2 21:27:43 /Y # 

ftp-i:2 21:27:43 /Y # dir /X
/bin/ls: /X/public: No such file or directory
total 0
drwxrwx--- 5 root 11578 69 Mar 23  2007 
drwxrwx--- 5 root 11578 69 Mar 23  2007 .
ftp-i:2 21:28:11 /Y # 

An umount/mount sequence said:

Feb 13 21:29:06 ftp-i kernel: Filesystem "loop1": Disabling barriers, not 
supported by the underlying device
Feb 13 21:29:06 ftp-i kernel: XFS mounting filesystem loop1
Feb 13 21:29:06 ftp-i kernel: Ending clean XFS mount for filesystem: loop1

with the same result: df shows occupied space (which should be correct as 
the customer told me), but ls shows no files.

Then I tried xfs_repair (while umounted), with this result:

ftp-i:2 21:47:09 /Y # xfs_repair -n /dev/loop1 >xfs_repair-n.out 
2>xfs_repair.err
*** buffer overflow detected ***: xfs_repair terminated
======= Backtrace: =========
/lib/libc.so.6(__chk_fail+0x41)[0xb7ee3291]
xfs_repair[0x8065577]
xfs_repair[0x805aef7]
xfs_repair[0x805b3b1]
xfs_repair[0x8050bb2]
xfs_repair[0x80514f3]
xfs_repair[0x8069948]
xfs_repair[0x806a100]
xfs_repair[0x8082c12]

/lib/libc.so.6(__libc_start_main+0xdc)[0xb7e268ac]
xfs_repair[0x804b211]
======= Memory map: ========
08048000-080da000 r-xp 00000000 08:01 590208     /sbin/xfs_repair
080da000-080db000 rw-p 00092000 08:01 590208     /sbin/xfs_repair
080db000-08a1c000 rw-p 080db000 00:00 0          [heap]
ad000000-ad03b000 rw-p ad000000 00:00 0 
ad03b000-ad100000 ---p ad03b000 00:00 0 
ad100000-ad121000 rw-p ad100000 00:00 0 
ad121000-ad200000 ---p ad121000 00:00 0 
ad200000-ad300000 rw-p ad200000 00:00 0 
ad3ff000-ad400000 ---p ad3ff000 00:00 0 
ad400000-adc62000 rw-p ad400000 00:00 0 
adc62000-add00000 ---p adc62000 00:00 0 
add1a000-add24000 r-xp 00000000 08:01 294926     /lib/libgcc_s.so.1
add24000-add25000 rw-p 00009000 08:01 294926     /lib/libgcc_s.so.1
add41000-adf45000 rw-p add41000 00:00 0 
adf45000-adf46000 ---p adf45000 00:00 0 
adf46000-ae746000 rw-p adf46000 00:00 0 
ae746000-ae747000 ---p ae746000 00:00 0 
ae747000-aef47000 rw-p ae747000 00:00 0 
aef47000-aef48000 ---p aef47000 00:00 0 
aef48000-af748000 rw-p aef48000 00:00 0 
af748000-af749000 ---p af748000 00:00 0 
af749000-aff49000 rw-p af749000 00:00 0 
aff49000-aff4a000 ---p aff49000 00:00 0 
aff4a000-b7ddc000 rw-p aff4a000 00:00 0 
b7ddc000-b7e0f000 r--p 00000000 08:02 903441     
/usr/lib/locale/de_DE@euro/LC_CTYPE
b7e0f000-b7e11000 rw-p b7e0f000 00:00 0 
b7e11000-b7f37000 r-xp 00000000 08:01 295274     /lib/libc-2.4.so
b7f37000-b7f39000 r--p 00125000 08:01 295274     /lib/libc-2.4.so
b7f39000-b7f3b000 rw-p 00127000 08:01 295274     /lib/libc-2.4.so
b7f3b000-b7f3e000 rw-p b7f3b000 00:00 0 
b7f3e000-b7f50000 r-xp 00000000 08:01 295300     /lib/libpthread-2.4.so
b7f50000-b7f52000 rw-p 00011000 08:01 295300     /lib/libpthread-2.4.so
b7f52000-b7f54000 rw-p b7f52000 00:00 0 
b7f54000-b7f5b000 r-xp 00000000 08:01 295304     /lib/librt-2.4.so
b7f5b000-b7f5d000 rw-p 00006000 08:01 295304     /lib/librt-2.4.so
b7f5d000-b7f60000 r-xp 00000000 08:01 295669     /lib/libuuid.so.1.2
b7f60000-b7f61000 rw-p 00002000 08:01 295669     /lib/libuuid.so.1.2
b7f7d000-b7f7e000 rw-p b7f7d000 00:00 0 
b7f7e000-b7f98000 r-xp 00000000 08:01 295267     /lib/ld-2.4.so
b7f98000-b7f9a000 rw-p 0001a000 08:01 295267     /lib/ld-2.4.so
bfdb9000-bfdce000 rw-p bfdb9000 00:00 0          [stack]
ffffe000-fffff000 ---p 00000000 00:00 0          [vdso]
Aborted
ftp-i:2 21:47:58 /Y # 

Then I have dd'ed the /dev/loop1 to a native SAN LUN and tried xfs_repair 
without the /dev/loop layer, but same result.

So xfs_repair is aborting.
The error output is appended (xfs_repair.dm-31.err).
These are the first lines:

Phase 1 - find and verify superblock...
Phase 2 - using internal log
        - zero log...
        - scan filesystem freespace and inode maps...
        - found root inode chunk
Phase 3 - for each AG...
        - scan and clear agi unlinked lists...
        - process known inodes and perform inode discovery...
        - agno = 0
entry "" in shortform directory 128 references invalid inode 0
zero length entry in shortform dir 128, junking 3 entries
corrected entry count in directory 128, was 3, now 0
corrected directory 128 size, was 69, now 6
bogus .. inode number (0) in directory inode 128, clearing inode number
entry "" in shortform directory 132 references invalid inode 0
zero length entry in shortform dir 132, junking 255 entries
corrected directory 132 size, was 8, now 6
bogus .. inode number (0) in directory inode 132, clearing inode number
size of entry #0 overflows space left in in shortform dir 3524
junking 4 entries
corrected entry count in directory 3524, was 4, now 0
corrected directory 3524 size, was 120, now 6
size of entry #0 overflows space left in in shortform dir 3527
junking 5 entries

Then I tried xfs_check, output is in second attachment (xfs_check.090215).
These are the first lines:

dir 128 entry                                           public bad offset 0
dir 128 bad size in entry at 68
root directory 128 has .. 0
dir 132 size is 8, should be 6
dir 3524 bad size in entry at 6
dir 3527 bad size in entry at 6
dir 3533 bad size in entry at 6
dir 3540 bad size in entry at 6
dir 3547 bad size in entry at 6
dir 3559 bad size in entry at 6
dir 3567 bad size in entry at 6
dir 3570 bad size in entry at 6
dir 3578 bad size in entry at 6
dir 3581 entry         w bad offset 11894
dir 3581 bad size in entry at 96
dir 3581 offsets too high
dir 69043742 bad size in entry at 13
dir 69043742 offsets too high
dir 71351171 bad size in entry at 6
dir 71351174 bad size in entry at 53
dir 71351174 offsets too high
dir 71351201 bad size in entry at 6

Then I tried xfs_ncheck, which brought a nice list of inode numbers and 
path names (third attachment).
The first lines:

  103748414 MM-TPLSM1-DATA/DATA2002/12-02-02/12Feb02120818-018.gif
  103590728 MM-TPLSM1-DATA/DATA2002/28-01-02/28Jan02133928-092.gif
  103389454 MM-TPLSM1-DATA/DATA2001/04-12-01/4Dez01113518-006.gif
  103006777 E-physiol/rat10001-15000/RT12615.abf
   97668529 MM-TPLSM1-DATA/hippocampus/23-09-03H/23Sep03111418-118.tif
   79966673 E-physiol/rat10001-15000/rt12208.abf
   79908342 E-physiol/rat10001-15000/rt11728.abf

At last I tried 

  xfs_metadump -w /dev/dm-30 /Z/metadump.090215 >metadump.090215.log 
2>metadump.090215.err

which created this file:

  -rw-r--r--  1 root root 39256064 Feb 15 13:54 metadump.090215

and the error output of the fourth attachment (metadump.090215.err).

The xfs_metadump command is still running for many hours now after 
producing file and output, using a full CPU, being absolutely silent:

10251 ?        S      0:00 [kjournald]
10745 ?        S<     0:00 [xfslogd/0]
10747 ?        S<     0:00 [xfslogd/1]
10748 ?        S<     0:00 [xfslogd/2]
10749 ?        S<     0:00 [xfslogd/3]
10750 ?        S<     0:00 [xfsdatad/0]
10751 ?        S<     0:00 [xfsdatad/1]
10752 ?        S<     0:00 [xfsdatad/2]
10753 ?        S<     0:00 [xfsdatad/3]
10754 ?        S<     0:00 [xfs_mru_cache]
11935 ?        S<     0:01 [xfsbufd]
11936 ?        S<     0:00 [xfssyncd]
12203 ?        S      0:00 [kjournald]
12475 pts/1    S+     0:00 /bin/sh -f /usr/sbin/xfs_metadump -w /dev/dm-30 
/Z/metadump.090215
12476 pts/1    R+   558:41 xfs_db -i -p xfs_metadump -c metadump -w  
/Z/metadump.090215 /dev/dm-30
16621 pts/0    R+     0:00 ps --sort start_time xww


Is this a programming loop, or can I hope that the process will come to an 
end some time? I can let it run for days this way if there is the chance 
to get any effort.

Can you give me an advice what to try next to restore the data?

Are you willing to process the xfs_repair segfault (and maybe the 
xfs_metadump processing loop) as a bug?
I would be at help with all I can do.


Viele Grüße
Eberhard Mönkeberg (emoenke@xxxxxxx, em@xxxxxxx)

-- 
Eberhard Mönkeberg
Arbeitsgruppe IT-Infrastruktur
E-Mail: emoenke@xxxxxxx      Tel.: +49 (0)551 201-1551
-------------------------------------------------------------------------
Gesellschaft für wissenschaftliche Datenverarbeitung mbH Göttingen (GWDG)
Am Fassberg 11, 37077 Göttingen
URL:    http://www.gwdg.de             E-Mail: gwdg@xxxxxxx
Tel.:   +49 (0)551 201-1510            Fax:    +49 (0)551 201-2150
Geschäftsführer:           Prof. Dr. Bernhard Neumair
Aufsichtsratsvorsitzender: Dipl.-Kfm. Markus Hoppe
Sitz der Gesellschaft:     Göttingen
Registergericht:           Göttingen  Handelsregister-Nr. B 598
-------------------------------------------------------------------------

Attachment: xfs_repair.dm-31.err
Description: Text document

Attachment: xfs_check.090215
Description: Text document

Attachment: xfs_ncheck.090215
Description: Text document

Attachment: metadump.090215.err
Description: Text document

<Prev in Thread] Current Thread [Next in Thread>
  • xfs_repair segfaulting, and probably xfs_metadata looping, Eberhard Moenkeberg <=