Oh, sorry... on linux v5.15.34
On Wed, May 18, 2022 at 04:59:49PM +1000, Chris Dunlop wrote:
Hi,
I have an fstrim that's been running for over 48 hours on a 256T thin
provisioned XFS fs containing around 55T of actual data on a slow
subsystem (ceph 8,3 erasure-encoded rbd). I don't think there would be
an an enourmous amount of data to trim, maybe a few T, but I've no
idea how long how long it might be expected to take. In an attempt to
see what the what the fstrim was doing, I ran an strace on it. The
strace has been sitting there without output and unkillable since
then, now 5+ hours ago. Since the strace, on that same filesystem I
now have 123 df processes and 615 rm processes -- and growing -- that
are blocked in xfs_inodegc_flush, e.g.:
May 18 15:31:52 d5 kernel: task:df state:D stack: 0 pid:31741 ppid: 1 flags:0x00004004
May 18 15:31:52 d5 kernel: Call Trace:
May 18 15:31:52 d5 kernel: <TASK>
May 18 15:31:52 d5 kernel: __schedule+0x241/0x740
May 18 15:31:52 d5 kernel: ? lock_is_held_type+0x97/0x100
May 18 15:31:52 d5 kernel: schedule+0x3a/0xa0
May 18 15:31:52 d5 kernel: schedule_timeout+0x271/0x310
May 18 15:31:52 d5 kernel: ? find_held_lock+0x2d/0x90
May 18 15:31:52 d5 kernel: ? sched_clock_cpu+0x9/0xa0
May 18 15:31:52 d5 kernel: ? lock_release+0x214/0x350
May 18 15:31:52 d5 kernel: wait_for_completion+0x7b/0xc0
May 18 15:31:52 d5 kernel: __flush_work+0x217/0x350
May 18 15:31:52 d5 kernel: ? flush_workqueue_prep_pwqs+0x120/0x120
May 18 15:31:52 d5 kernel: ? wait_for_completion+0x1c/0xc0
May 18 15:31:52 d5 kernel: xfs_inodegc_flush.part.24+0x62/0xc0 [xfs]
May 18 15:31:52 d5 kernel: xfs_fs_statfs+0x37/0x1a0 [xfs]
May 18 15:31:52 d5 kernel: statfs_by_dentry+0x3c/0x60
May 18 15:31:52 d5 kernel: vfs_statfs+0x16/0xd0
May 18 15:31:52 d5 kernel: user_statfs+0x44/0x80
May 18 15:31:52 d5 kernel: __do_sys_statfs+0x10/0x30
May 18 15:31:52 d5 kernel: do_syscall_64+0x34/0x80
May 18 15:31:52 d5 kernel: entry_SYSCALL_64_after_hwframe+0x44/0xae
May 18 15:31:52 d5 kernel: RIP: 0033:0x7fe9e9db3c07
May 18 15:31:52 d5 kernel: RSP: 002b:00007ffe08f50178 EFLAGS: 00000246 ORIG_RAX: 0000000000000089
May 18 15:31:52 d5 kernel: RAX: ffffffffffffffda RBX: 0000555963fcae40 RCX: 00007fe9e9db3c07
May 18 15:31:52 d5 kernel: RDX: 00007ffe08f50400 RSI: 00007ffe08f50180 RDI: 0000555963fcae40
May 18 15:31:52 d5 kernel: RBP: 00007ffe08f50180 R08: 0000555963fcae80 R09: 0000000000000000
May 18 15:31:52 d5 kernel: R10: 0000000000000000 R11: 0000000000000246 R12: 00007ffe08f50220
May 18 15:31:52 d5 kernel: R13: 0000000000000000 R14: 0000555963fcae80 R15: 0000555963fcae40
May 18 15:31:52 d5 kernel: </TASK>
Full 1.5M sysrq output at: https://file.io/bWOL8F7mzKI6
That stack trace is uncomfortably familiar:
Subject: Highly reflinked and fragmented considered harmful?
https://lore.kernel.org/linux-xfs/20220509024659.GA62606@xxxxxxxxxxxx/
FYI:
# xfs_info /vol
meta-data=/dev/vg01/vol isize=512 agcount=257, agsize=268434432 blks
= sectsz=4096 attr=2, projid32bit=1
= crc=1 finobt=1, sparse=1, rmapbt=1
= reflink=1 bigtime=1 inobtcount=1
data = bsize=4096 blocks=68719475712, imaxpct=1
= sunit=1024 swidth=8192 blks
naming =version 2 bsize=4096 ascii-ci=0, ftype=1
log =internal log bsize=4096 blocks=521728, version=2
= sectsz=4096 sunit=1 blks, lazy-count=1
realtime =none extsz=4096 blocks=0, rtextents=0
Is there something I can do to "unstick" things, or is it time to hit
the reset, and hope the recovery on mount isn't onerous?
Aside from that immediate issue, what has gone wrong here?
Cheers,
Chris
