2004-01-18 10:28:38

by Jan Dittmer

[permalink] [raw]
Subject: ext3 on raid5 failure

Hello,

I've recently upgraded my fileserver to 2.6.1 and since then I had to
reboot two times because of the following errors. Afterwards the
blockdevice was set readonly, so I couldn't even remount the partition
rw. Interestingly after reboot the raid is not marked dirty. So is this
an ext3 only error?
This never happenend with 2.4.23pre6-aa3 or any other 2.4 version which
run for about a year on this system without any (linux caused) downtime.
What I can try to debug this? The first time it happened after about 3
or 4 days uptime, the second time after about 1 day. So it's pretty
reproducible.

Thanks,

Jan

EXT3-fs error (device dm-1): ext3_readdir: bad entry in directory
#9783034: rec_len % 4 != 0 - offset=0, inode=1846971784, rec_len=33046,
name_len=154
Aborting journal on device dm-1.
ext3_abort called.
EXT3-fs abort (device dm-1): ext3_journal_start: Detected aborted journal
Remounting filesystem read-only

and

EXT3-fs error (device dm-1): ext3_readdir: bad entry in directory
#8422045: rec_len % 4 != 0 - offset=0, inode=655393188, rec_len=1998,
name_len=0
Aborting journal on device dm-1.
ext3_abort called.
EXT3-fs abort (device dm-1): ext3_journal_start: Detected aborted journal
Remounting filesystem read-only
EXT3-fs error (device dm-1) in start_transaction: Journal has aborted


$ cat /proc/mdstat
Personalities : [raid5]
read_ahead 1024 sectors
md0 : active raid5 ide/host2/bus1/target1/lun0/part1[3]
ide/host2/bus1/target0/lun0/part1[1]
ide/host2/bus0/target1/lun0/part1[2]
ide/host2/bus0/target0/lun0/part1[0]
ide/host0/bus1/target0/lun0/part1[4]
468872704 blocks level 5, 4k chunk, algorithm 2 [5/5] [UUUUU]

$ vgdisplay:
--- Volume group ---
VG Name myraid
System ID
Format lvm2
Metadata Areas 1
Metadata Sequence No 7
VG Access read/write
VG Status resizable
MAX LV 256
Cur LV 2
Open LV 2
Max PV 256
Cur PV 1
Act PV 1
VG Size 447.15 GB
PE Size 4.00 MB
Total PE 114470
Alloc PE / Size 114470 / 447.15 GB
Free PE / Size 0 / 0
VG UUID 0xPsvH-t204-YlD4-jVAW-mYgK-ndF5-nEVOTk

$ lvdisplay:
--- Logical volume ---
LV Name /dev/myraid/lvol0
VG Name myraid
LV UUID X47Raw-ZGgE-PZ4I-F1o3-lYX9-TVQ1-KIWqrs
LV Write Access read/write
LV Status available
# open 1
LV Size 100.00 GB
Current LE 25600
Segments 1
Allocation next free (default)
Read ahead sectors 0
Block device 254:1

--- Logical volume ---
LV Name /dev/myraid/lvol1
VG Name myraid
LV UUID LgnX1d-r3BP-3u7t-yLQb-iRke-544J-v7uBBd
LV Write Access read/write
LV Status available
# open 1
LV Size 347.15 GB
Current LE 88870
Segments 1
Allocation next free (default)
Read ahead sectors 0
Block device 254:2

$ mount -l
/dev/mapper/myraid-lvol1 on /mnt/data/1 type ext3 (rw)
/dev/mapper/myraid-lvol0 on /mnt/backup type ext3 (rw)


2004-01-18 18:02:40

by Mike Fedyk

[permalink] [raw]
Subject: Re: ext3 on raid5 failure

On Sun, Jan 18, 2004 at 11:27:54AM +0100, Jan Dittmer wrote:
> EXT3-fs error (device dm-1): ext3_readdir: bad entry in directory
> #9783034: rec_len % 4 != 0 - offset=0, inode=1846971784, rec_len=33046,
> name_len=154
> Aborting journal on device dm-1.
> ext3_abort called.
> EXT3-fs abort (device dm-1): ext3_journal_start: Detected aborted journal
> Remounting filesystem read-only

Run fsck on the filesystem.

2004-01-19 15:30:30

by Theodore Ts'o

[permalink] [raw]
Subject: Re: ext3 on raid5 failure

On Sun, Jan 18, 2004 at 10:02:32AM -0800, Mike Fedyk wrote:
> On Sun, Jan 18, 2004 at 11:27:54AM +0100, Jan Dittmer wrote:
> > EXT3-fs error (device dm-1): ext3_readdir: bad entry in directory
> > #9783034: rec_len % 4 != 0 - offset=0, inode=1846971784, rec_len=33046,
> > name_len=154
> > Aborting journal on device dm-1.
> > ext3_abort called.
> > EXT3-fs abort (device dm-1): ext3_journal_start: Detected aborted journal
> > Remounting filesystem read-only
>
> Run fsck on the filesystem.

Jan, what distribution are you running? The superblock *should* have
been marked "filesystems has errors", and so fsck should have been
forced when you rebooted. Did fsck in fact run, and if so, did it
detect and fix any problems?

- Ted

2004-01-23 08:22:38

by Jan Dittmer

[permalink] [raw]
Subject: Re: ext3 on raid5 failure

Theodore Ts'o wrote:
> On Sun, Jan 18, 2004 at 10:02:32AM -0800, Mike Fedyk wrote:
>
>>On Sun, Jan 18, 2004 at 11:27:54AM +0100, Jan Dittmer wrote:
>>
>>>EXT3-fs error (device dm-1): ext3_readdir: bad entry in directory
>>>#9783034: rec_len % 4 != 0 - offset=0, inode=1846971784, rec_len=33046,
>>>name_len=154
>>>Aborting journal on device dm-1.
>>>ext3_abort called.
>>>EXT3-fs abort (device dm-1): ext3_journal_start: Detected aborted journal
>>>Remounting filesystem read-only
>>
>>Run fsck on the filesystem.
>
>
> Jan, what distribution are you running? The superblock *should* have
> been marked "filesystems has errors", and so fsck should have been
> forced when you rebooted. Did fsck in fact run, and if so, did it
> detect and fix any problems?
>
> - Ted

Okay, I fscked all filesystems in single user mode, thereby fscked up my
root filesystem, though I didn't even check it - so I restored it from
backup (grub wouldn't even load anymore).
After 2 days in my freshly setup debian (2.6.1-bk6), same error. But
this time at least I know it's because I tried to delete those files in
the lost+found directory...
So, how do I delete these and why did fsck fail? It's pretty annoying to
reboot because of this. It would be nice to just being able to
remount,rw the partition.

Thanks,

Jan

EXT3-fs error (device dm-2): ext3_readdir: directory #16370 contains a
hole at offset 8192
Aborting journal on device dm-2.
EXT3-fs error (device dm-2): ext3_readdir: directory #16370 contains a
hole at offset 24576
ext3_abort called.
EXT3-fs abort (device dm-2): ext3_journal_start: Detected aborted journal
Remounting filesystem read-only


Attachments:
(No filename) (256.00 B)

2004-01-27 19:08:19

by Theodore Ts'o

[permalink] [raw]
Subject: Re: ext3 on raid5 failure

On Fri, Jan 23, 2004 at 09:22:25AM +0100, Jan Dittmer wrote:
>
> Okay, I fscked all filesystems in single user mode, thereby fscked up my
> root filesystem, though I didn't even check it - so I restored it from
> backup (grub wouldn't even load anymore).

What messages were printed by e2fsck while it was running --- and was
all of the filesystems unmounted, excepted for the root filesystem,
which should have been mounted read-only?

> After 2 days in my freshly setup debian (2.6.1-bk6), same error. But
> this time at least I know it's because I tried to delete those files in
> the lost+found directory...

How did you come to that conclusion?

> So, how do I delete these and why did fsck fail? It's pretty annoying to
> reboot because of this. It would be nice to just being able to
> remount,rw the partition.

How did fsck fail? Without a transcript of the fsck output, it's hard
to say exactly what happened here.

An output of dumpe2fs of the filesystem in question would also be useful.

- Ted

2004-01-28 11:06:15

by Jan Dittmer

[permalink] [raw]
Subject: Re: ext3 on raid5 failure

Theodore Ts'o wrote:
> On Fri, Jan 23, 2004 at 09:22:25AM +0100, Jan Dittmer wrote:
>
>>Okay, I fscked all filesystems in single user mode, thereby fscked up my
>>root filesystem, though I didn't even check it - so I restored it from
>>backup (grub wouldn't even load anymore).
>
>
> What messages were printed by e2fsck while it was running --- and was
> all of the filesystems unmounted, excepted for the root filesystem,
> which should have been mounted read-only?
>
>
>>After 2 days in my freshly setup debian (2.6.1-bk6), same error. But
>>this time at least I know it's because I tried to delete those files in
>>the lost+found directory...
>
>
> How did you come to that conclusion?

Argh, sorry, after chattr -aI the files could be deleted. sorry for the
noise.

Jan


Attachments:
(No filename) (256.00 B)

2004-01-28 10:55:21

by Jan Dittmer

[permalink] [raw]
Subject: Re: ext3 on raid5 failure

Theodore Ts'o wrote:
> On Fri, Jan 23, 2004 at 09:22:25AM +0100, Jan Dittmer wrote:
>
>>Okay, I fscked all filesystems in single user mode, thereby fscked up my
>>root filesystem, though I didn't even check it - so I restored it from
>>backup (grub wouldn't even load anymore).
>
>
> What messages were printed by e2fsck while it was running --- and was
> all of the filesystems unmounted, excepted for the root filesystem,
> which should have been mounted read-only?
>
Yep it was all unmounted. But I don't have a transcript of this session.
I was directly logged in, sorry.

>
>>After 2 days in my freshly setup debian (2.6.1-bk6), same error. But
>>this time at least I know it's because I tried to delete those files in
>>the lost+found directory...
>
>
> How did you come to that conclusion?

sfhq:/mnt/data/1/lost+found# ls -l
total 76
d-wSr----- 2 1212680233 136929556 49152 Jun 7 2008 #16370
-rwx-wx--- 1 1628702729 135220664 45056 May 4 1974 #16380
sfhq:/mnt/data/1/lost+found# rm *
rm: cannot remove `#16370': Operation not permitted
rm: cannot remove `#16380': Operation not permitted
sfhq:/mnt/data/1/lost+found# rm *
rm: cannot remove `#16370': Operation not permitted
rm: cannot remove `#16380': Operation not permitted
sfhq:/mnt/data/1/lost+found# rm *
rm: cannot remove `#16370': Operation not permitted
rm: cannot remove `#16380': Operation not permitted
sfhq:/mnt/data/1/lost+found# dmesg
EXT3-fs error (device dm-2): ext3_readdir: directory #16370 contains a
hole at offset 8192
Aborting journal on device dm-2.
EXT3-fs error (device dm-2): ext3_readdir: directory #16370 contains a
hole at offset 24576
ext3_abort called.
EXT3-fs abort (device dm-2): ext3_journal_start: Detected aborted journal
Remounting filesystem read-only

This is with 2.6.1-bk6 and no concurrent access. With 2.4.25-pre7-pac1
this does not happen.
So I rechecked the filesystem (with 2.4), hoping it won't get corrupted
and I would be able to delete the files, but:

sfhq:~# fsck /dev/myraid/lvol1
fsck 1.35-WIP (07-Dec-2003)
e2fsck 1.35-WIP (07-Dec-2003)
/dev/myraid/lvol1 contains a file system with errors, check forced.
Pass 1: Checking inodes, blocks, and sizes
Pass 2: Checking directory structure
Directory inode 16370 has an unallocated block #2. Allocate<y>? yes

Directory inode 16370 has an unallocated block #6. Allocate<y>? yes

Pass 3: Checking directory connectivity
Pass 3A: Optimizing directories
Pass 4: Checking reference counts
Pass 5: Checking group summary information

/dev/myraid/lvol1: ***** FILE SYSTEM WAS MODIFIED *****
/dev/myraid/lvol1: 2341/45514752 files (24.0% non-contiguous),
82194611/91002880 blocks

still no luck with undeleting these files

sfhq:/mnt/data/1/lost+found# rm -rf *
rm: cannot remove directory `#16370': Operation not permitted
rm: cannot remove `#16380': Operation not permitted

sfhq:/mnt/data# dumpe2fs /dev/myraid/lvol1
dumpe2fs 1.35-WIP (07-Dec-2003)
Filesystem volume name: <none>
Last mounted on: <not available>
Filesystem UUID: ba3f83cd-04c8-4c4d-82f7-990077aabb73
Filesystem magic number: 0xEF53
Filesystem revision #: 1 (dynamic)
Filesystem features: has_journal dir_index needs_recovery sparse_super
Default mount options: (none)
Filesystem state: clean
Errors behavior: Continue
Filesystem OS type: Linux
Inode count: 45514752
Block count: 91002880
Reserved block count: 3640115
Free blocks: 8808269
Free inodes: 45512411
First block: 0
Block size: 4096
Fragment size: 4096
Blocks per group: 32768
Fragments per group: 32768
Inodes per group: 16384
Inode blocks per group: 512
Filesystem created: Thu Jul 3 13:57:02 2003
Last mount time: Wed Jan 28 11:48:13 2004
Last write time: Wed Jan 28 11:48:13 2004
Mount count: 2
Maximum mount count: 23
Last checked: Wed Jan 28 11:47:06 2004
Check interval: 15552000 (6 months)
Next check after: Mon Jul 26 12:47:06 2004
Reserved blocks uid: 0 (user root)
Reserved blocks gid: 0 (group root)
First inode: 11
Inode size: 128
Journal inode: 8
Default directory hash: tea
Directory Hash Seed: a7fd0c53-efe9-4316-9fa6-e3206623f4fe
Journal backup: inode blocks

Do you need the complete output? Btw. I have the same error on another
partition (also on raid5, dm).

Thanks,

Jan


Attachments:
(No filename) (256.00 B)

2004-01-29 11:44:08

by Theodore Ts'o

[permalink] [raw]
Subject: Re: ext3 on raid5 failure

On Wed, Jan 28, 2004 at 11:54:44AM +0100, Jan Dittmer wrote:
> >>After 2 days in my freshly setup debian (2.6.1-bk6), same error. But
> >>this time at least I know it's because I tried to delete those files in
> >>the lost+found directory...
> >
> >
> >How did you come to that conclusion?
>
> sfhq:/mnt/data/1/lost+found# ls -l
> total 76
> d-wSr----- 2 1212680233 136929556 49152 Jun 7 2008 #16370
> -rwx-wx--- 1 1628702729 135220664 45056 May 4 1974 #16380

Ok, this looks like random garbage has gotten written into inode table.

If you can make this happen consistently with 2.6 and not with 2.4,
then that would be useful to know. There may be some kind of race
condition or problem with either the raid5 code, or the combination of
raid5 plus ext3. It's unlikely this kind of error would be caused by
a flaw in the ext3 code alone, since this is indicative of complete
garbage written to the inode table, or a block intended for another
location on disk getting written to the inode table. The natural
suspect is at the block device layer and below.

- Ted