Ceph » CephFS

Currently the kclient's testing branch has merged the fscryption name related patches, which will limit the MAX_NAME to 240 instead of the default 256.

Will found one way to fix it.

Patrick Donnelly wrote:

[...]

/ceph/teuthology-archive/pdonnell-2022-07-22_19:42:58-fs-wip-pdonnell-testing-20220721.235756-distro-default-smithi/6945847/teuthology.log

It's a MDS side bug, not kclient's:

Such as for the following error, the errno is EXDEV:

2022-07-22T20:52:25.830 INFO:tasks.workunit.client.0.smithi135.stderr:++ expr 3 + 1
2022-07-22T20:52:25.831 INFO:tasks.workunit.client.0.smithi135.stderr:+ ntest=4
2022-07-22T20:52:25.831 INFO:tasks.workunit.client.0.smithi135.stderr:+ expect 0 link fstest_d22bbf65b5ea67dbd4f2534c56018c49 _123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_1234
2022-07-22T20:52:25.831 INFO:tasks.workunit.client.0.smithi135.stderr:+ e=0
2022-07-22T20:52:25.831 INFO:tasks.workunit.client.0.smithi135.stderr:+ shift
2022-07-22T20:52:25.831 INFO:tasks.workunit.client.0.smithi135.stderr:++ /home/ubuntu/cephtest/mnt.0/client.0/tmp/tmp/../pjd-fstest-20090130-RC/tests/link/../../fstest link fstest_d22bbf65b5ea67dbd4f2534c56018c49 _123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_1234
2022-07-22T20:52:25.832 INFO:tasks.workunit.client.0.smithi135.stderr:++ tail -1
2022-07-22T20:52:25.832 INFO:tasks.workunit.client.0.smithi135.stderr:+ r=EXDEV
2022-07-22T20:52:25.832 INFO:tasks.workunit.client.0.smithi135.stderr:+ echo EXDEV
2022-07-22T20:52:25.832 INFO:tasks.workunit.client.0.smithi135.stderr:+ egrep '^0$'
2022-07-22T20:52:25.833 INFO:tasks.workunit.client.0.smithi135.stderr:+ '[' 1 -eq 0 ']'
2022-07-22T20:52:25.833 INFO:tasks.workunit.client.0.smithi135.stderr:+ echo 'not ok 4'

And in the remote/smithi141/log/a190153a-09fe-11ed-842f-001a4aab830c/ceph-mds.b.log.gz, before the pjd test #4 in test #3 it will unlink the file _123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_1234:

teuthology logs:

2022-07-22T20:52:25.828 INFO:tasks.workunit.client.0.smithi135.stderr:+ ntest=3
2022-07-22T20:52:25.828 INFO:tasks.workunit.client.0.smithi135.stderr:+ expect 0 unlink _123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_1234

mds.b logs:

2022-07-22T20:52:25.348+0000 7fe2bf6d4700  1 -- [v2:172.21.15.141:6838/1279389197,v1:172.21.15.141:6839/1279389197] <== client.24956 172.21.15.135:0/377103332 1199 ==== client_request(client.24956:592 unlink #0x10000000220/_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_1234 2022-07-22T20:52:25.348771+0000 caller_uid=0, caller_gid=0{0,}) v4 ==== 443+0+0 (crc 0 0 0) 0x55b102d34b00 con 0x55b10295e400
...
2022-07-22T20:52:25.348+0000 7fe2bf6d4700 10 mds.0.locker process_request_cap_release client.24956 pAsXsFscr on [inode 0x100000000d3 [2,head] /volumes/_nogroup/sv_1/6ae107c1-dbbf-417a-8a51-99df917679be/client.0/tmp/tmp/_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_1234 auth v455 pv458 ap=3 s=0 n(v0 1=1+0)->n(v0 rc2022-07-22T20:52:25.343772+0000 1=1+0) (ilink xlockdone x=1) (iversion lock w=1 last_client=24956) caps={24956=pAsLsXsFscr/pFscr@3},l=24956 | request=2 lock=3 caps=1 authpin=1 0x55b103050000]

And after that the inode 0x100000000d3 will go into the stray directory:

2022-07-22T20:52:25.349+0000 7fe2bf6d4700 10 mds.0.locker  got xlock on (dn xlock x=1 by 0x55b1028aec00) [dentry #0x100/stray1/100000000d3 [2,head] auth NULL (dn xlock x=1 by 0x55b1028aec00) (dversion lock) pv=0 v=492 ap=2 ino=(nil) state=1342177281|new | request=1 lock=1 authpin=1 0x55b103059b80]

So when the pjd test #4 began later:

2022-07-22T20:52:25.353+0000 7fe2bf6d4700  1 -- [v2:172.21.15.141:6838/1279389197,v1:172.21.15.141:6839/1279389197] <== client.24956 172.21.15.135:0/377103332 1200 ==== client_request(client.24956:593 link #0x10000000220/_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_1234 #0x10000000220/fstest_d22bbf65b5ea67dbd4f2534c56018c49 2022-07-22T20:52:25.353771+0000 caller_uid=0, caller_gid=0{0,}) v4 ==== 438+0+0 (crc 0 0 0) 0x55b102b4d8c0 con 0x55b10295e400

And when traversing the path2, it will find the it in the stray directory:

2022-07-22T20:52:25.354+0000 7fe2bf6d4700  7 mds.0.cache traverse: opening base ino 0x10000000220 snap head
2022-07-22T20:52:25.354+0000 7fe2bf6d4700 10 mds.0.locker try_rdlock_snap_layout request(client.24956:593 nref=3 cr=0x55b102b4d8c0) [inode 0x10000000220 [...2,head] /volumes/_nogroup/sv_1/6ae107c1-dbbf-417a-8a51-99df917679be/client.0/tmp/tmp/ auth{1=1,2=1,3=1,4=1} v199 pv209 ap=6 DIRTYPARENT f(v0 m2022-07-22T20:52:25.274773+0000 1=0+1)->f(v0 m2022-07-22T20:52:25.348771+0000 1=1+0) n(v3 rc2022-07-22T20:52:25.274773+0000 2=0+2)->n(v3 rc2022-07-22T20:52:25.348771+0000 1=0+1) (iauth sync r=1) (isnap sync r=5) (inest mix w=4 dirty) (ipolicy sync r=1) (ifile excl w=4) (iversion lock w=4 last_client=24956) caps={24956=pAsLsXsFsxcr/pAsLsXsFsxcral@52},l=24956 | dirtyscattered=1 request=0 lock=6 dirfrag=1 caps=1 dirtyrstat=0 dirtyparent=1 replicated=1 dirty=1 authpin=1 scrubqueue=0 0x55b1030a2c00]
2022-07-22T20:52:25.354+0000 7fe2bf6d4700 12 mds.0.cache traverse: path seg depth 0 'fstest_d22bbf65b5ea67dbd4f2534c56018c49' snapid head
2022-07-22T20:52:25.354+0000 7fe2bf6d4700 20 mds.0.cache.dir(0x10000000220) lookup (fstest_d22bbf65b5ea67dbd4f2534c56018c49, 'head')
2022-07-22T20:52:25.354+0000 7fe2bf6d4700 20 mds.0.cache.dir(0x10000000220)   hit -> (fstest_d22bbf65b5ea67dbd4f2534c56018c49,head)
2022-07-22T20:52:25.354+0000 7fe2bf6d4700  7 mds.0.cache linking in remote in [inode 0x100000000d3 [2,head] ~mds0/stray1/100000000d3 auth v455 pv493 ap=4 s=0 n(v0 1=1+0)->n(v0 rc2022-07-22T20:52:25.348771+0000 1=1+0) (ilink xlockdone x=2) (iversion lock w=2 last_client=24956) caps={24956=pAsXsFscr/pFscr@3},l=24956 | request=3 lock=5 caps=1 authpin=1 0x55b103050000]

And then it assume the two paths were in two different volumes and then fail it with EXDEV:

2022-07-22T20:52:25.354+0000 7fe2bf6d4700  7 mds.0.server target is in different subvolume, failing...
2022-07-22T20:52:25.354+0000 7fe2bf6d4700  7 mds.0.server reply_client_request -18 ((18) Invalid cross-device link) client_request(client.24956:593 link #0x10000000220/_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789_1234 #0x10000000220/fstest_d22bbf65b5ea67dbd4f2534c56018c49 2022-07-22T20:52:25.353771+0000 caller_uid=0, caller_gid=0{0,}) v4