[LU-4402] Ldiskfs errors ldiskfs_ext_find_extent, ldiskfs_ext_get_blocks, corruption Created: 20/Dec/13  Updated: 08/Feb/14  Resolved: 01/Feb/14

Status: Resolved
Project: Lustre
Component/s: None
Affects Version/s: Lustre 2.4.1
Fix Version/s: None

Type: Bug Priority: Major
Reporter: Blake Caldwell Assignee: Alex Zhuravlev
Resolution: Fixed Votes: 0
Labels: None
Environment:

RHEL6.4/distro IB/2.6.32-358.18.1.el6


Attachments: Text File atlas_20131219_errors.log.gz    
Severity: 2
Rank (Obsolete): 12084

 Description   

Starting with an otherwise operating filesystem, we had a nfs issue on the management server that does nfsroot to the nodes. This caused the nodes to hang on shell probes, ssh, etc, but lustre appeared to work okay, until the mount came back and there was a spew of I/O errors. We had -o errors=panic, so the nodes rebooted and we have a crash dump as well. A few of the interesting/disturbing messages are below and a complete log capture of the interval is attached. We rebooted every single one of our lustre systems that mounted this nfsroot and started up lustre. At this point, an e2fsck seems prudent given the messages? Please advise.

And for clarity's sake, this is from a completely separate system than LU-486 that I just updated.

Dec 19 14:07:28 atlas-oss3b4 kernel: [1987655.565953] end_request: I/O error, dev dm-0, sector 2641342080
... more of those ...
Dec 19 14:07:34 atlas-oss2f4 kernel: [1987662.210829] LDISKFS-fs error (device dm-8): ldiskfs_ext_find_extent: bad header/extent in inode #395571: invalid magic - magic 5fa6, entries 39658, max 42407(0), depth 37176(0)
Dec 19 14:09:02 atlas-linkfarm kernel: [1987621.160868] LustreError: 13071:0:(tgt_lastrcvd.c:577:tgt_client_new()) linkfarm-MDT0000: Failed to write client lcd at idx 18888, rc -30
Dec 19 14:09:11 atlas-mds1 kernel: [1355985.425764] LustreError: 15139:0:(osp_precreate.c:484:osp_precreate_send()) atlas1-OST0043-osc-MDT0000: can\'t precreate: rc = -30
Dec 19 14:09:11 atlas-mds1 kernel: [1355985.439222] LustreError: 15139:0:(osp_precreate.c:484:osp_precreate_send()) Skipped 990 previous similar messages
Dec 19 14:09:11 atlas-mds1 kernel: [1355985.451122] LustreError: 15139:0:(osp_precreate.c:989:osp_precreate_thread()) atlas1-OST0043-osc-MDT0000: cannot precreate objects: rc = -30
Dec 19 14:09:11 atlas-mds1 kernel: [1355985.465640] LustreError: 15139:0:(osp_precreate.c:989:osp_precreate_thread()) Skipped 990 previous similar messages
Dec 19 14:09:55 atlas-mds1 kernel: [1356029.474926] INFO: task mdt00_027:12952 blocked for more than 120 seconds.
Dec 19 14:10:46 atlas-oss1d1 kernel: [691120.297183] LDISKFS-fs error (device dm-1): ldiskfs_ext_find_extent: bad header/extent in inode #395600: invalid magic - magic a7bc, entries 21131, max 744(0), depth 0(0)
Dec 19 14:12:42 atlas-oss2d6 kernel: [1987967.199569] Buffer I/O error on device dm-9, logical block 5638
Dec 19 14:12:42 atlas-oss2d6 kernel: [1987967.199571] lost page write due to I/O error on dm-9
Dec 19 14:12:42 atlas-oss2d6 kernel: [1987967.199578] LDISKFS-fs error (device dm-9): kmmpd:
Dec 19 14:12:42 atlas-oss2d6 kernel: [1987967.199582] Aborting journal on device dm-9-8.
Dec 19 14:12:42 atlas-oss2d6 kernel: [1987967.199586] Buffer I/O error on device dm-9, logical block 137
Dec 19 14:12:42 atlas-oss2d6 kernel: [1987967.199588] Error writing to MMP block
Dec 19 14:12:42 atlas-oss2d6 kernel: [1987967.199589] lost page write due to I/O error on dm-9
Dec 19 14:12:42 atlas-oss2d6 kernel: [1987967.199590]
Dec 19 14:12:42 atlas-oss2d6 kernel: [1987967.199592] LDISKFS-fs (dm-9): Remounting filesystem read-only
Dec 19 14:13:25 atlas-oss2f5 kernel: [1988014.344558] LDISKFS-fs error (device dm-6): ldiskfs_ext_find_extent: bad header/extent in inode #268955: invalid magic - magic e79d, entries 37634, max 32686(0), depth 47774(0)

Dec 19 14:14:50 atlas-oss1a5 kernel: [691359.246757] LDISKFS-fs error (device dm-9): file system corruption: inode #591204 logical block 447 mapped to 137004702958273 (size 1)
Dec 19 14:14:53 atlas-oss1a5 kernel: [691362.375749] LDISKFS-fs error (device dm-9): file system corruption: inode #591204 logical block 447 mapped to 137004702958273 (size 1)
Dec 19 14:14:57 atlas-oss1a5 kernel: [691366.367144] LDISKFS-fs error (device dm-9): file system corruption: inode #591204 logical block 447 mapped to 137004702958273 (size 1)
Dec 19 14:15:02 atlas-oss1a5 kernel: [691371.356427] LDISKFS-fs error (device dm-9): file system corruption: inode #591204 logical block 447 mapped to 137004702958273 (size 1)
Dec 19 14:15:08 atlas-oss1a5 kernel: [691377.343445] LDISKFS-fs error (device dm-9): file system corruption: inode #591204 logical block 447 mapped to 137004702958273 (size 1)
Dec 19 14:15:15 atlas-oss1a5 kernel: [691384.328232] LDISKFS-fs error (device dm-9): file system corruption: inode #591204 logical block 447 mapped to 137004702958273 (size 1)
Dec 19 14:15:16 atlas-oss2e1 kernel: [1988136.371625] LDISKFS-fs error (device dm-3): ldiskfs_ext_find_extent: bad header/extent in inode #330052: invalid magic - magic 53be, entries 21067, max 517(0),
depth 0(0)
Dec 19 14:15:23 atlas-oss1a5 kernel: [691392.310962] LDISKFS-fs error (device dm-9): file system corruption: inode #591204 logical block 447 mapped to 137004702958273 (size 1)
Dec 19 14:15:32 atlas-oss1a5 kernel: [691401.291535] LDISKFS-fs error (device dm-9): file system corruption: inode #591204 logical block 447 mapped to 137004702958273 (size 1)
Dec 19 14:15:42 atlas-oss1a5 kernel: [691411.269872] LDISKFS-fs error (device dm-9): file system corruption: inode #591204 logical block 447 mapped to 137004702958273 (size 1)

Dec 19 14:21:50 atlas-oss1d3 kernel: [691780.266369] LDISKFS-fs error (device dm-2): ldiskfs_ext_find_extent: bad header/extent in inode #199528: invalid magic - magic 0, entries 0, max 0(0), depth 0(0
)

Dec 19 14:22:41 atlas-oss1d3 kernel: [691831.895277] LDISKFS-fs error (device dm-2): ldiskfs_ext_get_blocks: inode #199528: (comm ll_ost_io02_007) bad extent address iblock: 447, depth: 1 pblock 0



 Comments   
Comment by Alex Zhuravlev [ 20/Dec/13 ]

>Dec 19 14:07:25 atlas-mgs2 kernel: [1988887.590310] sd 6:0:8:1: [sdw] Warning! Received an indication that the LUN assignments on this target have changed. The Linux SCSI layer does not automatically remap LUN assignments.

sounds like at some point underlying device changed?

Comment by Blake Caldwell [ 20/Dec/13 ]

Well I'm going to say that it's not directly correlated, but there's more to it. That host is not actually part of the filesystem. It connects to, but does not have any LUNs mounted on the same SAS attached array that the MGS and MDS share, so perhaps it indicates an event on one of the other systems. We've grown accustomed to seeing those messages with RHEL hosts when something happens on the storage array (object storage arrays from a different brand do this too) and it has not indicated an actual LUN assignment change. It could be caused from an event on one of the other systems atlas-mds1, atlas-mds3, atlas-mgs1 such as an IO error after the nfsroot returned.

Comment by Alex Zhuravlev [ 20/Dec/13 ]

thanks for clarification.
can it be that some configuration changes on the storage system caused following I/O errors:
Dec 19 14:07:28 atlas-oss3b4 kernel: [1987655.605866] end_request: I/O error, dev dm-0, sector 2641344352
?

the confusing thing is that it's number of the systems started to observe corruptions:
Dec 19 14:10:46 atlas-oss1d1 kernel: [691120.297183] LDISKFS-fs error (device dm-1): ldiskfs_ext_find_extent: bad header/extent in inode #395600: invalid magic - magic a7bc, entries 21131, max 744(0), depth 0(0)
Dec 19 14:11:34 atlas-oss1b2 kernel: [691163.534948] LDISKFS-fs error (device dm-18): ldiskfs_ext_find_extent: bad header/extent in inode #268868: invalid magic - magic 222a, entries 21150, max 9(0), depth 0(0)
Dec 19 14:11:44 atlas-oss1a5 kernel: [691173.077090] LDISKFS-fs error (device dm-9): ldiskfs_ext_find_extent: bad header/extent in inode #591204: invalid magic - magic a9bf, entries 21131, max 868(0), depth 0(0)
Dec 19 14:11:55 atlas-oss1d4 kernel: [691184.758850] LDISKFS-fs error (device dm-4): ldiskfs_ext_find_extent: bad header/extent in inode #269305: invalid magic - magic b84, entries 44395, max 21257(0), depth 62507(0)

Comment by Blake Caldwell [ 20/Dec/13 ]

I agree its strange the number of errors. atlas-oss1d1 and atlas-oss1b2 use physically separate storage arrays. Of those listed only atlas-oss1d1 and atlas-oss1d4 share the same storage device. I checked the logs on the OST storage controllers and all that they saw was the hosts log out and then back in when they were rebooted.

The common piece that sticks out to me is that all systems had their nfsroot filesystems disrupted. They have recovered from this transparently a hundred times before.

Comment by Jodi Levi (Inactive) [ 07/Jan/14 ]

Are there any next steps on this ticket given the information that has been posted? ie. should this ticket be closed?

Comment by Blake Caldwell [ 08/Jan/14 ]

What would be the best way of validating what it is saying about this message... assuming the inode still exists? Since this is the ldiskfs layer, how do we correlate to inode #395571? Debugfs? Anything live without a downtime for e2fsck?

Dec 19 14:07:34 atlas-oss2f4 kernel: [1987662.210829] LDISKFS-fs error (device dm-8): ldiskfs_ext_find_extent: bad header/extent in inode #395571: invalid magic - magic 5fa6, entries 39658, max 42407(0), depth 37176(0)

Comment by Alex Zhuravlev [ 14/Jan/14 ]

you can try on the mounted filesystem: debugfs -R "stat <395571>"

Comment by Blake Caldwell [ 21/Jan/14 ]

Thanks. It turns out that since just had a downtime and I was able to run e2fsck across all OSTs. There were only 2 problems found and they did not correlate to the issues in the log messages. 1 problem was with inode 3, which I gather is a user quota file. The 2nd inode had a fid, but could not be found with fid2path. If the i_size for inode 3 difference is tolerable, then I believe we have arrived at the end of the road with this case.

[root@atlas-oss2e4 ~]# e2fsck -f /dev/mapper/atlas-ddn2e-l22
e2fsck 1.42.7.wc1 (12-Apr-2013)
Pass 1: Checking inodes, blocks, and sizes
Inode 3, i_size is 92160, should be 106496. Fix<y>? yes
Pass 2: Checking directory structure
Pass 3: Checking directory connectivity
Pass 4: Checking reference counts
Pass 5: Checking group summary information
[root@atlas-oss2i1 ~]# e2fsck -f /dev/mapper/atlas-ddn2i-l2
e2fsck 1.42.7.wc1 (12-Apr-2013)
Pass 1: Checking inodes, blocks, and sizes
Inode 209, i_size is 25165824, should be 26214400. Fix<y>? yes
Pass 2: Checking directory structure
Pass 3: Checking directory connectivity
Pass 4: Checking reference counts
Pass 5: Checking group summary information

[root@atlas-oss2i1 ~]# debugfs -R "stat <209>" /dev/mapper/atlas-ddn2i-l2
debugfs 1.42.7.wc1 (12-Apr-2013)
Inode: 209 Type: regular Mode: 0666 Flags: 0x80000
Generation: 3823026230 Version: 0x00000003:00036bbd
User: 9032 Group: 18319 Size: 25165824
File ACL: 0 Directory ACL: 0
Links: 1 Blockcount: 51208
Fragment: Address: 0 Number: 0 Size: 0
ctime: 0x52ceeba5:00000000 – Thu Jan 9 13:34:13 2014
atime: 0x52ceeba5:00000000 – Thu Jan 9 13:34:13 2014
mtime: 0x52ceeba5:00000000 – Thu Jan 9 13:34:13 2014
crtime: 0x524b4897:d033afac – Tue Oct 1 18:11:35 2013
Size of extra inode fields: 28
Extended attributes stored in inode body:
lma = "00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 7c 00 00 00 00 00 00 00 " (24)
lma: fid=[0x1000000:0x7c000000:0x0] compat=0 incompat=0
fid = "88 14 00 00 02 00 00 00 38 02 00 00 03 00 00 00 " (16)
fid: parent=[0x200001488:0x238:0x0] stripe=3
EXTENTS:
(ETB0):60304384, (0-255):60295936-60296191, (256-511):60296960-60297215, (512-1023):60298240-60298751, (1024-2047):60302336-60303359, (2048-4095):60305408-60307455, (4096-6143):60317696-60319743, (6144-6399):60327936-60328191

[root@atlas-oss2i1 ~]# debugfs -R "ncheck 209" /dev/mapper/atlas-ddn2i-l2
debugfs 1.42.7.wc1 (12-Apr-2013)
Inode Pathname
209 /O/0/d28/124
[root@client1 etc]# lfs fid2path /lustre/atlas1 [0x1000000:0x7c000000:0x0]
fid2path error: No such file or directory

Comment by James Nunez (Inactive) [ 31/Jan/14 ]

Blake,

Should we close this ticket or is there something else you need to be resolved?

Thanks,
James

Comment by Blake Caldwell [ 31/Jan/14 ]

This can be closed. Thanks James.

Generated at Sat Feb 10 01:42:24 UTC 2024 using Jira 9.4.14#940014-sha1:734e6822bbf0d45eff9af51f82432957f73aa32c.