Actions
Bug #65705
openqa: snaptest-multiple-capsnaps.sh failure
Status:
Fix Under Review
Priority:
High
Assignee:
Category:
Correctness/Safety
Target version:
% Done:
0%
Source:
Q/A
Tags:
Backport:
squid,reef
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(FS):
MDS
Labels (FS):
snapshots
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
2024-04-30T09:12:39.043 INFO:tasks.workunit.client.0.smithi107.stderr:+ ls -al .snap/1/a .snap/2/a .snap/3/a .snap/4/a .snap/5/a
2024-04-30T09:12:39.072 INFO:tasks.workunit.client.0.smithi107.stdout:-rw-rw-r-- 1 ubuntu ubuntu 0 Apr 30 09:12 .snap/1/a
2024-04-30T09:12:39.072 INFO:tasks.workunit.client.0.smithi107.stdout:-rw-rw-r-- 1 ubuntu ubuntu 0 Apr 30 09:12 .snap/2/a
2024-04-30T09:12:39.072 INFO:tasks.workunit.client.0.smithi107.stdout:-rwxrwxrwx 1 ubuntu ubuntu 5 Apr 30 09:12 .snap/3/a
2024-04-30T09:12:39.072 INFO:tasks.workunit.client.0.smithi107.stdout:-rw-rw-rw- 1 ubuntu ubuntu 5 Apr 30 09:12 .snap/4/a
2024-04-30T09:12:39.073 INFO:tasks.workunit.client.0.smithi107.stdout:-rw-rw-rw- 1 ubuntu ubuntu 5 Apr 30 09:12 .snap/5/a
2024-04-30T09:12:39.073 INFO:tasks.workunit.client.0.smithi107.stderr:+ grep asdf .snap/1/a
2024-04-30T09:12:39.075 DEBUG:teuthology.orchestra.run:got remote process result: 1
2024-04-30T09:12:39.076 INFO:tasks.workunit:Stopping ['fs/snaps'] on client.0...
2024-04-30T09:12:39.076 DEBUG:teuthology.orchestra.run.smithi107:> sudo rm -rf -- /home/ubuntu/cephtest/workunits.list.client.0 /home/ubuntu/cephtest/clone.client.0
2024-04-30T09:12:40.430 ERROR:teuthology.run_tasks:Saw exception from tasks.
Traceback (most recent call last):
File "/home/teuthworker/src/git.ceph.com_teuthology_9481b1d62f50e7d0a4f3dd83adf6945b08d5ff17/teuthology/run_tasks.py", line 105, in run_tasks
manager = run_one_task(taskname, ctx=ctx, config=config)
File "/home/teuthworker/src/git.ceph.com_teuthology_9481b1d62f50e7d0a4f3dd83adf6945b08d5ff17/teuthology/run_tasks.py", line 83, in run_one_task
return task(**kwargs)
File "/home/teuthworker/src/git.ceph.com_ceph-c_8feaf7d9864e980041b042fd5d964ac18adfd20f/qa/tasks/workunit.py", line 145, in task
_spawn_on_all_clients(ctx, refspec, all_tasks, config.get('env'),
File "/home/teuthworker/src/git.ceph.com_ceph-c_8feaf7d9864e980041b042fd5d964ac18adfd20f/qa/tasks/workunit.py", line 295, in _spawn_on_all_clients
p.spawn(_run_tests, ctx, refspec, role, [unit], env,
File "/home/teuthworker/src/git.ceph.com_teuthology_9481b1d62f50e7d0a4f3dd83adf6945b08d5ff17/teuthology/parallel.py", line 84, in __exit__
for result in self:
File "/home/teuthworker/src/git.ceph.com_teuthology_9481b1d62f50e7d0a4f3dd83adf6945b08d5ff17/teuthology/parallel.py", line 98, in __next__
resurrect_traceback(result)
File "/home/teuthworker/src/git.ceph.com_teuthology_9481b1d62f50e7d0a4f3dd83adf6945b08d5ff17/teuthology/parallel.py", line 30, in resurrect_traceback
raise exc.exc_info[1]
File "/home/teuthworker/src/git.ceph.com_teuthology_9481b1d62f50e7d0a4f3dd83adf6945b08d5ff17/teuthology/parallel.py", line 23, in capture_traceback
return func(*args, **kwargs)
File "/home/teuthworker/src/git.ceph.com_ceph-c_8feaf7d9864e980041b042fd5d964ac18adfd20f/qa/tasks/workunit.py", line 434, in _run_tests
remote.run(
File "/home/teuthworker/src/git.ceph.com_teuthology_9481b1d62f50e7d0a4f3dd83adf6945b08d5ff17/teuthology/orchestra/remote.py", line 523, in run
r = self._runner(client=self.ssh, name=self.shortname, **kwargs)
File "/home/teuthworker/src/git.ceph.com_teuthology_9481b1d62f50e7d0a4f3dd83adf6945b08d5ff17/teuthology/orchestra/run.py", line 455, in run
r.wait()
File "/home/teuthworker/src/git.ceph.com_teuthology_9481b1d62f50e7d0a4f3dd83adf6945b08d5ff17/teuthology/orchestra/run.py", line 161, in wait
self._raise_for_status()
File "/home/teuthworker/src/git.ceph.com_teuthology_9481b1d62f50e7d0a4f3dd83adf6945b08d5ff17/teuthology/orchestra/run.py", line 181, in _raise_for_status
raise CommandFailedError(
teuthology.exceptions.CommandFailedError: Command failed (workunit test fs/snaps/snaptest-multiple-capsnaps.sh) on smithi107 with status 1: 'mkdir -p -- /home/ubuntu/cephtest/mnt.0/client.0/tmp && cd -- /home/ubuntu/cephtest/mnt.0/client.0/tmp && CEPH_CLI_TEST_DUP_COMMAND=1 CEPH_REF=8feaf7d9864e980041b042fd5d964ac18adfd20f TESTDIR="/home/ubuntu/cephtest" CEPH_ARGS="--cluster ceph" CEPH_ID="0" PATH=$PATH:/usr/sbin CEPH_BASE=/home/ubuntu/cephtest/clone.client.0 CEPH_ROOT=/home/ubuntu/cephtest/clone.client.0 CEPH_MNT=/home/ubuntu/cephtest/mnt.0 adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 6h /home/ubuntu/cephtest/clone.client.0/qa/workunits/fs/snaps/snaptest-multiple-capsnaps.sh'
From: /teuthology/pdonnell-2024-04-30_05:04:19-fs-wip-pdonnell-testing-20240429.210911-debug-distro-default-smithi/7680644/teuthology.log
Updated by Venky Shankar 11 days ago
Xiubo, this is using the distro kernel. Maybe the relevant kclient fixes haven't yet landed in the distro kernel?
Updated by Xiubo Li 11 days ago ยท Edited
Venky Shankar wrote in #note-2:
Xiubo, this is using the distro kernel. Maybe the relevant kclient fixes haven't yet landed in the distro kernel?
No, this is using the k-testing kernel. And a different issue with https://tracker.ceph.com/issues/59343.
2024-04-30T08:47:05.039 INFO:teuthology.task.kernel:Installing kernel 806ec36b21129f113ce356c007dd59694d340b37 on client.0... 2024-04-30T08:47:05.040 DEBUG:teuthology.orchestra.run.smithi107:> sudo dpkg -i /tmp/linux-image.deb 2024-04-30T08:47:05.519 INFO:teuthology.orchestra.run.smithi107.stdout:Selecting previously unselected package linux-image-6.9.0-rc3-g806ec36b2112. 2024-04-30T08:47:07.548 INFO:teuthology.orchestra.run.smithi107.stdout:(Reading database ... 129542 files and directories currently installed.) 2024-04-30T08:47:07.553 INFO:teuthology.orchestra.run.smithi107.stdout:Preparing to unpack /tmp/linux-image.deb ...
I have checked the mds logs and found that there was a flush cap request came just before the flush snap request and removed the need_snapflush={2b2=4846,2b3=4846} from 0x1000000a2bb directly:
2024-04-30T09:12:38.870+0000 7f3c0dc00640 1 -- [v2:172.21.15.107:6835/1150090015,v1:172.21.15.107:6837/1150090015] <== client.4846 v1:172.21.15.107:0/3095293583 424185 ==== client_caps(update ino 0x1000000a2bb 1 seq 5 caps=pAsxLsXsxFc dirty=- wanted=pAsxXsxFxwb follows 0 size 0/0 mtime 2024-04-30T09:12:38.794146+0000 ctime 2024-04-30T09:12:38.794146+0000 change_attr 4 tws 1 xattrs(v=518 l=0)) ==== 268+0+0 (unknown 3706804660 0 0) 0x5617bfe61180 con 0x5617becec000
2024-04-30T09:12:38.870+0000 7f3c0dc00640 7 mds.0.locker handle_client_caps on 0x1000000a2bb tid 0 follows 0 op update flags 0x0
2024-04-30T09:12:38.870+0000 7f3c0dc00640 20 mds.0.4 get_session have 0x5617bec63900 client.4846 v1:172.21.15.107:0/3095293583 state open
2024-04-30T09:12:38.870+0000 7f3c0dc00640 10 mds.0.locker head inode [inode 0x1000000a2bb [2b4,head] /client.0/tmp/a auth v6 ap=3 DIRTYPARENT truncating(5 to 0) s=0 n(v0 rc2024-04-30T09:12:38.794146+0000 1=1+0) need_snapflush={2b2=4846,2b3=4846} (iauth excl) (ifile xlocksnap) (ixattr excl) cr={4846=0-4194304@2b1} caps={4846=pAsxLsXsxFc/pAsxLsXsxFcb/pAsxXsxFxwb@5},l=4846 | ptrwaiter=0 request=0 lock=0 caps=1 truncating=1 needsnapflush=1 dirtyparent=1 dirty=1 waiter=1 authpin=1 0x5617c319f180]
2024-04-30T09:12:38.870+0000 7f3c0dc00640 10 mds.0.locker follows 0 retains pAsxLsXsxFc dirty - on [inode 0x1000000a2bb [2b4,head] /client.0/tmp/a auth v6 ap=3 DIRTYPARENT truncating(5 to 0) s=0 n(v0 rc2024-04-30T09:12:38.794146+0000 1=1+0) need_snapflush={2b2=4846,2b3=4846} (iauth excl) (ifile xlocksnap) (ixattr excl) cr={4846=0-4194304@2b1} caps={4846=pAsxLsXsxFc/pAsxXsxFxwb@5},l=4846 | ptrwaiter=0 request=0 lock=0 caps=1 truncating=1 needsnapflush=1 dirtyparent=1 dirty=1 waiter=1 authpin=1 0x5617c319f180]
2024-04-30T09:12:38.870+0000 7f3c0dc00640 10 mds.0.cache.ino(0x1000000a2bb) auth_pin by 0x5617bdc834a0 on [inode 0x1000000a2bb [2b4,head] /client.0/tmp/a auth v6 ap=4 DIRTYPARENT truncating(5 to 0) s=0 n(v0 rc2024-04-30T09:12:38.794146+0000 1=1+0) need_snapflush={2b2=4846,2b3=4846} (iauth excl) (ifile xlocksnap) (ixattr excl) cr={4846=0-4194304@2b1} caps={4846=pAsxLsXsxFc/pAsxXsxFxwb@5},l=4846 | ptrwaiter=0 request=0 lock=0 caps=1 truncating=1 needsnapflush=1 dirtyparent=1 dirty=1 waiter=1 authpin=1 0x5617c319f180] now 4
2024-04-30T09:12:38.870+0000 7f3c0dc00640 15 mds.0.cache.dir(0x1000000a2ba) adjust_nested_auth_pins 1 on [dir 0x1000000a2ba /client.0/tmp/ [2,head] auth v=7 cv=0/0 ap=0+10 state=1610874881|complete f(v0 m2024-04-30T09:12:38.674148+0000 1=1+0) n(v0 rc2024-04-30T09:12:38.794146+0000 1=1+0) hs=1+1,ss=1+0 dirty=2 | child=1 dirty=1 authpin=0 0x5617c0cd6000] by 0x5617c319f180 count now 0/10
2024-04-30T09:12:38.870+0000 7f3c0dc00640 10 mds.0.locker _do_null_snapflush client.4846 on [inode 0x1000000a2bb [2b4,head] /client.0/tmp/a auth v6 ap=4 DIRTYPARENT truncating(5 to 0) s=0 n(v0 rc2024-04-30T09:12:38.794146+0000 1=1+0) need_snapflush={2b2=4846,2b3=4846} (iauth excl) (ifile xlocksnap) (ixattr excl) cr={4846=0-4194304@2b1} caps={4846=pAsxLsXsxFc/pAsxXsxFxwb@5},l=4846 | ptrwaiter=0 request=0 lock=0 caps=1 truncating=1 needsnapflush=1 dirtyparent=1 dirty=1 waiter=1 authpin=1 0x5617c319f180]
2024-04-30T09:12:38.870+0000 7f3c0dc00640 10 mds.0.locker doing async NULL snapflush on 2b2 from client.4846
2024-04-30T09:12:38.870+0000 7f3c0dc00640 10 mds.0.cache pick_inode_snap follows 2b1 on [inode 0x1000000a2bb [2b4,head] /client.0/tmp/a auth v6 ap=4 DIRTYPARENT truncating(5 to 0) s=0 n(v0 rc2024-04-30T09:12:38.794146+0000 1=1+0) need_snapflush={2b2=4846,2b3=4846} (iauth excl) (ifile xlocksnap) (ixattr excl) cr={4846=0-4194304@2b1} caps={4846=pAsxLsXsxFc/pAsxXsxFxwb@5},l=4846 | ptrwaiter=0 request=0 lock=0 caps=1 truncating=1 needsnapflush=1 dirtyparent=1 dirty=1 waiter=1 authpin=1 0x5617c319f180]
2024-04-30T09:12:38.870+0000 7f3c0dc00640 10 mds.0.cache pick_inode_snap found [inode 0x1000000a2bb [2b2,2b3] /client.0/tmp/a auth v2 ap=6 s=0 n(v0 1=1+0) (iauth snap->sync w=1) (ilink snap->sync w=1) (ifile snap->sync w=1) (ixattr snap->sync w=1) cr={4846=0-4194304@2b1} | request=0 lock=4 dirty=1 authpin=1 0x5617c788b700]
And then when the flush snap request came it will fail to update the capsnap for snap 1 and snap 2, please see not expecting flushsnap 2b2 and not expecting flushsnap 2b3:
2024-04-30T09:12:38.874+0000 7f3c0dc00640 1 -- [v2:172.21.15.107:6835/1150090015,v1:172.21.15.107:6837/1150090015] <== client.4846 v1:172.21.15.107:0/3095293583 424186 ==== client_caps(flushsnap ino 0x1000000a2bb 0 seq 0 tid 127531 caps=pAsxLsXsxFsxcrwb dirty=Fw wanted=- follows 1 size 5/0 mtime 2024-04-30T09:12:38.682148+0000 ctime 2024-04-30T09:12:38.682148+0000 change_attr 1) ==== 268+0+0 (unknown 2501511299 0 0) 0x5617cf357500 con 0x5617becec000
2024-04-30T09:12:38.874+0000 7f3c0dc00640 7 mds.0.locker handle_client_caps on 0x1000000a2bb tid 127531 follows 1 op flushsnap flags 0x0
2024-04-30T09:12:38.874+0000 7f3c0dc00640 20 mds.0.4 get_session have 0x5617bec63900 client.4846 v1:172.21.15.107:0/3095293583 state open
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.locker head inode [inode 0x1000000a2bb [2b4,head] /client.0/tmp/a auth v6 ap=1 DIRTYPARENT truncating(5 to 0) s=0 n(v0 rc2024-04-30T09:12:38.794146+0000 1=1+0) (iauth excl) (ifile excl) (ixattr excl) cr={4846=0-4194304@2b1} caps={4846=pAsxLsXsxFsxcrwb/pAsxXsxFxwb@6},l=4846 | ptrwaiter=0 request=0 lock=0 caps=1 truncating=1 needsnapflush=0 dirtyparent=1 dirty=1 waiter=0 authpin=1 0x5617c319f180]
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.cache.snaprealm(0x1000000a2ba seq 691 0x5617c030e900) get_snaps 2b2,2b3 (seq 2b3 cached_seq 2b3)
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.locker flushsnap follows 1 -> snap 2b2
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.cache pick_inode_snap follows 2b1 on [inode 0x1000000a2bb [2b4,head] /client.0/tmp/a auth v6 ap=1 DIRTYPARENT truncating(5 to 0) s=0 n(v0 rc2024-04-30T09:12:38.794146+0000 1=1+0) (iauth excl) (ifile excl) (ixattr excl) cr={4846=0-4194304@2b1} caps={4846=pAsxLsXsxFsxcrwb/pAsxXsxFxwb@6},l=4846 | ptrwaiter=0 request=0 lock=0 caps=1 truncating=1 needsnapflush=0 dirtyparent=1 dirty=1 waiter=0 authpin=1 0x5617c319f180]
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.cache pick_inode_snap found [inode 0x1000000a2bb [2b2,2b3] /client.0/tmp/a auth v2 pv10 ap=6 s=0 n(v0 1=1+0)->n(v0 1=1+0) (iauth snap->sync w=1) (ilink snap->sync w=1) (ifile snap->sync w=1) (ixattr snap->sync w=1) cr={4846=0-4194304@2b1} | ptrwaiter=2 request=0 lock=4 dirty=1 authpin=1 0x5617c788b700]
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.locker snapped inode [inode 0x1000000a2bb [2b2,2b3] /client.0/tmp/a auth v2 pv10 ap=6 s=0 n(v0 1=1+0)->n(v0 1=1+0) (iauth snap->sync w=1) (ilink snap->sync w=1) (ifile snap->sync w=1) (ixattr snap->sync w=1) cr={4846=0-4194304@2b1} | ptrwaiter=2 request=0 lock=4 dirty=1 authpin=1 0x5617c788b700]
2024-04-30T09:12:38.874+0000 7f3c0dc00640 7 mds.0.locker not expecting flushsnap 2b2 from client.4846 on [inode 0x1000000a2bb [2b2,2b3] /client.0/tmp/a auth v2 pv10 ap=6 s=0 n(v0 1=1+0)->n(v0 1=1+0) (iauth snap->sync w=1) (ilink snap->sync w=1) (ifile snap->sync w=1) (ixattr snap->sync w=1) cr={4846=0-4194304@2b1} | ptrwaiter=2 request=0 lock=4 dirty=1 authpin=1 0x5617c788b700]
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.4 send_message_client_counted client.4846 seq 253985 client_caps(flushsnap_ack ino 0x1000000a2bb 0 seq 0 tid 127531 caps=- dirty=Fw wanted=- follows 1 size 0/0 mtime 0.000000 ctime 0.000000 change_attr 0)
2024-04-30T09:12:38.874+0000 7f3c0dc00640 1 -- [v2:172.21.15.107:6835/1150090015,v1:172.21.15.107:6837/1150090015] --> v1:172.21.15.107:0/3095293583 -- client_caps(flushsnap_ack ino 0x1000000a2bb 0 seq 0 tid 127531 caps=- dirty=Fw wanted=- follows 1 size 0/0 mtime 0.000000 ctime 0.000000 change_attr 0) -- 0x5617bfe61180 con 0x5617becec000
2024-04-30T09:12:38.874+0000 7f3c0dc00640 1 -- [v2:172.21.15.107:6835/1150090015,v1:172.21.15.107:6837/1150090015] <== client.4846 v1:172.21.15.107:0/3095293583 424187 ==== client_caps(flushsnap ino 0x1000000a2bb 0 seq 0 tid 127532 caps=pAsxLsXsxFsxcrwb dirty=AxFw wanted=- follows 2b2 size 5/0 mtime 2024-04-30T09:12:38.682148+0000 ctime 2024-04-30T09:12:38.786146+0000 change_attr 2) ==== 268+0+0 (unknown 2984913037 0 0) 0x5617c605ee00 con 0x5617becec000
2024-04-30T09:12:38.874+0000 7f3c0dc00640 7 mds.0.locker handle_client_caps on 0x1000000a2bb tid 127532 follows 2b2 op flushsnap flags 0x0
2024-04-30T09:12:38.874+0000 7f3c0dc00640 20 mds.0.4 get_session have 0x5617bec63900 client.4846 v1:172.21.15.107:0/3095293583 state open
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.locker head inode [inode 0x1000000a2bb [2b4,head] /client.0/tmp/a auth v6 ap=1 DIRTYPARENT truncating(5 to 0) s=0 n(v0 rc2024-04-30T09:12:38.794146+0000 1=1+0) (iauth excl) (ifile excl) (ixattr excl) cr={4846=0-4194304@2b1} caps={4846=pAsxLsXsxFsxcrwb/pAsxXsxFxwb@6},l=4846 | ptrwaiter=0 request=0 lock=0 caps=1 truncating=1 needsnapflush=0 dirtyparent=1 dirty=1 waiter=0 authpin=1 0x5617c319f180]
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.cache.snaprealm(0x1000000a2ba seq 691 0x5617c030e900) get_snaps 2b2,2b3 (seq 2b3 cached_seq 2b3)
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.locker flushsnap follows 2b2 -> snap 2b3
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.cache pick_inode_snap follows 2b2 on [inode 0x1000000a2bb [2b4,head] /client.0/tmp/a auth v6 ap=1 DIRTYPARENT truncating(5 to 0) s=0 n(v0 rc2024-04-30T09:12:38.794146+0000 1=1+0) (iauth excl) (ifile excl) (ixattr excl) cr={4846=0-4194304@2b1} caps={4846=pAsxLsXsxFsxcrwb/pAsxXsxFxwb@6},l=4846 | ptrwaiter=0 request=0 lock=0 caps=1 truncating=1 needsnapflush=0 dirtyparent=1 dirty=1 waiter=0 authpin=1 0x5617c319f180]
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.cache pick_inode_snap found [inode 0x1000000a2bb [2b2,2b3] /client.0/tmp/a auth v2 pv10 ap=6 s=0 n(v0 1=1+0)->n(v0 1=1+0) (iauth snap->sync w=1) (ilink snap->sync w=1) (ifile snap->sync w=1) (ixattr snap->sync w=1) cr={4846=0-4194304@2b1} | ptrwaiter=2 request=0 lock=4 dirty=1 authpin=1 0x5617c788b700]
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.locker snapped inode [inode 0x1000000a2bb [2b2,2b3] /client.0/tmp/a auth v2 pv10 ap=6 s=0 n(v0 1=1+0)->n(v0 1=1+0) (iauth snap->sync w=1) (ilink snap->sync w=1) (ifile snap->sync w=1) (ixattr snap->sync w=1) cr={4846=0-4194304@2b1} | ptrwaiter=2 request=0 lock=4 dirty=1 authpin=1 0x5617c788b700]
2024-04-30T09:12:38.874+0000 7f3c0dc00640 7 mds.0.locker not expecting flushsnap 2b3 from client.4846 on [inode 0x1000000a2bb [2b2,2b3] /client.0/tmp/a auth v2 pv10 ap=6 s=0 n(v0 1=1+0)->n(v0 1=1+0) (iauth snap->sync w=1) (ilink snap->sync w=1) (ifile snap->sync w=1) (ixattr snap->sync w=1) cr={4846=0-4194304@2b1} | ptrwaiter=2 request=0 lock=4 dirty=1 authpin=1 0x5617c788b700]
2024-04-30T09:12:38.874+0000 7f3c0dc00640 10 mds.0.4 send_message_client_counted client.4846 seq 253986 client_caps(flushsnap_ack ino 0x1000000a2bb 0 seq 0 tid 127532 caps=- dirty=AxFw wanted=- follows 2b2 size 0/0 mtime 0.000000 ctime 0.000000 change_attr 0)
2024-04-30T09:12:38.874+0000 7f3c0dc00640 1 -- [v2:172.21.15.107:6835/1150090015,v1:172.21.15.107:6837/1150090015] --> v1:172.21.15.107:0/3095293583 -- client_caps(flushsnap_ack ino 0x1000000a2bb 0 seq 0 tid 127532 caps=- dirty=AxFw wanted=- follows 2b2 size 0/0 mtime 0.000000 ctime 0.000000 change_attr 0) -- 0x5617cf357500 con 0x5617becec000
I still am going through the kclient code to check why could this happen.
Updated by Venky Shankar 11 days ago
Xiubo Li wrote in #note-3:
Venky Shankar wrote in #note-2:
Xiubo, this is using the distro kernel. Maybe the relevant kclient fixes haven't yet landed in the distro kernel?
No, this is using the k-testing kernel. And a different issue with https://tracker.ceph.com/issues/59343.
That's a bit confusing since the yaml has:
kernel: client: branch: testing kdb: True sha1: distro
Though the sha1 is distro, its the branch: testing that's making the testing kernel install, correct?
Updated by Xiubo Li 11 days ago
Venky Shankar wrote in #note-4:
Xiubo Li wrote in #note-3:
Venky Shankar wrote in #note-2:
Xiubo, this is using the distro kernel. Maybe the relevant kclient fixes haven't yet landed in the distro kernel?
No, this is using the k-testing kernel. And a different issue with https://tracker.ceph.com/issues/59343.
That's a bit confusing since the yaml has:
[...]
Though the sha1 is
distro, its thebranch: testingthat's making the testing kernel install, correct?
Yeah, correct. Please see:
2024-04-30T08:45:23.569 INFO:teuthology.run_tasks:Running task kernel...
2024-04-30T08:45:23.586 INFO:teuthology.task.kernel:normalize config orig: {'client': {'branch': 'testing'}, 'kdb': True, 'sha1': 'distro'}
2024-04-30T08:45:23.586 INFO:teuthology.task.kernel:normalize config final: {'client.0': {'branch': 'testing'}}
2024-04-30T08:45:23.586 INFO:teuthology.task.kernel:config {'client.0': {'branch': 'testing'}}, timeout 300
2024-04-30T08:45:23.586 DEBUG:teuthology.orchestra.run.smithi107:> test -f /run/.containerenv -o -f /.dockerenv
2024-04-30T08:45:23.591 DEBUG:teuthology.orchestra.run:got remote process result: 1
2024-04-30T08:45:23.591 DEBUG:teuthology.packaging:Querying https://shaman.ceph.com/api/search?status=ready&project=kernel&flavor=default&distros=ubuntu%2F22.04%2Fx86_64&ref=testing
2024-04-30T08:45:23.831 DEBUG:teuthology.task.kernel:sha1 for client.0 is 806ec36b21129f113ce356c007dd59694d340b37
2024-04-30T08:45:23.832 INFO:teuthology.task.kernel:Checking kernel version of client.0, want "806ec36b21129f113ce356c007dd59694d340b37"...
2024-04-30T08:45:23.832 DEBUG:teuthology.orchestra.run.smithi107:> uname -r
2024-04-30T08:45:23.837 INFO:teuthology.orchestra.run.smithi107.stdout:5.15.0-56-generic
2024-04-30T08:45:23.837 DEBUG:teuthology.task.kernel:current kernel version is 5.15.0-56-generic vs 806ec36b21129f113ce356c007dd59694d340b37
2024-04-30T08:45:23.838 DEBUG:teuthology.task.kernel:failed to parse current kernel version
2024-04-30T08:45:23.838 INFO:teuthology.task.kernel:Installing linux-firmware on client.0...
But I still haven't got exactly where is setting the sha1: distro, any idea ?
Updated by Xiubo Li 10 days ago
- Status changed from New to Fix Under Review
The ceph patch link: https://patchwork.kernel.org/project/ceph-devel/list/?series=851489&archive=both
Actions