[prev in list] [next in list] [prev in thread] [next in thread]
List: linux-s390
Subject: [Bug report] More xfs courruption issue found on s390x
From: Zorro Lang <zlang () redhat ! com>
Date: 2023-10-29 4:33:33
Message-ID: 20231029043333.v6wkqsorxdk2dbch () dell-per750-06-vm-08 ! rhts ! eng ! pek2 ! redhat ! com
[Download RAW message or body]
Hi xfs folks,
Besides https://lore.kernel.org/linux-xfs/20231029041122.bx2k7wwm7otebjd5@dell-per750-06-vm-08.rhts.eng.pek2.redhat.com/T/#u \
,
I always hit another failure on s390x too, by running generic/039 or generic/065 [1]:
XFS: Assertion failed: ip->i_nblocks == 0, file: fs/xfs/xfs_inode.c, line: 2359
More details as dmesg output [2] and .full output [3].
And ... more other kind of failure likes [3]:
XFS: Assertion failed: error != -ENOENT, file: fs/xfs/xfs_trans.c, line: 1310
All these falures are on s390x only... and more xfs corruption failure by running
fstests on s390x. I don't know if it's a s390x issue or a xfs issue on big endian
machine (s390x), so cc s390x list.
I tested on mainline linux 6.6.0-rc7+, the HEAD commit is:
commit 750b95887e567848ac2c851dae47922cac6db946
Author: Linus Torvalds <torvalds@linux-foundation.org>
Date: Thu Oct 26 20:42:02 2023 -1000
Merge tag 'drm-fixes-2023-10-27' of git://anongit.freedesktop.org/drm/drm
Thanks,
Zorro
[1]
FSTYP -- xfs (debug)
PLATFORM -- Linux/s390x s390x-kvm-091 6.6.0-rc7+ #1 SMP Fri Oct 27 08:58:03 EDT \
2023 MKFS_OPTIONS -- -f -m crc=1,finobt=1,rmapbt=0,reflink=1,bigtime=1,inobtcount=1 \
/dev/loop1 MOUNT_OPTIONS -- -o context=system_u:object_r:root_t:s0 /dev/loop1 \
/mnt/fstests/SCRATCH_DIR
generic/065 _check_xfs_filesystem: filesystem on /dev/loop1 is inconsistent (r)
(see /var/lib/xfstests/results//generic/065.full for details)
_check_dmesg: something found in dmesg (see \
/var/lib/xfstests/results//generic/065.dmesg)
- output mismatch (see /var/lib/xfstests/results//generic/065.out.bad)
--- tests/generic/065.out 2023-10-27 09:04:38.185351816 -0400
+++ /var/lib/xfstests/results//generic/065.out.bad 2023-10-27 09:09:12.145421405 \
-0400 @@ -4,11 +4,11 @@
wrote 65536/65536 bytes at offset 0
XXX Bytes, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)
File 'foo' content after log replay:
-0000000 aa aa aa aa aa aa aa aa aa aa aa aa aa aa aa aa
+0000000 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
*
0020000
...
(Run 'diff -u /var/lib/xfstests/tests/generic/065.out \
/var/lib/xfstests/results//generic/065.out.bad' to see the entire \
diff)
Ran: generic/065
Failures: generic/065
Failed 1 of 1 tests
[2]
[ 440.713107] run fstests generic/065 at 2023-10-27 09:09:11
[ 440.971883] XFS (dm-3): Mounting V5 Filesystem \
6d36b06f-6fbd-4a9f-925c-c49582f14078 [ 440.972968] XFS (dm-3): Ending clean mount
[ 441.037265] XFS (dm-3): Unmounting Filesystem 6d36b06f-6fbd-4a9f-925c-c49582f14078
[ 441.045980] XFS (dm-3): Mounting V5 Filesystem \
6d36b06f-6fbd-4a9f-925c-c49582f14078 [ 441.046947] XFS (dm-3): Starting recovery \
(logdev: internal) [ 441.047283] XFS (dm-3): Ending recovery (logdev: internal)
[ 441.055894] XFS: Assertion failed: ip->i_nblocks == 0, file: fs/xfs/xfs_inode.c, \
line: 2359 [ 441.055920] ------------[ cut here ]------------
[ 441.055921] WARNING: CPU: 3 PID: 212189 at fs/xfs/xfs_message.c:104 \
assfail+0x4e/0x68 [xfs] [ 441.056180] Modules linked in: dm_flakey tls loop lcs ctcm \
fsm qeth ccwgroup zfcp qdio scsi_transport_fc dasd_fba_mod dasd_eckd_mod dasd_mod \
rfkill sunrpc vfio_ccw mdev zcrypt_cex4 vfio_iommu_type1 vfio drm fuse i2c_core \
drm_panel_orientation_quirks xfs libcrc32c ghash_s390 prng aes_s390 virtio_net \
des_s390 sha3_512_s390 net_failover failover sha3_256_s390 virtio_blk dm_mirror \
dm_region_hash dm_log dm_mod pkey zcrypt [ 441.056210] CPU: 3 PID: 212189 Comm: \
kworker/3:5 Kdump: loaded Tainted: G W 6.6.0-rc7+ #1 [ 441.056213] \
Hardware name: IBM 3931 LA1 400 (KVM/Linux) [ 441.056215] Workqueue: \
xfs-inodegc/dm-3 xfs_inodegc_worker [xfs] [ 441.056312] Krnl PSW : 0704c00180000000 \
000003ff7ffb36d2 (assfail+0x52/0x68 [xfs]) [ 441.056410] R:0 T:1 IO:1 \
EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:0 PM:0 RI:0 EA:3 [ 441.056413] Krnl GPRS: \
c000000100000021 000003ff8001d9a0 ffffffffffffffea 000000000000000a [ 441.056415] \
00000380048aba90 0000000000000000 000003ff801272ba 0000000088f81488 [ 441.056417] \
00000000d6301708 000000008cb5d000 00000001c459c800 00000001c459c800 [ 441.056419] \
0000000081de3600 0000000000000000 000003ff7ffb36c0 00000380048abb38 [ 441.056426] \
Krnl Code: 000003ff7ffb36c6: 95001010 cli 16(%r1),0
000003ff7ffb36ca: a774000a brc 7,000003ff7ffb36de
#000003ff7ffb36ce: af000000 mc 0,0
>000003ff7ffb36d2: eb6ff0a80004 lmg %r6,%r15,168(%r15)
000003ff7ffb36d8: 07fe bcr 15,%r14
000003ff7ffb36da: 47000700 bc 0,1792
000003ff7ffb36de: af000000 mc 0,0
000003ff7ffb36e2: 0707 bcr 0,%r7
[ 441.056439] Call Trace:
[ 441.056440] [<000003ff7ffb36d2>] assfail+0x52/0x68 [xfs]
[ 441.056537] ([<000003ff7ffb36c0>] assfail+0x40/0x68 [xfs])
[ 441.056635] [<000003ff7ffaf3ca>] xfs_ifree+0x42a/0x478 [xfs]
[ 441.056737] [<000003ff7ffaf4c8>] xfs_inactive_ifree+0xb0/0x210 [xfs]
[ 441.056815] [<000003ff7ffaf7aa>] xfs_inactive+0x182/0x2e0 [xfs]
[ 441.056899] [<000003ff7ffa1f0c>] xfs_inodegc_worker+0xf4/0x1c8 [xfs]
[ 441.056983] [<000000003242f8f0>] process_one_work+0x1b8/0x408
[ 441.056989] [<000000003242fe40>] worker_thread+0x300/0x460
[ 441.056992] [<000000003243a758>] kthread+0x120/0x128
[ 441.056995] [<00000000323b6fcc>] __ret_from_fork+0x3c/0x58
[ 441.056997] [<0000000032da7072>] ret_from_fork+0xa/0x30
[ 441.057003] Last Breaking-Event-Address:
[ 441.057004] [<000003ff7ffb351c>] xfs_printk_level+0xac/0xd8 [xfs]
[ 441.057095] ---[ end trace 0000000000000000 ]---
[ 441.060319] XFS (dm-3): Unmounting Filesystem 6d36b06f-6fbd-4a9f-925c-c49582f14078
[ 441.109229] XFS (loop0): Unmounting Filesystem \
1eef4fa0-3548-491e-a877-16ca42a411b6
[3]
meta-data=/dev/loop1 isize=512 agcount=4, agsize=655360 blks
= sectsz=512 attr=2, projid32bit=1
= crc=1 finobt=1, sparse=1, rmapbt=0
= reflink=1 bigtime=1 inobtcount=1 nrext64=1
data = bsize=4096 blocks=2621440, imaxpct=25
= sunit=0 swidth=0 blks
naming =version 2 bsize=4096 ascii-ci=0, ftype=1
log =internal log bsize=4096 blocks=16384, version=2
= sectsz=512 sunit=0 blks, lazy-count=1
realtime =none extsz=4096 blocks=0, rtextents=0
Discarding blocks...Done.
_check_xfs_filesystem: filesystem on /dev/loop1 is inconsistent (r)
*** xfs_repair -n output ***
Phase 1 - find and verify superblock...
Phase 2 - using internal log
- zero log...
- scan filesystem freespace and inode maps...
- found root inode chunk
Phase 3 - for each AG...
- scan (but don't clear) agi unlinked lists...
- process known inodes and perform inode discovery...
- agno = 0
bad nblocks 16 for inode 133, would reset to 0
- agno = 1
- agno = 2
- agno = 3
- process newly discovered inodes...
Phase 4 - check for duplicate blocks...
- setting up duplicate extent list...
- check for inodes claiming duplicate blocks...
- agno = 0
- agno = 2
- agno = 1
bad nblocks 16 for inode 133, would reset to 0
- agno = 3
No modify flag set, skipping phase 5
Phase 6 - check inode connectivity...
- traversing filesystem ...
- traversal finished ...
- moving disconnected inodes to lost+found ...
Phase 7 - verify link counts...
No modify flag set, skipping filesystem flush and exiting.
*** end xfs_repair output
*** mount output ***
proc on /proc type proc (rw,nosuid,nodev,noexec,relatime)
sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime,seclabel)
devtmpfs on /dev type devtmpfs \
(rw,nosuid,seclabel,size=4096k,nr_inodes=986186,mode=755,inode64) securityfs on \
/sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime) tmpfs on \
/dev/shm type tmpfs (rw,nosuid,nodev,seclabel,inode64) devpts on /dev/pts type devpts \
(rw,nosuid,noexec,relatime,seclabel,gid=5,mode=620,ptmxmode=000) tmpfs on /run type \
tmpfs (rw,nosuid,nodev,seclabel,size=1592372k,nr_inodes=819200,mode=755,inode64) \
cgroup2 on /sys/fs/cgroup type cgroup2 \
(rw,nosuid,nodev,noexec,relatime,seclabel,nsdelegate,memory_recursiveprot) pstore on \
/sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime,seclabel) bpf on \
/sys/fs/bpf type bpf (rw,nosuid,nodev,noexec,relatime,mode=700)
/dev/mapper/rhel_s390x--kvm--091-root on / type xfs \
(rw,relatime,seclabel,attr2,inode64,logbufs=8,logbsize=32k,noquota) selinuxfs on \
/sys/fs/selinux type selinuxfs (rw,nosuid,noexec,relatime) systemd-1 on \
/proc/sys/fs/binfmt_misc type autofs \
(rw,relatime,fd=29,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=3937) \
mqueue on /dev/mqueue type mqueue (rw,nosuid,nodev,noexec,relatime,seclabel) debugfs \
on /sys/kernel/debug type debugfs (rw,nosuid,nodev,noexec,relatime,seclabel) tracefs \
on /sys/kernel/tracing type tracefs (rw,nosuid,nodev,noexec,relatime,seclabel) \
hugetlbfs on /dev/hugepages type hugetlbfs (rw,relatime,seclabel,pagesize=1M) \
configfs on /sys/kernel/config type configfs (rw,nosuid,nodev,noexec,relatime) \
fusectl on /sys/fs/fuse/connections type fusectl (rw,nosuid,nodev,noexec,relatime) \
ramfs on /run/credentials/systemd-sysctl.service type ramfs \
(ro,nosuid,nodev,noexec,relatime,seclabel,mode=700) ramfs on \
/run/credentials/systemd-tmpfiles-setup-dev.service type ramfs \
(ro,nosuid,nodev,noexec,relatime,seclabel,mode=700)
/dev/vda1 on /boot type xfs \
(rw,relatime,seclabel,attr2,inode64,logbufs=8,logbsize=32k,noquota)
/dev/mapper/rhel_s390x--kvm--091-home on /home type xfs \
(rw,relatime,seclabel,attr2,inode64,logbufs=8,logbsize=32k,noquota) ramfs on \
/run/credentials/systemd-tmpfiles-setup.service type ramfs \
(ro,nosuid,nodev,noexec,relatime,seclabel,mode=700) sunrpc on /var/lib/nfs/rpc_pipefs \
type rpc_pipefs (rw,relatime) tmpfs on /run/user/0 type tmpfs \
(rw,nosuid,nodev,relatime,seclabel,size=796184k,nr_inodes=199046,mode=700,inode64)
*** end mount output
[3]
[ 3078.795314] run fstests generic/506 at 2023-10-27 09:53:09
[ 3079.005423] XFS (loop1): Mounting V5 Filesystem \
c94f4c60-e4fd-4fec-b130-e245b3880061 [ 3079.006596] XFS (loop1): Ending clean mount
[ 3079.007556] XFS (loop1): User initiated shutdown received.
[ 3079.007565] XFS (loop1): Metadata I/O Error (0x4) detected at \
xfs_fs_goingdown+0x5a/0xf8 [xfs] (fs/xfs/xfs_fsops.c:492). Shutting down filesystem. \
[ 3079.007769] XFS (loop1): Please unmount the filesystem and rectify the problem(s) \
[ 3079.008944] XFS (loop1): Unmounting Filesystem \
c94f4c60-e4fd-4fec-b130-e245b3880061 [ 3079.031168] XFS (loop1): Mounting V5 \
Filesystem ba7c075d-3018-49c9-a17d-0689c02892e2 [ 3079.032478] XFS (loop1): Ending \
clean mount [ 3079.032515] XFS (loop1): Quotacheck needed: Please wait.
[ 3079.036144] XFS (loop1): Quotacheck: Done.
[ 3079.040399] XFS (loop1): Unmounting Filesystem \
ba7c075d-3018-49c9-a17d-0689c02892e2 [ 3079.044961] XFS (loop1): Mounting V5 \
Filesystem ba7c075d-3018-49c9-a17d-0689c02892e2 [ 3079.045808] XFS (loop1): Ending \
clean mount [ 3079.055991] XFS (loop1): User initiated shutdown received.
[ 3079.055994] XFS (loop1): Log I/O Error (0x6) detected at \
xfs_fs_goingdown+0xb4/0xf8 [xfs] (fs/xfs/xfs_fsops.c:495). Shutting down filesystem. \
[ 3079.056076] XFS (loop1): Please unmount the filesystem and rectify the problem(s) \
[ 3079.099382] XFS (loop1): Unmounting Filesystem \
ba7c075d-3018-49c9-a17d-0689c02892e2 [ 3079.102254] XFS (loop1): Mounting V5 \
Filesystem ba7c075d-3018-49c9-a17d-0689c02892e2 [ 3079.103055] XFS (loop1): Starting \
recovery (logdev: internal) [ 3079.103217] XFS (loop1): Ending recovery (logdev: \
internal) [ 3079.106775] XFS (loop1): Unmounting Filesystem \
ba7c075d-3018-49c9-a17d-0689c02892e2 [ 3079.113727] XFS (loop1): Mounting V5 \
Filesystem ba7c075d-3018-49c9-a17d-0689c02892e2 [ 3079.114471] XFS (loop1): Ending \
clean mount [ 3079.115334] XFS: Assertion failed: error != -ENOENT, file: \
fs/xfs/xfs_trans.c, line: 1310 [ 3079.115372] ------------[ cut here ]------------
[ 3079.115374] WARNING: CPU: 1 PID: 2035839 at fs/xfs/xfs_message.c:104 \
assfail+0x4e/0x68 [xfs] [ 3079.115495] Modules linked in: dm_log_writes dm_thin_pool \
dm_persistent_data dm_bio_prison sd_mod t10_pi sg dm_snapshot dm_bufio ext4 mbcache \
jbd2 dm_flakey tls loop lcs ctcm fsm qeth ccwgroup zfcp qdio scsi_transport_fc \
dasd_fba_mod dasd_eckd_mod dasd_mod rfkill sunrpc vfio_ccw mdev zcrypt_cex4 \
vfio_iommu_type1 vfio drm fuse i2c_core drm_panel_orientation_quirks xfs libcrc32c \
ghash_s390 prng aes_s390 virtio_net des_s390 sha3_512_s390 net_failover failover \
sha3_256_s390 virtio_blk dm_mirror dm_region_hash dm_log dm_mod pkey zcrypt [last \
unloaded: scsi_debug] [ 3079.115532] CPU: 1 PID: 2035839 Comm: touch Kdump: loaded \
Tainted: G W 6.6.0-rc7+ #1 [ 3079.115534] Hardware name: IBM 3931 LA1 \
400 (KVM/Linux) [ 3079.115536] Krnl PSW : 0704c00180000000 000003ff7ffb36d2 \
(assfail+0x52/0x68 [xfs]) [ 3079.115625] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 \
P:0 AS:3 CC:0 PM:0 RI:0 EA:3 [ 3079.115627] Krnl GPRS: c000000100000021 \
000003ff8001d9a0 ffffffffffffffea 000000000000000a [ 3079.115629] \
0000038006d0f928 0000000000000000 000003ff80129d40 000000008f254398 [ 3079.115630] \
0000038006d0fb20 000000008f254000 00000380fffffffe 00000000a12a8400 [ 3079.115632] \
000003ff8762ef68 0000000000000000 000003ff7ffb36c0 0000038006d0f9d0 [ 3079.115638] \
Krnl Code: 000003ff7ffb36c6: 95001010 cli 16(%r1),0
000003ff7ffb36ca: a774000a brc 7,000003ff7ffb36de
#000003ff7ffb36ce: af000000 mc 0,0
>000003ff7ffb36d2: eb6ff0a80004 lmg %r6,%r15,168(%r15)
000003ff7ffb36d8: 07fe bcr 15,%r14
000003ff7ffb36da: 47000700 bc 0,1792
000003ff7ffb36de: af000000 mc 0,0
000003ff7ffb36e2: 0707 bcr 0,%r7
[ 3079.115648] Call Trace:
[ 3079.115649] [<000003ff7ffb36d2>] assfail+0x52/0x68 [xfs]
[ 3079.115727] ([<000003ff7ffb36c0>] assfail+0x40/0x68 [xfs])
[ 3079.115803] [<000003ff7ffc0c34>] xfs_trans_alloc_ichange+0x274/0x318 [xfs]
[ 3079.115880] [<000003ff7ffa9058>] xfs_setattr_nonsize+0xa0/0x478 [xfs]
[ 3079.115966] [<00000000327530ce>] notify_change+0x38e/0x530
[ 3079.115972] [<0000000032776fee>] vfs_utimes+0x12e/0x268
[ 3079.115976] [<000000003277740e>] do_utimes+0x6e/0xb0
[ 3079.115980] [<00000000327779de>] __s390x_sys_utimensat+0x86/0xc0
[ 3079.115983] [<0000000032d97060>] __do_syscall+0x1d0/0x1f8
[ 3079.115988] [<0000000032da7040>] system_call+0x70/0x98
[ 3079.115992] Last Breaking-Event-Address:
[ 3079.115993] [<000003ff7ffb351c>] xfs_printk_level+0xac/0xd8 [xfs]
[ 3079.116070] ---[ end trace 0000000000000000 ]---
[ 3079.127976] XFS (loop1): User initiated shutdown received.
[ 3079.127983] XFS (loop1): Log I/O Error (0x6) detected at \
xfs_fs_goingdown+0xb4/0xf8 [xfs] (fs/xfs/xfs_fsops.c:495). Shutting down filesystem. \
[ 3079.128127] XFS (loop1): Please unmount the filesystem and rectify the problem(s) \
[ 3079.179362] XFS (loop1): Unmounting Filesystem \
ba7c075d-3018-49c9-a17d-0689c02892e2 [ 3079.182441] XFS (loop1): Mounting V5 \
Filesystem ba7c075d-3018-49c9-a17d-0689c02892e2 [ 3079.183327] XFS (loop1): Starting \
recovery (logdev: internal) [ 3079.183464] XFS (loop1): Ending recovery (logdev: \
internal) [ 3079.186928] XFS (loop1): Unmounting Filesystem \
ba7c075d-3018-49c9-a17d-0689c02892e2 [ 3079.198937] XFS (loop0): Unmounting \
Filesystem 1eef4fa0-3548-491e-a877-16ca42a411b6
[prev in list] [next in list] [prev in thread] [next in thread]
Configure |
About |
News |
Add a list |
Sponsored by KoreLogic