File system corruption
In short, I am able to: mkfs...; mount...; cp 1gbfile...; sync; cp 1gbfile...; sync # and now the xfs is corrupt
I see multiple bugs
1. very simple, non-corner-case actions create a corrupted file system
2. corrupt data is knowingly written to the file system.
3. the file system stays online and writable
4. future write operations to the file system return success.
Details:
[wwalker@speedy ~] [] $ cat xfs_bug_report
bash-4.1# uname -a
Linux localhost.localdomain 2.6.32-71.29.1.el6.x86_64 #1 SMP Mon Jun 27 19:49:27 BST 2011 x86_64 x86_64 x86_64 GNU/Linux
bash-4.1# xfs_repair -Vxfs_repair version 3.1.1
bash-4.1# cat /proc/meminfo
MemTotal: 98933876 kB MemFree: 10626620 kB Buffers: 88828 kB Cached: 1693684 kB SwapCached: 0 kB Active: 2094048 kB Inactive: 278972 kB Active(anon): 1713716 kB Inactive(anon): 95388 kB Active(file): 380332 kB Inactive(file): 183584 kB Unevictable: 0 kB Mlocked: 0 kB SwapTotal: 20479992 kB SwapFree: 20479992 kB Dirty: 208 kB Writeback: 0 kB AnonPages: 590704 kB Mapped: 57760 kB Shmem: 1218600 kB Slab: 1761776 kB SReclaimable: 142184 kB SUnreclaim: 1619592 kB KernelStack: 4632 kB PageTables: 13496 kB NFS_Unstable: 0 kB Bounce: 0 kB WritebackTmp: 0 kB CommitLimit: 28003888 kB Committed_AS: 3281984 kB VmallocTotal: 34359738367 kB VmallocUsed: 489664 kB VmallocChunk: 34307745544 kB HardwareCorrupted: 0 kB AnonHugePages: 0 kB HugePages_Total: 40960 HugePages_Free: 40794 HugePages_Rsvd: 173 HugePages_Surp: 0 Hugepagesize: 2048 kB DirectMap4k: 5632 kB DirectMap2M: 2082816 kB DirectMap1G: 98566144 kB
bash-4.1# # 2 CPUs, E5620 8 core procs
bash-4.1# cat /proc/cpuinfo
processor : 0vendor_id : GenuineIntel
cpu family : 6
model : 44
model name : Intel(R) Xeon(R) CPU E5620 @ 2.40GHz
stepping : 2
cpu MHz : 1600.000
cache size : 12288 KB
physical id : 0
siblings : 8
core id : 0
cpu cores : 4
apicid : 0
initial apicid : 0
fpu : yesfpu_exception : yes
cpuid level : 11
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm dca sse4_1 sse4_2 popcnt aes lahf_lm ida arat tpr_shadow vnmi flexpriority ept vpid
bogomips : 4800.20
clflush size : 64cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management:
<14 core reports deleted>
processor : 15vendor_id : GenuineIntel
cpu family : 6
model : 44
model name : Intel(R) Xeon(R) CPU E5620 @ 2.40GHz
stepping : 2
cpu MHz : 1600.000
cache size : 12288 KB
physical id : 1
siblings : 8
core id : 10
cpu cores : 4
apicid : 53
initial apicid : 53
fpu : yesfpu_exception : yes
cpuid level : 11
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm dca sse4_1 sse4_2 popcnt aes lahf_lm ida arat tpr_shadow vnmi flexpriority ept vpid
bogomips : 4799.88
clflush size : 64cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management:
bash-4.1# cat /proc/mounts
rootfs / rootfs rw 0 0
/proc /proc proc rw,relatime 0 0
/sys /sys sysfs rw,relatime 0 0
udev /dev devtmpfs rw,relatime,size=49459988k,nr_inodes=12364997,mode=755 0 0
devpts /dev/pts devpts rw,relatime,gid=5,mode=620,ptmxmode=000 0 0
tmpfs /dev/shm tmpfs rw,relatime 0 0/dev/sdb1 / ext3 rw,relatime,errors=continue,user_xattr,acl,barrier=1,data=ordered 0 0 /proc/bus/usb /proc/bus/usb usbfs rw,relatime 0 0/dev/sdb5 /core xfs rw,relatime,attr2,noquota 0 0/dev/sdb6 /data xfs rw,relatime,attr2,noquota 0 0/dev/sdd1 /database xfs rw,relatime,attr2,noquota 0 0/dev/sdb2 /secondary ext3 rw,relatime,errors=continue,user_xattr,acl,barrier=1,data=ordered 0 0 tmpfs /dev/shm tmpfs rw,relatime 0 0/dev/sda1 /vpd xfs rw,noatime,attr2,sunit=2048,swidth=8192,noquota 0 0/dev/sda8 /cfg_backup xfs rw,noatime,attr2,sunit=2048,swidth=8192,noquota 0 0/dev/sdg1 /db_backup xfs rw,relatime,attr2,sunit=2048,swidth=8192,noquota 0 0/dev/sdf1 /dtfs_data/data2 xfs rw,noatime,attr2,nobarrier,logdev=/dev/sda6,sunit=2048,swidth=8192,noquota 0 0 /dev/sdh1 /dtfs_data/data3 xfs rw,noatime,attr2,nobarrier,logdev=/dev/sda7,sunit=2048,swidth=8192,noquota 0 0 none /proc/sys/fs/binfmt_misc binfmt_misc rw,relatime 0 0
sunrpc /var/lib/nfs/rpc_pipefs rpc_pipefs rw,relatime 0 0/etc/auto.misc /misc autofs rw,relatime,fd=7,pgrp=2972,timeout=300,minproto=5,maxproto=5,indirect 0 0 -hosts /net autofs rw,relatime,fd=13,pgrp=2972,timeout=300,minproto=5,maxproto=5,indirect 0 0
bash-4.1# cat /proc/partitions
major minor #blocks name
8 0 39082680 sda 8 1 18432 sda1 8 2 391168 sda2 8 3 390144 sda3 8 4 1 sda4 8 5 389120 sda5 8 6 390144 sda6 8 7 389120 sda7 8 8 37108736 sda8 8 16 78150744 sdb 8 17 10240000 sdb1 8 18 10240000 sdb2 8 19 20480000 sdb3 8 20 1 sdb4 8 21 5120000 sdb5 8 22 32067584 sdb6 8 48 2254857216 sdd 8 49 2147482624 sdd1 8 32 4731979776 sdc 8 33 4731977728 sdc1 8 64 4732048384 sde 8 65 4732046336 sde1 8 96 712964096 sdg 8 97 712962048 sdg1
8 112 5502995456 sdh
8 113 5502993408 sdh1
8 80 5502925824 sdf
8 81 5502923776 sdf1
bash-4.1# lspci | grep -i RAID
84:00.0 RAID bus controller: LSI Logic / Symbios Logic MegaRAID SAS 2208 [Thunderbolt] (rev 01) 85:00.0 RAID bus controller: LSI Logic / Symbios Logic MegaRAID SAS 2208 [Thunderbolt] (rev 01)
There is an SSD (INTEL SSDSA2CT040G3; sda) used as an external log.
Each controller has 8 SEAGATE ST33000650SS 3 TB SATA drives.
The file system with a problem (sde1) is a RAID 6 made up of 6 drives and split into 3 pieces (sdc, sdd, sde) of roughly 4.7 TB, 2.2 TB, 4.7 TB. sdc and sdd are mounted but are idle (sdc) or probably idle (sdd has postgres data on it but no transactions occurring) during the steps to produce a corrupt fs.
There are no LVMs in use
Both BBUs are fully charged and good
All VDs are set to: WriteBack, ReadAhead, Direct, No Write Cache if bad BBU
There is no significant IO or CPU load on the machine at all during the tests.
The exact commands to create the failure:
/sbin/mkfs.xfs -f -l logdev=/dev/sda5 -b size=4096 -d su=1024k,sw=4 /dev/sde1 cat /etc/fstab
mount -t xfs -o defaults,noatime,logdev=/dev/sda5 /dev/sde1 /dtfs_data/data1 cp random_data.1G /dtfs_data/data1
# returns 0 sync # file system reported no failure yet cp random_data.1G /dtfs_data/data1 # returns 0 sync # file system reports stack trace, bad agf, and page discard
bash-4.1# xfs_info /dtfs_data/data1
meta-data=/dev/sde1 isize=256 agcount=5, agsize=268435200 blks
= sectsz=512 attr=2
data = bsize=4096 blocks=1183011584, imaxpct=5
= sunit=256 swidth=1024 blks
naming =version 2 bsize=4096 ascii-ci=0
log =external bsize=4096 blocks=97280, version=2
= sectsz=512 sunit=0 blks, lazy-count=1
realtime =none extsz=4096 blocks=0, rtextents=0_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs
Quoted 10 lines · Wayne Walker
In short, I am able to: mkfs...; mount...; cp 1gbfile...; sync; cp 1gbfile...; sync # and now the xfs is corrupt
I see multiple bugs
1. very simple, non-corner-case actions create a corrupted file system
2. corrupt data is knowingly written to the file system.
3. the file system stays online and writable
4. future write operations to the file system return success.Details:
<snip>
I left out that the files written to disk have data after the first 4K, but the first 4K is 0's..
And I left out the dmesg info:
XFS mounting filesystem sde1
Ending clean XFS mount for filesystem: sde1ffff880d244f1200: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Filesystem "sde1": XFS internal error xfs_alloc_read_agf at line 2157 of file fs/xfs/xfs_alloc.c. Caller 0xffffffffa01c0989
Pid: 18009, comm: flush-8:64 Not tainted 2.6.32-71.29.1.el6.x86_64 #1
Call Trace: [<ffffffffa01eacc3>] xfs_error_report+0x43/0x50 [xfs] [<ffffffffa01c0989>] ? xfs_alloc_read_agf+0x39/0xe0 [xfs] [<ffffffffa01ead2a>] xfs_corruption_error+0x5a/0x70 [xfs] [<ffffffffa01c08af>] xfs_read_agf+0xef/0x190 [xfs] [<ffffffffa01c0989>] ? xfs_alloc_read_agf+0x39/0xe0 [xfs] [<ffffffff81156a90>] ? cache_alloc_refill+0x1c0/0x240 [<ffffffffa01c0989>] xfs_alloc_read_agf+0x39/0xe0 [xfs] [<ffffffffa01c2dd4>] xfs_alloc_fix_freelist+0x2f4/0x480 [xfs] [<ffffffff812593c9>] ? cpumask_next_and+0x29/0x50 [<ffffffff81062c74>] ? find_busiest_group+0x254/0xb40 [<ffffffffa0203fc8>] ? xfs_perag_get+0x48/0xc0 [xfs] [<ffffffffa01c3193>] xfs_alloc_vextent+0x173/0x600 [xfs] [<ffffffffa0203fc8>] ? xfs_perag_get+0x48/0xc0 [xfs] [<ffffffffa01cd2a7>] xfs_bmap_btalloc+0x167/0x9d0 [xfs] [<ffffffffa01cdb1e>] xfs_bmap_alloc+0xe/0x10 [xfs] [<ffffffffa01d4696>] xfs_bmapi+0x9f6/0x11a0 [xfs] [<ffffffffa01fd3c0>] ? xfs_log_reserve+0xf0/0x150 [xfs] [<ffffffff814cad26>] ? down_write+0x16/0x40 [<ffffffffa01f6b75>] xfs_iomap_write_allocate+0x1c5/0x3b0 [xfs] [<ffffffff81264e08>] ? call_rwsem_wake+0x18/0x30 [<ffffffffa01f78b9>] xfs_iomap+0x389/0x440 [xfs] [<ffffffff8119633b>] ? __mark_inode_dirty+0x3b/0x160 [<ffffffffa0210dbd>] xfs_map_blocks+0x2d/0x40 [xfs] [<ffffffffa0212408>] xfs_page_state_convert+0x2f8/0x750 [xfs] [<ffffffff8125ec05>] ? radix_tree_gang_lookup_tag_slot+0x95/0xe0 [<ffffffffa0212a16>] xfs_vm_writepage+0x86/0x170 [xfs] [<ffffffff8111f6e7>] __writepage+0x17/0x40 [<ffffffff81120979>] write_cache_pages+0x189/0x430 [<ffffffff8111f6d0>] ? __writepage+0x0/0x40 [<ffffffff81120c44>] generic_writepages+0x24/0x30 [<ffffffffa02117fe>] xfs_vm_writepages+0x5e/0x80 [xfs] [<ffffffff81120c71>] do_writepages+0x21/0x40 [<ffffffff8119694d>] writeback_single_inode+0xdd/0x2c0 [<ffffffff81196d4e>] writeback_sb_inodes+0xce/0x180 [<ffffffff81196ea3>] writeback_inodes_wb+0xa3/0x1a0 [<ffffffff8119723b>] wb_writeback+0x29b/0x3f0 [<ffffffff814c92b6>] ? thread_return+0x4e/0x778 [<ffffffff8119744b>] wb_do_writeback+0xbb/0x240 [<ffffffff81197633>] bdi_writeback_task+0x63/0x1b0 [<ffffffff81091d67>] ? bit_waitqueue+0x17/0xd0 [<ffffffff8112f040>] ? bdi_start_fn+0x0/0x100 [<ffffffff8112f0c6>] bdi_start_fn+0x86/0x100 [<ffffffff8112f040>] ? bdi_start_fn+0x0/0x100 [<ffffffff81091b36>] kthread+0x96/0xa0 [<ffffffff810141ca>] child_rip+0xa/0x20 [<ffffffff81091aa0>] ? kthread+0x0/0xa0 [<ffffffff810141c0>] ? child_rip+0x0/0x20
Filesystem "sde1": page discard on page ffffea0003cfc418, inode 0x1004, offset 0.
_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs
Quoted 11 lines · Wayne Walker
In short, I am able to: mkfs...; mount...; cp 1gbfile...; sync; cp 1gbfile...; sync # and now the xfs is corrupt
I see multiple bugs
1. very simple, non-corner-case actions create a corrupted file system
2. corrupt data is knowingly written to the file system.
3. the file system stays online and writable
4. future write operations to the file system return success.Details:
.....
Nothing unusual there in the hardware. Seems sane to me.
Quoted 7 lines
The exact commands to create the failure:
/sbin/mkfs.xfs-f -l logdev=/dev/sda5 -b size=4096 -d su=1024k,sw=4/dev/sde1
cat/etc/fstab
mount -t xfs -o defaults,noatime,logdev=/dev/sda5/dev/sde1/dtfs_data/data1 cp random_data.1G /dtfs_data/data1
Quoted 7 lines
# returns 0 sync # file system reported no failure yet cp random_data.1G /dtfs_data/data1 # returns 0 sync # file system reports stack trace, bad agf, and page discard
Ok, so having looked at the stack trace, the AGF block taht was read contained zeros, not valid metadata, which is why the allocation failed.
Can you remake the filesystem at will? If so, can you run mkfs.xfs as per above, then run the following command?
# echo 3 > /proc/sys/vm/drop_caches # for i in `seq 0 4`; do
Quoted 2 lines
xfs_db-l/dev/sda5-c "sb $i" -c p -c "agf $i" -c p/dev/sde1done
So that we can see what mkfs put on disk? Can you then mount the filesystem, unmount it again, and run the same commands? Then mount the filesystem, run the copy/sync to trigger the error, then unmount and run the commands again?
What I'm interested in if whether xfs_db sees the AGF (which ever one it is) as zero, or whether only the kernel is seeing that.
Cheers,
Dave.
Signature · 7 lines
Dave Chinner [email protected] _______________________________________________ xfs mailing list [email protected] http://oss.sgi.com/mailman/listinfo/xfs
A message that is not in the archive (sent off-list or not yet received): [email protected]
[cc'd the list again so everyone can see what is happening]
Quoted 22 lines · Wayne Walker
On 10/11/2012 04:07 PM, Dave Chinner wrote:
<snip>Quoted 11 lines
Ok, so having looked at the stack trace, the AGF block taht was read contained zeros, not valid metadata, which is why the allocation failed.
Can you remake the filesystem at will? If so, can you run mkfs.xfs as per above, then run the following command?
# echo 3 > /proc/sys/vm/drop_caches # for i in `seq 0 4`; doQuoted 2 lines
xfs_db-l/dev/sda5-c "sb $i" -c p -c "agf $i" -c p/dev/sde1doneQuoted 7 lines
So that we can see what mkfs put on disk? Can you then mount the filesystem, unmount it again, and run the same commands? Then mount the filesystem, run the copy/sync to trigger the error, then unmount and run the commands again?
What I'm interested in if whether
xfs_dbsees the AGF (which ever one it is) as zero, or whether only the kernel is seeing that.Thank you for the help. I believe this has everything you asked for Dave.
....
Quoted 14 lines
bash-4.1# uname -a
Linux t30-2.commstor.crossroads.com 2.6.32-71.29.1.el6.x86_64 #1 SMP Mon Jun 27 19:49:27 BST 2011x86_64x86_64x86_64GNU/Linux bash-4.1#/sbin/mkfs.xfs-f -l logdev=/dev/sda5 -b size=4096 -d su=1024k,sw=4/dev/sde1
meta-data=/dev/sde1 isize=256 agcount=5,
agsize=268435200 blks= sectsz=512 attr=2 data = bsize=4096 blocks=1183011584, imaxpct=5 = sunit=256 swidth=1024 blks naming =version 2 bsize=4096 ascii-ci=0 log =/dev/sda5 bsize=4096 blocks=97280, version=2 = sectsz=512 sunit=0 blks, lazy-count=1 realtime =none extsz=4096 blocks=0, rtextents=0
Quoted 5 lines
bash-4.1# echo 3 >
/proc/sys/vm/drop_caches
bash-4.1# for i inseq 0 4; doxfs_db-l/dev/sda5-c "sb $i" -c p -c "agf $i" -c p/dev/sde1; done
magicnum =0x58465342
blocksize = 4096
.....
All superblocks and AGF headers look good.
Quoted 7 lines
bash-4.1# mount -t xfs -o defaults,noatime,logdev=/dev/sda5
/dev/sde1/dtfs_data/data1
bash-4.1# cp random_data.1G /dtfs_data/data1/foo2 bash-4.1# sync
bash-4.1# cp random_data.1G /dtfs_data/data1/foo3 bash-4.1# sync
bash-4.1# dmesg | tail -100
.....
Quoted 8 lines
Filesystem "sde1": Disabling barriers, not supported with external log device
XFS mounting filesystem sde1
Ending clean XFS mount for filesystem: sde1ffff881808615200: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
................
Filesystem "sde1": XFS internal errorxfs_alloc_read_agfat line 2157 of filefs/xfs/xfs_alloc.c. Caller0xffffffffa01d7989
.....
Quoted 5 lines
bash-4.1# umount /dtfs_data/data1
bash-4.1# echo 3 >/proc/sys/vm/drop_caches
bash-4.1# for i inseq 0 4; doxfs_db-l/dev/sda5-c "sb $i" -c p -c "agf $i" -c p/dev/sde1; donexfs_db: cannot init perag data (117)
xfs_db sees the corruption, too. What is corrupted?
Quoted 3 lines
magicnum =
0x58465342
blocksize = 4096
dblocks = 1183011584
sb 0 is fine.
Quoted 3 lines
magicnum =
0x58414746
versionnum = 1
seqno = 0
AGF 0 is fine.
So are SB/AGF 1.
Quoted 3 lines
magicnum = 0
blocksize = 0
dblocks = 0
SB 2 is zeroed.
Quoted 3 lines
magicnum = 0
versionnum = 0
seqno = 0
AGF 2 is zeroed.
Quoted 3 lines
magicnum =
0x58465342
blocksize = 4096
dblocks = 1183011584
And SB/AGF 3 and 4 are ok, too.
So, the filesystem headers just beyond the 2TB offset are zero. That tends to point to a block device problem, as an offset of 2TB is where a 32 bit sector count will overflow (i.e. 2^32). Next step is to run blktrace/blkparse on the cp workload that generates the error to see if anything actually writes to the 2TB offset region, and if so, where it comes from.
Probably best to compress the resultant blkparse output file - it might be quite large but the text will compress well.
Cheers,
Dave.
Signature · 7 lines
Dave Chinner [email protected] _______________________________________________ xfs mailing list [email protected] http://oss.sgi.com/mailman/listinfo/xfs
On 10/12/2012 07:14 PM, Dave Chinner wrote:
<snip>
Quoted 1 line
And SB/AGF 3 and 4 are ok, too. So, the filesystem headers just beyond the 2TB offset are zero. That tends to point to a block device problem, as an offset of 2TB is where a 32 bit sector count will overflow (i.e. 2^32). Next step is to run blktrace/blkparse on the cp workload that generates the error to see if anything actually writes to the 2TB offset region, and if so, where it comes from. Probably best to compress the resultant blkparse output file - it might be quite large but the text will compress well. Cheers, Dave.
Dave,
Thank you for your help.
10 MB .gz file at http://rx-7.bybent.com/blktrace.sde1.out.gz
What I can see seems to have most of the writes are around 2^31.
Wayne
_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs
Quoted 12 lines · Wayne Walker
On 10/12/2012 07:14 PM, Dave Chinner wrote:
<snip>Quoted 9 lines
And SB/AGF 3 and 4 are ok, too. So, the filesystem headers just beyond the 2TB offset are zero. That tends to point to a block device problem, as an offset of 2TB is where a 32 bit sector count will overflow (i.e. 2^32). Next step is to run blktrace/blkparse on the cp workload that generates the error to see if anything actually writes to the 2TB offset region, and if so, where it comes from. Probably best to compress the resultant blkparse output file - it might be quite large but the text will compress well. Cheers, Dave.
Quoted 7 lines
Dave,
Thank you for your help.
10 MB .gz file at http://rx-7.bybent.com/blktrace.sde1.out.gz
What I can see seems to have most of the writes are around 2^31.
Which is 2^31 sectors of just above 1TB. i.e. writing the data into AG #1. The writes stop a short way into #AG1. The filesystem does not issue any writes to the AG#2 headers, only a single read. IOWs, the filesystem is not overwriting it's own metadata during the workload, so that implies a problem at a lower storage layer....
IOWs, I can't see the filesystem doing anything wrong here.
FWIW, can you pattern the block device around the 2TB offset and re-run the test, and see if the sb/agf 2 are zeroed via xfs_db after the failure occurs? i.e. do something like:
# xfs_io -F -f -c "pwrite 2047g 2g" -c fsync /dev/sde1
the mkfs, run xfs_db to dump sb 2 and agf 2, then run the test and dump sb 2/agf 2 again after the test? use the same xfs-db scripts as the previous time (i.e. including the drop caches commands) if you can.
Cheers,
Dave.
Signature · 7 lines
Dave Chinner [email protected] _______________________________________________ xfs mailing list [email protected] http://oss.sgi.com/mailman/listinfo/xfs