Bug #57657
Updated by Patrick Donnelly over 1 year ago
<pre>
2022-09-22T13:11:47.201+0000 7f83d76d9700 20 mds.0.scrubstack dequeue [inode 0x10000000001 [...2,head] /parent/flushed/ auth v14 ap=1 f(v0 m2022-09-22T13:11:00.272150+0000 3=3+0) n(v0 rc2022-09-22T13:11:00.274637+0000 b17 4=3+1) (ifile excl) (iversion lock) | request=0 lock=0 dirfrag=1 caps=0 authpin=1 scrubqueue=1 0x55fcb96ab180] from ScrubStack
2022-09-22T13:11:47.201+0000 7f83d76d9700 10 mds.0.scrubstack scrub_dirfrag [dir 0x10000000001 /parent/flushed/ [2,head] auth v=14 cv=13/13 ap=1+0 state=1610612737|complete f(v0 m2022-09-22T13:11:00.272150+0000 3=3+0) n(v0 rc2022-09-22T13:11:00.274637+0000 b17 3=3+0) hs=2+0,ss=0+0 | child=1 dirty=1 waiter=0 authpin=1 scrubqueue=1 0x55fcb96bd180]
2022-09-22T13:11:47.201+0000 7f83d76d9700 20 mds.0.cache.den(0x10000000001 charlie) scrubbing [dentry #0x1/parent/flushed/charlie [2,head] auth (dversion lock) pv=0 v=13 ino=0x100000001f8 state=1073741824 0x55fcb96aea00] next_seq = 2
2022-09-22T13:11:47.201+0000 7f83d76d9700 10 mds.0.cache.snaprealm(0x1 seq 1 0x55fcb969a400) get_snaps (seq 1 cached_seq 1)
2022-09-22T13:11:47.201+0000 7f83d76d9700 10 mds.0.scrubstack _enqueue with {[inode 0x100000001f8 [2,head] /parent/flushed/charlie auth v12 s=7 n(v0 rc2022-09-22T13:11:00.274637+0000 b7 1=1+0) (iversion lock) 0x55fcb96ab700]}, top=0
2022-09-22T13:11:47.201+0000 7f83d76d9700 20 mds.0.cache.ino(0x100000001f8) scrub_initialize with scrub_version 12
2022-09-22T13:11:47.201+0000 7f83d76d9700 20 mds.0.scrubstack enqueue [inode 0x100000001f8 [2,head] /parent/flushed/charlie auth v12 s=7 n(v0 rc2022-09-22T13:11:00.274637+0000 b7 1=1+0) (iversion lock) 0x55fcb96ab700] to bottom of ScrubStack
2022-09-22T13:11:47.201+0000 7f83d76d9700 20 mds.0.cache.den(0x10000000001 alpha) scrubbing [dentry #0x1/parent/flushed/alpha [2,head] auth (dversion lock) pv=0 v=13 ino=0x10000000002 state=1073741824 0x55fcb96aec80] next_seq = 2
2022-09-22T13:11:47.201+0000 7f83d76d9700 10 mds.0.cache.snaprealm(0x1 seq 1 0x55fcb969a400) get_snaps (seq 1 cached_seq 1)
2022-09-22T13:11:47.201+0000 7f83d76d9700 10 mds.0.scrubstack _enqueue with {[inode 0x10000000002 [2,head] /parent/flushed/alpha auth v8 s=5 n(v0 rc2022-09-22T13:11:00.267473+0000 b5 1=1+0) (iversion lock) 0x55fcb96bf600]}, top=0
2022-09-22T13:11:47.201+0000 7f83d76d9700 20 mds.0.cache.ino(0x10000000002) scrub_initialize with scrub_version 8
2022-09-22T13:11:47.201+0000 7f83d76d9700 20 mds.0.scrubstack enqueue [inode 0x10000000002 [2,head] /parent/flushed/alpha auth v8 s=5 n(v0 rc2022-09-22T13:11:00.267473+0000 b5 1=1+0) (iversion lock) 0x55fcb96bf600] to bottom of ScrubStack
2022-09-22T13:11:47.201+0000 7f83d76d9700 1 mds.0.cache.dir(0x10000000001) mismatch between head items and fnode.fragstat! printing dentries
2022-09-22T13:11:47.201+0000 7f83d76d9700 1 mds.0.cache.dir(0x10000000001) get_num_head_items() = 2; fnode.fragstat.nfiles=3 fnode.fragstat.nsubdirs=0
2022-09-22T13:11:47.201+0000 7f83d76d9700 1 mds.0.cache.dir(0x10000000001) mismatch between child accounted_rstats and my rstats!
2022-09-22T13:11:47.201+0000 7f83d76d9700 1 mds.0.cache.dir(0x10000000001) total of child dentries: n(v0 rc2022-09-22T13:11:00.274637+0000 b12 2=2+0)
2022-09-22T13:11:47.201+0000 7f83d76d9700 1 mds.0.cache.dir(0x10000000001) my rstats: n(v0 rc2022-09-22T13:11:00.274637+0000 b17 3=3+0)
2022-09-22T13:11:47.201+0000 7f83d76d9700 10 mds.0.cache.dir(0x10000000001) check_rstats complete on 0x55fcb96bd180
2022-09-22T13:11:47.201+0000 7f83d76d9700 0 log_channel(cluster) log [WRN] : Scrub error on dir 0x10000000001 (/parent/flushed) see mds.a log and `damage ls` output for details
2022-09-22T13:11:47.201+0000 7f83d76d9700 20 mds.0.cache.dir(0x10000000001) scrub_finished
</pre>
From: /ceph/teuthology-archive/pdonnell-2022-09-22_12:22:37-fs-wip-pdonnell-testing-20220920.234701-distro-default-smithi/7041083/remote/smithi110/log/ceph-mds.a.log.gz
This is with the new postgres/scrub/snap changes to fs:workload. What's particularly relevant to this change is that scrub now properly reports damage of dirfrags where check_rstats locates damage. It did not before.