[BUG 4.1.11] EXT4-fs error: ext4_xattr_block_get:299 - Remounting filesystem read-only

From: Philipp Hahn
Date: Tue Apr 19 2016 - 10:38:26 EST


Hello,

we have a virtual machine running linxu-4.1.11 on VMware ESX. After
swapping hard disks on the host the VM mounted its root file system
read-only two times now after detecting some file system corruption.

I hopefully collected enough data from the system, which I attach to
this mail.

Looking at the ACL block I don't see the EXT4_XATTR_MAGIC.
But I see the string signature of two EAs ("posix_acl" and
"DOSATTRIB"), so block 14221335 seems to be a corrupted ACL block.



We recently observed several other problems related to EAs, so here for
reference:

* With 3.16 we had on corruption on KVM. I re-checked
<https://bugzilla.kernel.org/show_bug.cgi?id=102731>, which is fixed
since v3.17-rc1~141^2~79, so this is a different bug.
And here we're running on VMware.

* With 4.1.11 we observed samba hanging due to many different EAs:
<https://bugzilla.kernel.org/show_bug.cgi?id=107301>-
Here smbd doesn't get stuck, but the fs gets mounted read-only.

* There is
<http://lkml.iu.edu/hypermail/linux/kernel/1603.2/01585.html>, which has
"ext4_xattr_block_get" in it, but is with 4.5.


Any ideas?

Philipp

PS: I'm subscribed to LKML but not to ext4.
--
Philipp Hahn
Open Source Software Engineer

Univention GmbH
be open.
Mary-Somerville-Str. 1
D-28359 Bremen
Tel.: +49 421 22232-0
Fax : +49 421 22232-99
hahn@xxxxxxxxxxxxx

http://www.univention.de/
GeschÃftsfÃhrer: Peter H. Ganten
HRB 20755 Amtsgericht Bremen
Steuer-Nr.: 71-597-02876
# uname -r
4.1.0-ucs163-amd64
# This matches linux-4.1.12


# dmesg
[1024404.313457] EXT4-fs error (device dm-0): ext4_xattr_block_get:299: inode #3555356: comm smbd: bad block 14221335
[1024404.313631] Aborting journal on device dm-0-8.
[1024404.313762] EXT4-fs (dm-0): Remounting filesystem read-only
[1024404.314620] EXT4-fs error (device dm-0): ext4_xattr_block_get:299: inode #3555356: comm smbd: bad block 14221335
[1024404.315418] EXT4-fs error (device dm-0): ext4_xattr_block_get:299: inode #3555356: comm smbd: bad block 14221335
[1024404.315639] EXT4-fs error (device dm-0): ext4_xattr_block_get:299: inode #3555356: comm smbd: bad block 14221335
[1024404.316269] EXT4-fs error (device dm-0): ext4_xattr_block_get:299: inode #3555356: comm smbd: bad block 14221335
[1024404.316848] EXT4-fs error (device dm-0): ext4_xattr_block_get:299: inode #3555356: comm smbd: bad block 14221335
[1024404.326320] EXT4-fs error (device dm-0): ext4_xattr_block_get:299: inode #3555356: comm smbd: bad block 14221335
[1024404.327182] EXT4-fs error (device dm-0): ext4_xattr_block_get:299: inode #3555356: comm smbd: bad block 14221335


debugfs: stat <3555356>
Inode: 3555356 Type: directory Mode: 0770 Flags: 0x80000
Generation: 1397519545 Version: 0x00000000:00000007
User: 3279 Group: 5055 Size: 4096
File ACL: 14221335 Directory ACL: 0
Links: 2 Blockcount: 16
Fragment: Address: 0 Number: 0 Size: 0
ctime: 0x5715f2cc:3021d798 -- Tue Apr 19 10:56:44 2016
atime: 0x5715f166:4005ecb4 -- Tue Apr 19 10:50:46 2016
mtime: 0x52d51e30:4292f030 -- Tue Jan 14 12:23:28 2014
crtime: 0x52d51e68:93b4a2b4 -- Tue Jan 14 12:24:24 2014
Size of extra inode fields: 28
Extended attributes stored in inode body:
= "01 00 00 00 01 00 07 00 02 00 07 00 cf 0c 00 00 04 00 00 00 08 00 07 00 21 00 00 00 08 00 00 00 bf 13 00 00 10 00 07 00 20 00 00 00 " (44)
EXTENTS:
(0):14175007


debugfs: ncheck 3555356
Inode Pathname
3555356 /home/cri/windows-profiles/default/Eigene Dateien/MuseScore/plugins/break


debugfs: ls "/home/cri/windows-profiles/default/Eigene Dateien/MuseScore/plugins/break"
3555356 (12) . 3555351 (12) .. 3553852 (40) break.js
3553850 (4032) break.ui


debugfs: logdump -i <3555356>
Inode 3555356 is at group 434, block 14156832, offset 3456
Journal starts at block 22620, transaction 90202501
Found sequence 90187323 (not 90202951) at block 29271: end of journal.


debugfs: testb 14221335
Block 14221335 marked in use


debugfs: logdump -b 14221335
Journal starts at block 22620, transaction 90202501
FS block 14155778 logged at sequence 90202946, journal block 29181 (flags 0x2)
(block bitmap for block 14221335: block is CLEAR)
Found sequence 90187323 (not 90202951) at block 29271: end of journal.


# dd if=/dev/dm-0 of=/dev/shm/1 bs=4k count=1 skip=14221335
# od /dev/shm/1
0000000 101500 000000 000001 000000 000000 000000 000000 000000
0000020 000000 000000 000110 045504 050062 031061 032461 033127
0000040 000411 007710 000000 000000 000070 000000 025035 066777
0000060 047504 040523 052124 044522 000102 000000 046040 020040
0000100 020040 020040 032123 000200 000000 030456 030071 020040
0000120 020040 046501 051126 042514 046040 053111 051124 052501
0000140 046114 020040 020040 020040 020040 020040 020040 020040
0000160 020040 020040 020040 020040 020040 000000 000000 007400
0000200 040001 001000 001000 000006 000000 000000 000000 000000
0000220 000000 000000 000000 000000 000000 000000 000003 000170
0000240 000170 000170 000170 000000 000000 000000 000000 000000
0000260 000000 000000 000000 000000 000000 000000 000000 000000
*
0007040 000000 000000 000001 000000 000001 000007 000002 000007
0007060 006317 000000 000004 000000 000010 000007 000041 000000
0007100 000010 000000 011677 000000 000020 000007 000040 000000
0007120 000004 000004 000000 000002 000004 000002 000001 127660
0007140 012703 175623 011205 123375 044312 137430 136045 020454
0007160 146337 120714 114761 036101 175372 123256 022737 000000
0007200 000000 000000 000000 000000 000000 000000 000000 000000
0007220 000000 000000 000000 000000 000000 000000 000000 067560
0007240 064563 057570 061541 000154 127036 026675 010433 000717
0007260 023254 054213 145743 116700 173425 014560 124625 020071
0007300 004664 131010 152420 163501 151071 150120 054265 024656
0007320 000000 000000 000000 000000 000000 000000 000000 000000
*
0007360 000001 100004 000264 000000 000320 000000 000000 000000
0007400 000354 000000 002401 000000 000000 002400 000025 000000
0007420 001156 166500 142764 135041 057241 042367 016606 000000
0007440 002401 000000 000000 002400 000025 000000 001156 166500
0007460 142764 135041 057241 042367 025547 000000 000002 000214
0007500 000005 000000 000000 000044 000777 000037 002401 000000
0007520 000000 002400 000025 000000 001156 166500 142764 135041
0007540 057241 042367 016606 000000 005400 000024 000777 000037
0007560 000401 000000 000000 001400 000000 000000 000000 000044
0007600 000000 000000 002401 000000 000000 002400 000025 000000
0007620 001156 166500 142764 135041 057241 042367 025547 000000
0007640 005400 000024 000000 000000 000401 000000 000000 001400
0007660 000001 000000 001400 000024 000000 000000 000401 000000
0007700 000000 000400 000000 000000 074060 030061 000000 000003
0007720 000003 000000 000021 000000 000020 000000 000000 000000
0007740 000000 000000 000000 000000 000000 000000 000000 000000
0007760 051573 006050 010433 000717 000000 000000 000000 000000
0010000


# strings /dev/shm/1
DK2P1215W6
mDOSATTRIB
L S4
.190 AMVRLE LIVTRAULL
posix_acl
0x10


# cat /proc/cpuinfo
processor : 3
vendor_id : GenuineIntel
cpu family : 6
model : 30
model name : Intel(R) Xeon(R) CPU X3430 @ 2.40GHz
stepping : 5
microcode : 0x3
cpu MHz : 2400.000
cache size : 8192 KB
physical id : 0
siblings : 4
core id : 3
cpu cores : 4
apicid : 3
initial apicid : 3
fpu : yes
fpu_exception : yes
cpuid level : 11
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts mmx fxsr sse sse2 ss ht syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts nopl xtopology tsc_reliable nonstop_tsc aperfmperf pni ssse3 cx16 sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer hypervisor lahf_lm ida dtherm tsc_adjust
bugs :
bogomips : 4800.00
clflush size : 64
cache_alignment : 64
address sizes : 42 bits physical, 48 bits virtual
power management:


# TODO: Check <https://downloadcenter.intel.com/download/25512/Linux-Processor-Microcode-Data-File?v=t>


# df -T
Dateisystem Typ 1K-BlÃcke Benutzt VerfÃgbar Verw% EingehÃngt auf
udev devtmpfs 10240 0 10240 0% /dev
tmpfs tmpfs 3293668 25908 3267760 1% /run
/dev/mapper/vg_ucs-rootfs ext4 877173548 606854700 233523112 73% /
tmpfs tmpfs 5120 0 5120 0% /run/lock
tmpfs tmpfs 8684480 4 8684476 1% /run/shm
/dev/sda2 ext4 499656 78552 384408 17% /boot
cgroup tmpfs 16468336 0 16468336 0% /sys/fs/cgroup


# cat /proc/fs/ext4/dm-0/options
ro
block_validity
delalloc
barrier
user_xattr
acl
quota
usrquota
grpquota
resuid=0
resgid=0
errors=remount-ro
commit=5
min_batch_time=0
max_batch_time=15000
stripe=0
data=ordered
inode_readahead_blks=32
init_itable=10
max_dir_size_kb=0