Skip to contentSkip to conversation

xfs crash

DISCUSSION Cedric - Equinoxe Media 3 participants 7 messages Nov 5, 2007 – Nov 7, 2007 1 message not in the archive

lore
Share & tools
lore
#0 lore raw

Hi,

I got a crash with xfs serving nfs :

Hardware is Dell Poweredge 2950 with RAID5 SAS
Linux fng2 2.6.22-3-amd64 #1 SMP Wed Oct 31 13:43:07 UTC 2007 x86_64 GNU/Linux

Here is the dmesg :

NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory
NFSD: starting 90-second grace period
XFS internal error XFS_WANT_CORRUPTED_GOTO at line 1563 of file fs/xfs/xfs_alloc.c. Caller 0xffffffff88113b35

Call Trace:
 [<ffffffff88111fcb>] :xfs:xfs_free_ag_extent+0x1a6/0x6b5
 [<ffffffff88113b35>] :xfs:xfs_free_extent+0xa9/0xc9
 [<ffffffff8811cf77>] :xfs:xfs_bmap_finish+0xee/0x167
 [<ffffffff8813c843>] :xfs:xfs_itruncate_finish+0x19b/0x2e0
 [<ffffffff881543c1>] :xfs:xfs_setattr+0x841/0xe57
 [<ffffffff8023a29e>] __mod_timer+0xc3/0xd3
 [<ffffffff80229db3>] task_rq_lock+0x3d/0x6f
 [<ffffffff80229976>] __activate_task+0x26/0x38
 [<ffffffff8815eae8>] :xfs:xfs_vn_setattr+0x121/0x144
 [<ffffffff80296791>] notify_change+0x156/0x2f1
 [<ffffffff88309aba>] :nfsd:nfsd_setattr+0x334/0x4b1
 [<ffffffff883102e2>] :nfsd:nfsd3_proc_setattr+0xa2/0xae
 [<ffffffff8830524d>] :nfsd:nfsd_dispatch+0xdd/0x19e
 [<ffffffff88283180>] :sunrpc:svc_process+0x3df/0x6ef
 [<ffffffff803f4cc2>] __down_read+0x12/0x9a
 [<ffffffff88305815>] :nfsd:nfsd+0x191/0x2ac
 [<ffffffff8020aba8>] child_rip+0xa/0x12
 [<ffffffff88305684>] :nfsd:nfsd+0x0/0x2ac
 [<ffffffff8020ab9e>] child_rip+0x0/0x12

xfs_force_shutdown(sda4,0x8) called from line 4258 of file fs/xfs/xfs_bmap.c. Return address = 0xffffffff8811cfb4 Filesystem "sda4": Corruption of in-memory data detected. Shutting down
filesystem: sda4
Please umount the filesystem, and rectify the problem(s)
nfsd: non-standard errno: -117

----------------
Here I stopped nfs, umount -f /dev/sda4, mount /dev/sda4 then start nfs again.
----------------

nfsd: last server has exited
nfsd: unexporting all filesystems xfs_force_shutdown(sda4,0x1) called from line 423 of file fs/xfs/xfs_rw.c. Return address = 0xffffffff88158289 xfs_force_shutdown(sda4,0x1) called from line 423 of file fs/xfs/xfs_rw.c. Return address = 0xffffffff88158289 XFS mounting filesystem sda4
Starting XFS recovery on filesystem: sda4 (logdev: internal) XFS internal error XFS_WANT_CORRUPTED_GOTO at line 1563 of file fs/xfs/xfs_alloc.c. Caller 0xffffffff88113b35

Call Trace:
 [<ffffffff88111fcb>] :xfs:xfs_free_ag_extent+0x1a6/0x6b5
 [<ffffffff88113b35>] :xfs:xfs_free_extent+0xa9/0xc9
 [<ffffffff88145edf>] :xfs:xlog_recover_process_efi+0xf7/0x12a
 [<ffffffff88147288>] :xfs:xlog_recover_process_efis+0x4f/0x81
 [<ffffffff881472d3>] :xfs:xlog_recover_finish+0x19/0x9a
 [<ffffffff8814bd22>] :xfs:xfs_mountfs+0x83d/0x91b
 [<ffffffff802f4b29>] _atomic_dec_and_lock+0x39/0x58
 [<ffffffff88151b34>] :xfs:xfs_mount+0x317/0x39d
 [<ffffffff88161889>] :xfs:xfs_fs_fill_super+0x0/0x1a7
 [<ffffffff88161907>] :xfs:xfs_fs_fill_super+0x7e/0x1a7
 [<ffffffff803f4c21>] __down_write_nested+0x12/0x9a
 [<ffffffff80297003>] get_filesystem+0x12/0x35
 [<ffffffff80284ff5>] sget+0x39d/0x3af
 [<ffffffff80284a0c>] set_bdev_super+0x0/0xf
 [<ffffffff80284a1b>] test_bdev_super+0x0/0xd
 [<ffffffff80285a35>] get_sb_bdev+0x105/0x152
 [<ffffffff8028542a>] vfs_kern_mount+0x93/0x11a
 [<ffffffff80285500>] do_kern_mount+0x43/0xdd
 [<ffffffff80298eda>] do_mount+0x691/0x708
 [<ffffffff80297a3c>] mntput_no_expire+0x1c/0x94
 [<ffffffff8028cba5>] link_path_walk+0xce/0xe0
 [<ffffffff80266af7>] activate_page+0xad/0xd4
 [<ffffffff8025ff17>] find_get_page+0x21/0x50
 [<ffffffff80262028>] filemap_nopage+0x180/0x2ab
 [<ffffffff8026c709>] __handle_mm_fault+0x3e6/0x9d9
 [<ffffffff80269c17>] zone_statistics+0x3f/0x60
 [<ffffffff802f796f>] __up_read+0x13/0x8a
 [<ffffffff802646fe>] __alloc_pages+0x5a/0x2bc
 [<ffffffff80298fdb>] sys_mount+0x8a/0xd7
 [<ffffffff80209d8e>] system_call+0x7e/0x83

Ending XFS recovery on filesystem: sda4 (logdev: internal)
NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory
NFSD: starting 90-second grace period

I have no other message in the dmesg, the server has latest RAID firmware from dell.

Cédric.

A message that is not in the archive (sent off-list or not yet received): [email protected]

#2 lore raw
Quoted 11 lines · David Chinner
Quoted 9 lines · Cedric - Equinoxe Media

XFS internal error XFS_WANT_CORRUPTED_GOTO at line 1563 of file fs/xfs/xfs_alloc.c. Caller 0xffffffff88113b35

Call Trace:
 [<ffffffff88111fcb>] :xfs:xfs_free_ag_extent+0x1a6/0x6b5
 [<ffffffff88113b35>] :xfs:xfs_free_extent+0xa9/0xc9
 [<ffffffff8811cf77>] :xfs:xfs_bmap_finish+0xee/0x167
 [<ffffffff8813c843>] :xfs:xfs_itruncate_finish+0x19b/0x2e0
 [<ffffffff881543c1>] :xfs:xfs_setattr+0x841/0xe57
Quoted 3 lines

Corrupted free space btree, by the look of it. Can you run xfs_check on the filesystem and report the output. You can recover from this by running xfs_repair.

xfs_check /dev/sda4 :
bad format 2 for inode 2961770479 type 0
bad format 2 for inode 3229517262 type 0
block 20/621714 type unknown not expected
link count mismatch for inode 2961770479 (name ?), nlink 0, counted 1 link count mismatch for inode 3229517262 (name ?), nlink 0, counted 1

the xfs_repair worked perfectly.

Do you have an idea why this corruption happened ?

Thanks.
Cédric

#3 lore raw

I just had exactly the same crash again today :
/dev/sda4 on /filer type xfs (rw,noexec,nosuid,nodev,noatime)

Nov  6 16:40:24 fng2 kernel: XFS internal error XFS_WANT_CORRUPTED_GOTO at line 1563 of file fs/xfs/xfs_alloc.c.  Caller 0xffffffff88113b35
Nov  6 16:40:24 fng2 kernel: 
Nov  6 16:40:24 fng2 kernel: Call Trace:
Nov  6 16:40:24 fng2 kernel:  [<ffffffff88111fcb>] :xfs:xfs_free_ag_extent+0x1a6/0x6b5
Nov  6 16:40:24 fng2 kernel:  [<ffffffff88113b35>] :xfs:xfs_free_extent+0xa9/0xc9
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8811cf77>] :xfs:xfs_bmap_finish+0xee/0x167
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8813c843>] :xfs:xfs_itruncate_finish+0x19b/0x2e0
Nov  6 16:40:24 fng2 kernel:  [<ffffffff881543c1>] :xfs:xfs_setattr+0x841/0xe57
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8815c328>] :xfs:xfs_fs_get_dentry+0x38/0x59
Nov  6 16:40:24 fng2 kernel:  [<ffffffff80229db3>] task_rq_lock+0x3d/0x6f
Nov  6 16:40:24 fng2 kernel:  [<ffffffff80229976>] __activate_task+0x26/0x38
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8815eae8>] :xfs:xfs_vn_setattr+0x121/0x144
Nov  6 16:40:24 fng2 kernel:  [<ffffffff80296791>] notify_change+0x156/0x2f1
Nov  6 16:40:24 fng2 kernel:  [<ffffffff88309aba>] :nfsd:nfsd_setattr+0x334/0x4b1
Nov  6 16:40:24 fng2 kernel:  [<ffffffff883102e2>] :nfsd:nfsd3_proc_setattr+0xa2/0xae
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8830524d>] :nfsd:nfsd_dispatch+0xdd/0x19e
Nov  6 16:40:24 fng2 kernel:  [<ffffffff88283180>] :sunrpc:svc_process+0x3df/0x6ef
Nov  6 16:40:24 fng2 kernel:  [<ffffffff803f4cc2>] __down_read+0x12/0x9a
Nov  6 16:40:24 fng2 kernel:  [<ffffffff88305815>] :nfsd:nfsd+0x191/0x2ac
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8020aba8>] child_rip+0xa/0x12
Nov  6 16:40:24 fng2 kernel:  [<ffffffff88305684>] :nfsd:nfsd+0x0/0x2ac
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8020ab9e>] child_rip+0x0/0x12
Nov  6 16:40:24 fng2 kernel: 
Nov  6 16:40:24 fng2 kernel: xfs_force_shutdown(sda4,0x8) called from line 4258 of file fs/xfs/xfs_bmap.c.  Return address = 0xffffffff8811cfb4
Nov  6 16:40:24 fng2 kernel: Filesystem "sda4": Corruption of in-memory data detected.  Shutting down filesystem: sda4
Nov  6 16:40:24 fng2 kernel: Please umount the filesystem, and rectify the problem(s)

Seems to be again on a setattr() ?

Regards.
Cédric

#4 lore raw
Quoted 30 lines · Cedric - Equinoxe Media

I just had exactly the same crash again today :
/dev/sda4 on /filer type xfs (rw,noexec,nosuid,nodev,noatime)

Nov  6 16:40:24 fng2 kernel: XFS internal error XFS_WANT_CORRUPTED_GOTO at line 1563 of file fs/xfs/xfs_alloc.c.  Caller 0xffffffff88113b35
Nov  6 16:40:24 fng2 kernel:
Nov  6 16:40:24 fng2 kernel: Call Trace:
Nov  6 16:40:24 fng2 kernel:  [<ffffffff88111fcb>] :xfs:xfs_free_ag_extent+0x1a6/0x6b5
Nov  6 16:40:24 fng2 kernel:  [<ffffffff88113b35>] :xfs:xfs_free_extent+0xa9/0xc9
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8811cf77>] :xfs:xfs_bmap_finish+0xee/0x167
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8813c843>] :xfs:xfs_itruncate_finish+0x19b/0x2e0
Nov  6 16:40:24 fng2 kernel:  [<ffffffff881543c1>] :xfs:xfs_setattr+0x841/0xe57
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8815c328>] :xfs:xfs_fs_get_dentry+0x38/0x59
Nov  6 16:40:24 fng2 kernel:  [<ffffffff80229db3>] task_rq_lock+0x3d/0x6f
Nov  6 16:40:24 fng2 kernel:  [<ffffffff80229976>] __activate_task+0x26/0x38
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8815eae8>] :xfs:xfs_vn_setattr+0x121/0x144
Nov  6 16:40:24 fng2 kernel:  [<ffffffff80296791>] notify_change+0x156/0x2f1
Nov  6 16:40:24 fng2 kernel:  [<ffffffff88309aba>] :nfsd:nfsd_setattr+0x334/0x4b1
Nov  6 16:40:24 fng2 kernel:  [<ffffffff883102e2>] :nfsd:nfsd3_proc_setattr+0xa2/0xae
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8830524d>] :nfsd:nfsd_dispatch+0xdd/0x19e
Nov  6 16:40:24 fng2 kernel:  [<ffffffff88283180>] :sunrpc:svc_process+0x3df/0x6ef
Nov  6 16:40:24 fng2 kernel:  [<ffffffff803f4cc2>] __down_read+0x12/0x9a
Nov  6 16:40:24 fng2 kernel:  [<ffffffff88305815>] :nfsd:nfsd+0x191/0x2ac
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8020aba8>] child_rip+0xa/0x12
Nov  6 16:40:24 fng2 kernel:  [<ffffffff88305684>] :nfsd:nfsd+0x0/0x2ac
Nov  6 16:40:24 fng2 kernel:  [<ffffffff8020ab9e>] child_rip+0x0/0x12
Nov  6 16:40:24 fng2 kernel:
Nov  6 16:40:24 fng2 kernel: xfs_force_shutdown(sda4,0x8) called from line 4258 of file fs/xfs/xfs_bmap.c.  Return address = 0xffffffff8811cfb4
Nov  6 16:40:24 fng2 kernel: Filesystem "sda4": Corruption of in-memory data detected.  Shutting down filesystem: sda4
Nov  6 16:40:24 fng2 kernel: Please umount the filesystem, and rectify the problem(s)
Quoted 6 lines

Seems to be again on a setattr() ?

Regards.
Cédric

Have you run a memory test on your server? memtest86

#5 lore raw
Quoted 1 line · Justin Piszcz

Have you run a memory test on your server? memtest86

But I doubt it is hardware memory corruption because it is a brand new dell server with ECC memory and the backtrace is always the same.

Anyway I will do the memtest tomorrow...

I also have a spare server, If I find nothing I will move everything to the spare and wait for the possible bug to appear again.

Regards
Cédric

#6 lore raw
In reply to Cedric - Equinoxe Media
Quoted 2 lines · Cedric - Equinoxe Media

I just had exactly the same crash again today :
/dev/sda4 on /filer type xfs (rw,noexec,nosuid,nodev,noatime)

What did xfs_check tell you about the corruption?

Quoted 1 line

Seems to be again on a setattr() ?

Doing a truncation freeing some blocks.

What is the client doing (i.e. io patterns, application, etc) to cause this? can you reproduce it without NFS being used? To track this down I'm going to need a reproducable test case....

Seeing this is a brand new server, have you run and soak or stress test on the raw storage to confirm it is error free?

Cheers,

Dave.

Signature · 3 lines
Dave Chinner
Principal Engineer
SGI Australian Software Group
#7 lore raw
Quoted 5 lines · David Chinner
Quoted 2 lines · Cedric - Equinoxe Media

I just had exactly the same crash again today :
/dev/sda4 on /filer type xfs (rw,noexec,nosuid,nodev,noatime)

What did xfs_check tell you about the corruption?

I had quite the same message as last time, forgot to copy/paste...

Quoted 7 lines
Quoted 1 line

Seems to be again on a setattr() ?

Doing a truncation freeing some blocks.

What is the client doing (i.e. io patterns, application, etc) to cause this? can you reproduce it without NFS being used? To track this down I'm going to need a reproducable test case....

It is 5 web servers with php as nfsv3 clients.

Quoted 2 lines

Seeing this is a brand new server, have you run and soak or stress test on the raw storage to confirm it is error free?

I have run bonnie++ and memtest86+ with no errors.

I am now trying to recompile linux without nfsv4, ACL and all experimental features of nfs and xfs.

Signature · 3 lines
Cédric Tabary
Ingénieur réseau - Equinoxe Media
+33 (0)6 77 45 80 15