Actions
Bug #14557
closedBug #54460: snaptest-multiple-capsnaps.sh test failure
Bug #59343: qa: fs/snaps/snaptest-multiple-capsnaps.sh failed
snaps: failed snaptest-multiple-capsnaps.sh
Status:
Duplicate
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
% Done:
0%
Source:
Development
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(FS):
Labels (FS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
This is on a testing branch, but it's about to get merged to master.
http://pulpito.ceph.com/gregf-2016-01-26_15:35:20-fs-greg-fs-testing-126---basic-mira/44959/
2016-01-26T19:58:40.416 INFO:tasks.workunit:Running workunit fs/snaps/snaptest-multiple-capsnaps.sh... 2016-01-26T19:58:40.417 INFO:teuthology.orchestra.run.mira069:Running (workunit test fs/snaps/snaptest-multiple-capsnaps.sh): '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=0ec5adcdcfce5ef675be0fa88c3806dd27a8deb7 TESTDIR="/home/ubuntu/cephtest" CEPH_ID="0" PATH=$PAT H:/usr/sbin adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 3h /home/ubuntu/cephtest/workunit.client.0/fs/snaps/snaptest-multiple-capsnaps.sh' 2016-01-26T19:58:40.462 INFO:tasks.workunit.client.0.mira069.stderr:+ set -e 2016-01-26T19:58:40.462 INFO:tasks.workunit.client.0.mira069.stderr:+ ceph mds set allow_new_snaps true --yes-i-really-mean-it 2016-01-26T19:58:41.782 INFO:tasks.workunit.client.0.mira069.stderr:enabled new snapshots 2016-01-26T19:58:41.801 INFO:tasks.workunit.client.0.mira069.stderr:+ echo asdf 2016-01-26T19:58:41.802 INFO:tasks.workunit.client.0.mira069.stderr:+ mkdir .snap/1 2016-01-26T19:58:41.820 INFO:tasks.workunit.client.0.mira069.stderr:+ chmod 777 a 2016-01-26T19:58:41.825 INFO:tasks.workunit.client.0.mira069.stderr:+ mkdir .snap/2 2016-01-26T19:58:41.862 INFO:tasks.workunit.client.0.mira069.stderr:+ echo qwer 2016-01-26T19:58:41.869 INFO:tasks.workunit.client.0.mira069.stderr:+ mkdir .snap/3 2016-01-26T19:58:41.891 INFO:tasks.workunit.client.0.mira069.stderr:+ chmod 666 a 2016-01-26T19:58:41.893 INFO:tasks.workunit.client.0.mira069.stderr:+ mkdir .snap/4 2016-01-26T19:58:41.926 INFO:tasks.workunit.client.0.mira069.stderr:+ echo zxcv 2016-01-26T19:58:41.934 INFO:tasks.workunit.client.0.mira069.stderr:+ mkdir .snap/5 2016-01-26T19:58:41.972 INFO:tasks.workunit.client.0.mira069.stderr:+ ls -al .snap/1/a .snap/2/a .snap/3/a .snap/4/a .snap/5/a 2016-01-26T19:58:42.003 INFO:tasks.workunit.client.0.mira069.stdout:-rw-rw-r-- 1 ubuntu ubuntu 0 Jan 27 03:58 .snap/1/a 2016-01-26T19:58:42.003 INFO:tasks.workunit.client.0.mira069.stdout:-rwxrwxrwx 1 ubuntu ubuntu 5 Jan 27 03:58 .snap/2/a 2016-01-26T19:58:42.003 INFO:tasks.workunit.client.0.mira069.stdout:-rwxrwxrwx 1 ubuntu ubuntu 5 Jan 27 03:58 .snap/3/a 2016-01-26T19:58:42.003 INFO:tasks.workunit.client.0.mira069.stdout:-rw-rw-rw- 1 ubuntu ubuntu 5 Jan 27 03:58 .snap/4/a 2016-01-26T19:58:42.004 INFO:tasks.workunit.client.0.mira069.stdout:-rw-rw-rw- 1 ubuntu ubuntu 5 Jan 27 03:58 .snap/5/a 2016-01-26T19:58:42.004 INFO:tasks.workunit.client.0.mira069.stderr:+ grep asdf .snap/1/a 2016-01-26T19:58:42.008 INFO:tasks.workunit:Stopping ['fs/snaps/snaptest-multiple-capsnaps.sh'] on client.0... 2016-01-26T19:58:42.008 INFO:teuthology.orchestra.run.mira069:Running: 'rm -rf -- /home/ubuntu/cephtest/workunits.list.client.0 /home/ubuntu/cephtest/workunit.client.0 /home/ubuntu/cephtest/clone'
Updated by Zheng Yan about 8 years ago
- Status changed from New to Duplicate
2016-01-26T19:58:40.462 INFO:tasks.workunit.client.0.mira069.stderr:+ ceph mds set allow_new_snaps true --yes-i-really-mean-it 2016-01-26T19:58:41.782 INFO:tasks.workunit.client.0.mira069.stderr:enabled new snapshots 2016-01-26T19:58:41.801 INFO:tasks.workunit.client.0.mira069.stderr:+ echo asdf 2016-01-26T19:58:41.802 INFO:tasks.workunit.client.0.mira069.stderr:+ mkdir .snap/1 2016-01-26T19:58:41.820 INFO:tasks.workunit.client.0.mira069.stderr:+ chmod 777 a 2016-01-26T19:58:41.825 INFO:tasks.workunit.client.0.mira069.stderr:+ mkdir .snap/2 2016-01-26T19:58:41.862 INFO:tasks.workunit.client.0.mira069.stderr:+ echo qwer 2016-01-26T19:58:41.869 INFO:tasks.workunit.client.0.mira069.stderr:+ mkdir .snap/3 2016-01-26T19:58:41.891 INFO:tasks.workunit.client.0.mira069.stderr:+ chmod 666 a 2016-01-26T19:58:41.893 INFO:tasks.workunit.client.0.mira069.stderr:+ mkdir .snap/4 2016-01-26T19:58:41.926 INFO:tasks.workunit.client.0.mira069.stderr:+ echo zxcv 2016-01-26T19:58:41.934 INFO:tasks.workunit.client.0.mira069.stderr:+ mkdir .snap/5 2016-01-26T19:58:41.972 INFO:tasks.workunit.client.0.mira069.stderr:+ ls -al .snap/1/a .snap/2/a .snap/3/a .snap/4/a .snap/5/a 2016-01-26T19:58:42.003 INFO:tasks.workunit.client.0.mira069.stdout:-rw-rw-r-- 1 ubuntu ubuntu 0 Jan 27 03:58 .snap/1/a 2016-01-26T19:58:42.003 INFO:tasks.workunit.client.0.mira069.stdout:-rwxrwxrwx 1 ubuntu ubuntu 5 Jan 27 03:58 .snap/2/a 2016-01-26T19:58:42.003 INFO:tasks.workunit.client.0.mira069.stdout:-rwxrwxrwx 1 ubuntu ubuntu 5 Jan 27 03:58 .snap/3/a 2016-01-26T19:58:42.003 INFO:tasks.workunit.client.0.mira069.stdout:-rw-rw-rw- 1 ubuntu ubuntu 5 Jan 27 03:58 .snap/4/a 2016-01-26T19:58:42.004 INFO:tasks.workunit.client.0.mira069.stdout:-rw-rw-rw- 1 ubuntu ubuntu 5 Jan 27 03:58 .snap/5/a </prev> size of .snap/1/a is 0, this should be dup of #10436
Updated by Xiubo Li 12 months ago
vshankar-2023-04-06_04:14:11-fs-wip-vshankar-testing-20230330.105356-testing-default-smithi/7233705/teuthology.log
A recent issue the same with this.
The make snapshot reqeust finished successfully:
2023-04-06T05:25:47.852+0000 7fe193fff700 20 client.4902 encode_inode_release enter(in:0x100000017b1.snapdir(faked_ino=0 nref=8 ll_ref=72 cap_refs={} open={} mode=40775 size=0/0 nlink=1 btime=2023-04-06T05:11:44.751169+0000 mtime=2023-04-06T05:25:41.236814+0000 ctime=2023-04-06T05:25:41.236814+0000 change_attr=70 caps=- 0x7fe1b91132e0), req:0x7fe1603f0c70 mds:0, drop:Fs, unless:Fx, force:1)
2023-04-06T05:25:47.852+0000 7fe193fff700 20 client.4902 send_request set sent_stamp to 2023-04-06T05:25:47.854275+0000
2023-04-06T05:25:47.852+0000 7fe193fff700 10 client.4902 send_request client_request(unknown.0:92406 mksnap #0x100000017b1//v0.72 2023-04-06T05:25:47.854169+0000 caller_uid=1000, caller_gid=1267{6,27,108,1267,10102,}) v6 to mds.0
2023-04-06T05:25:47.852+0000 7fe193fff700 1 -- 192.168.0.1:0/2332599002 --> [v2:172.21.15.98:6836/1818983428,v1:172.21.15.98:6837/1818983428] -- client_request(unknown.0:92406 mksnap #0x100000017b1//v0.72 2023-04-06T05:25:47.854169+0000 caller_uid=1000, caller_gid=1267{6,27,108,1267,10102,}) v6 -- 0x7fe1601eb340 con 0x55ca2fbedcf0
...
2023-04-06T05:25:47.916+0000 7fe1cd7fa700 1 -- 192.168.0.1:0/2332599002 <== mds.0 v2:172.21.15.98:6836/1818983428 303661 ==== client_reply(???:92406 = 0 (0) Success safe) v1 ==== 357+0+0 (crc 0 0 0) 0x7fe1d0474ca0 con 0x55ca2fbedcf0
It failed to lookup the snapshot v0.72 0x240:
2023-04-06T05:25:47.846+0000 7ff009dfa700 20 mds.0.4 get_session have 0x55f1112a4d00 client.4902 192.168.0.1:0/2332599002 state open
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.server oldest_client_tid=92401
2023-04-06T05:25:47.846+0000 7ff009dfa700 7 mds.0.cache request_start request(client.4902:92404 nref=2 cr=0x55f120dac000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 7 mds.0.server dispatch_client_request client_request(client.4902:92404 lookupsnap #0x100000017b1//v0.72 2023-04-06T05:25:47.850943+0000 caller_uid=1000, caller_gid=1267{6,27,108,1267,10102,}) v6
2023-04-06T05:25:47.846+0000 7ff009dfa700 10 mds.0.server rdlock_path_pin_ref request(client.4902:92404 nref=2 cr=0x55f120dac000) #0x100000017b1//v0.72
2023-04-06T05:25:47.846+0000 7ff009dfa700 7 mds.0.cache traverse: opening base ino 0x100000017b1 snap head
2023-04-06T05:25:47.846+0000 7ff009dfa700 12 mds.0.cache traverse: path seg depth 0 '' snapid head
2023-04-06T05:25:47.846+0000 7ff009dfa700 10 mds.0.cache traverse: snapdir
2023-04-06T05:25:47.846+0000 7ff009dfa700 12 mds.0.cache traverse: path seg depth 1 'v0.72' snapid snapdir
2023-04-06T05:25:47.846+0000 7ff009dfa700 10 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) resolve_snapname 'v0.72' in [0,head]
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(1fa 0x100000017b1 'v0.1' 2023-04-06T05:19:31.865348+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(1fb 0x100000017b1 'v0.2' 2023-04-06T05:19:36.821286+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(1fc 0x100000017b1 'v0.3' 2023-04-06T05:19:41.937115+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(1fd 0x100000017b1 'v0.4' 2023-04-06T05:19:46.788596+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(1fe 0x100000017b1 'v0.5' 2023-04-06T05:19:51.767297+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(1ff 0x100000017b1 'v0.6' 2023-04-06T05:19:56.123211+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(200 0x100000017b1 'v0.7' 2023-04-06T05:20:00.630289+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(201 0x100000017b1 'v0.8' 2023-04-06T05:20:05.261090+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(202 0x100000017b1 'v0.9' 2023-04-06T05:20:09.804902+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(203 0x100000017b1 'v0.10' 2023-04-06T05:20:14.462021+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(204 0x100000017b1 'v0.11' 2023-04-06T05:20:17.787009+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(205 0x100000017b1 'v0.12' 2023-04-06T05:20:21.306663+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(206 0x100000017b1 'v0.13' 2023-04-06T05:20:25.164480+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(207 0x100000017b1 'v0.14' 2023-04-06T05:20:29.052699+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(208 0x100000017b1 'v0.15' 2023-04-06T05:20:33.206122+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(209 0x100000017b1 'v0.16' 2023-04-06T05:20:37.023396+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(20a 0x100000017b1 'v0.17' 2023-04-06T05:20:41.420716+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(20b 0x100000017b1 'v0.18' 2023-04-06T05:20:50.820581+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(20c 0x100000017b1 'v0.19' 2023-04-06T05:20:54.801024+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(20d 0x100000017b1 'v0.20' 2023-04-06T05:20:58.947936+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(20e 0x100000017b1 'v0.21' 2023-04-06T05:21:05.615735+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(20f 0x100000017b1 'v0.22' 2023-04-06T05:21:09.619036+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(210 0x100000017b1 'v0.23' 2023-04-06T05:21:13.134111+0000)
...
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(234 0x100000017b1 'v0.60' 2023-04-06T05:24:30.844013+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(235 0x100000017b1 'v0.61' 2023-04-06T05:24:39.200715+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(236 0x100000017b1 'v0.62' 2023-04-06T05:24:44.133541+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(237 0x100000017b1 'v0.63' 2023-04-06T05:24:49.635201+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(238 0x100000017b1 'v0.64' 2023-04-06T05:24:55.114972+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(239 0x100000017b1 'v0.65' 2023-04-06T05:25:01.486373+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(23a 0x100000017b1 'v0.66' 2023-04-06T05:25:06.967497+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(23b 0x100000017b1 'v0.67' 2023-04-06T05:25:14.944894+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(23c 0x100000017b1 'v0.68' 2023-04-06T05:25:22.066591+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(23d 0x100000017b1 'v0.69' 2023-04-06T05:25:28.490131+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(23e 0x100000017b1 'v0.70' 2023-04-06T05:25:32.994396+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 15 mds.0.cache.snaprealm(0x100000017b1 seq 575 0x55f112179b00) ? snap(23f 0x100000017b1 'v0.71' 2023-04-06T05:25:41.236814+0000)
2023-04-06T05:25:47.846+0000 7ff009dfa700 10 mds.0.cache.snaprealm(0x1 seq 1 0x55f1110cad80) resolve_snapname 'v0.72' in [1fa,head]
2023-04-06T05:25:47.846+0000 7ff009dfa700 10 mds.0.cache traverse: snap v0.72 -> 0
2023-04-06T05:25:47.846+0000 7ff009dfa700 10 mds.0.server FAIL on error -2
While the snapshot v0.72 0x240 was popped from the project to snaprealm was at 2023-04-06T05:25:47.874+0000, just after the lookup reqeust:
2023-04-06T05:25:47.874+0000 7ff003dee700 10 MDSIOContextBase::complete: 19C_MDS_mksnap_finish
2023-04-06T05:25:47.874+0000 7ff003dee700 10 MDSContext::complete: 19C_MDS_mksnap_finish
2023-04-06T05:25:47.874+0000 7ff003dee700 10 mds.0.server _mksnap_finish request(client.4902:92406 nref=3 cr=0x55f11d824000) snap(240 0x100000017b1 'v0.72' 2023-04-06T05:25:47.854169+0000)
2023-04-06T05:25:47.874+0000 7ff003dee700 15 mds.0.cache.ino(0x1) pop_and_dirty_projected_inode v707
2023-04-06T05:25:47.874+0000 7ff003dee700 10 mds.0.cache.ino(0x1) mark_dirty [inode 0x1 [...240,head] / auth v707 ap=1 snaprealm=0x55f1110cad80 f(v0 m2023-04-06T05:08:32.048280+0000 1=0+1) n(v146 rc2023-04-06T05:25:47.854169+0000 b753490708 rs71 2420=2188+232)/n(v0 rc2023-04-06T05:07:56.696766+0000 1=0+1) old_inodes=108 (isnap sync r=1) (inest lock w=1 dirty) (iversion lock w=1 last_client=4902) caps={4902=pAsLsXsFs/-@5} | dirtyscattered=1 request=0 lock=3 dirfrag=1 caps=1 dirtyparent=0 dirty=1 authpin=1 0x55f1103ac680]
2023-04-06T05:25:47.874+0000 7ff003dee700 15 mds.0.cache.ino(0x10000000000) pop_and_dirty_projected_inode v1695
2023-04-06T05:25:47.874+0000 7ff003dee700 10 mds.0.cache.ino(0x10000000000) mark_dirty [inode 0x10000000000 [...240,head] /client.0/ auth v1695 ap=1 f(v0 m2023-04-06T05:11:44.712278+0000 1=0+1) n(v144 rc2023-04-06T05:25:47.854169+0000 b753490708 rs71 2419=2188+231) old_inodes=119 (isnap sync r=1) (inest lock w=1 dirty) (ifile excl) (iversion lock w=1 last_client=4902) caps={4902=pAsLsXsFsx/-@37},l=4902 | ptrwaiter=0 dirtyscattered=1 request=0 lock=3 dirfrag=1 caps=1 dirtyrstat=0 dirtyparent=0 dirty=1 authpin=1 0x55f1112d5600]
2023-04-06T05:25:47.874+0000 7ff003dee700 10 mds.0.cache.den(0x1 client.0) mark_dirty [dentry #0x1/client.0 [2,head] auth (dversion lock) pv=1695 v=1693 ino=0x10000000000 state=1610612736 | request=0 lock=0 inodepin=1 dirty=1 authpin=0 clientlease=0 0x55f1110f0000]
2023-04-06T05:25:47.874+0000 7ff003dee700 10 mds.0.cache.dir(0x1) _mark_dirty (already dirty) [dir 0x1 / [2,head] auth pv=1696 v=1694 cv=1/1 REP dir_auth=0 ap=1+1 state=1610874881|complete f(v0 m2023-04-06T05:08:32.048280+0000 1=0+1)->f(v0 m2023-04-06T05:08:32.048280+0000 1=0+1) n(v146 rc2023-04-06T05:25:46.802264+0000 b753490708 rs70 2419=2188+231)->n(v146 rc2023-04-06T05:25:47.854169+0000 b753490708 rs71 2419=2188+231) hs=1+0,ss=0+0 dirty=1 | child=1 subtree=1 dirty=1 authpin=1 0x55f110386d00] version 1694
2023-04-06T05:25:47.874+0000 7ff003dee700 15 mds.0.cache.ino(0x100000017b1) pop_and_dirty_projected_inode v4054
2023-04-06T05:25:47.874+0000 7ff003dee700 10 mds.0.cache.ino(0x100000017b1) pop_projected_snaprealm 0x55f110333930 seq 240
2023-04-06T05:25:47.874+0000 7ff003dee700 10 mds.0.cache.ino(0x100000017b1) realm snaprealm(0x100000017b1 seq 240 lc 240 cr 240 cps 1fa snaps={1fa=snap(1fa 0x100000017b1 'v0.1' 2023-04-06T05:19:31.865348+0000),1fb=snap(1fb 0x100000017b1 'v0.2' 2023-04-06T05:19:36.821286+0000),1fc=snap(1fc 0x100000017b1 'v0.3' 2023-04-06T05:19:41.937115+0000),1fd=snap(1fd 0x100000017b1 'v0.4' 2023-04-06T05:19:46.788596+0000),1fe=snap(1fe 0x100000017b1 'v0.5' 2023-04-06T05:19:51.767297+0000),1ff=snap(1ff 0x100000017b1 'v0.6' 2023-04-06T05:19:56.123211+0000),200=snap(200 0x100000017b1 'v0.7' 2023-04-06T05:20:00.630289+0000),201=snap(201 0x100000017b1 'v0.8' 2023-04-06T05:20:05.261090+0000),202=snap(202 0x100000017b1 'v0.9' 2023-04-06T05:20:09.804902+0000),203=snap(203 0x100000017b1 'v0.10' 2023-04-06T05:20:14.462021+0000),204=snap(204 0x100000017b1 'v0.11' 2023-04-06T05:20:17.787009+0000),205=snap(205 0x100000017b1 'v0.12' 2023-04-06T05:20:21.306663+0000),206=snap(206 0x100000017b1 'v0.13' 2023-04-06T05:20:25.164480+0000),207=snap(207 0x100000017b1 'v0.14' 2023-04-06T05:20:29.052699+0000),208=snap(208 0x100000017b1 'v0.15' 2023-04-06T05:20:33.206122+0000),209=snap(209 0x100000017b1 'v0.16' 2023-04-06T05:20:37.023396+0000),20a=snap(20a 0x100000017b1 'v0.17' 2023-04-06T05:20:41.420716+0000),20b=snap(20b 0x100000017b1 'v0.18' 2023-04-06T05:20:50.820581+0000),20c=snap(20c 0x100000017b1 'v0.19' 2023-04-06T05:20:54.801024+0000),20d=snap(20d 0x100000017b1 'v0.20' 2023-04-06T05:20:58.947936+0000),20e=snap(20e 0x100000017b1 'v0.21' 2023-04-06T05:21:05.615735+0000),20f=snap(20f 0x100000017b1 'v0.22' 2023-04-06T05:21:09.619036+0000),210=snap(210 0x100000017b1 'v0.23' 2023-04-06T05:21:13.134111+0000),211=snap(211 0x100000017b1 'v0.24' 2023-04-06T05:21:17.056743+0000),212=snap(212 0x100000017b1 'v0.25' 2023-04-06T05:21:24.387893+0000),213=snap(213 0x100000017b1 'v0.26' 2023-04-06T05:21:29.220346+0000),214=snap(214 0x100000017b1 'v0.27' 2023-04-06T05:21:33.902121+0000),215=snap(215 0x100000017b1 'v0.28' 2023-04-06T05:21:38.616219+0000),216=snap(216 0x100000017b1 'v0.29' 2023-04-06T05:21:42.680876+0000),217=snap(217 0x100000017b1 'v0.30' 2023-04-06T05:21:47.576817+0000),218=snap(218 0x100000017b1 'v0.31' 2023-04-06T05:21:54.251767+0000),219=snap(219 0x100000017b1 'v0.32' 2023-04-06T05:21:58.888636+0000),21a=snap(21a 0x100000017b1 'v0.33' 2023-04-06T05:22:03.226317+0000),21b=snap(21b 0x100000017b1 'v0.34' 2023-04-06T05:22:06.615089+0000),21c=snap(21c 0x100000017b1 'v0.35' 2023-04-06T05:22:11.916365+0000),21d=snap(21d 0x100000017b1 'v0.36' 2023-04-06T05:22:17.139833+0000),21e=snap(21e 0x100000017b1 'v0.37' 2023-04-06T05:22:22.034117+0000),21f=snap(21f 0x100000017b1 'v0.38' 2023-04-06T05:22:26.613668+0000),220=snap(220 0x100000017b1 'v0.39' 2023-04-06T05:22:32.469763+0000),221=snap(221 0x100000017b1 'v0.40' 2023-04-06T05:22:37.664040+0000),222=snap(222 0x100000017b1 'v0.41' 2023-04-06T05:22:41.665634+0000),223=snap(223 0x100000017b1 'v0.42' 2023-04-06T05:22:46.722956+0000),224=snap(224 0x100000017b1 'v0.43' 2023-04-06T05:22:50.956750+0000),225=snap(225 0x100000017b1 'v0.44' 2023-04-06T05:22:55.612783+0000),226=snap(226 0x100000017b1 'v0.45' 2023-04-06T05:23:00.302410+0000),227=snap(227 0x100000017b1 'v0.46' 2023-04-06T05:23:06.341143+0000),228=snap(228 0x100000017b1 'v0.47' 2023-04-06T05:23:11.764293+0000),229=snap(229 0x100000017b1 'v0.49' 2023-04-06T05:23:19.864532+0000),22a=snap(22a 0x100000017b1 'v0.50' 2023-04-06T05:23:24.828613+0000),22b=snap(22b 0x100000017b1 'v0.51' 2023-04-06T05:23:29.094309+0000),22c=snap(22c 0x100000017b1 'v0.52' 2023-04-06T05:23:34.470628+0000),22d=snap(22d 0x100000017b1 'v0.53' 2023-04-06T05:23:42.127857+0000),22e=snap(22e 0x100000017b1 'v0.54' 2023-04-06T05:23:47.997181+0000),22f=snap(22f 0x100000017b1 'v0.55' 2023-04-06T05:23:57.161336+0000),230=snap(230 0x100000017b1 'v0.56' 2023-04-06T05:24:03.861614+0000),231=snap(231 0x100000017b1 'v0.57' 2023-04-06T05:24:11.182613+0000),232=snap(232 0x100000017b1 'v0.58' 2023-04-06T05:24:18.304587+0000),233=snap(233 0x100000017b1 'v0.59' 2023-04-06T05:24:24.265157+0000),234=snap(234 0x100000017b1 'v0.60' 2023-04-06T05:24:30.844013+0000),235=snap(235 0x100000017b1 'v0.61' 2023-04-06T05:24:39.200715+0000),236=snap(236 0x100000017b1 'v0.62' 2023-04-06T05:24:44.133541+0000),237=snap(237 0x100000017b1 'v0.63' 2023-04-06T05:24:49.635201+0000),238=snap(238 0x100000017b1 'v0.64' 2023-04-06T05:24:55.114972+0000),239=snap(239 0x100000017b1 'v0.65' 2023-04-06T05:25:01.486373+0000),23a=snap(23a 0x100000017b1 'v0.66' 2023-04-06T05:25:06.967497+0000),23b=snap(23b 0x100000017b1 'v0.67' 2023-04-06T05:25:14.944894+0000),23c=snap(23c 0x100000017b1 'v0.68' 2023-04-06T05:25:22.066591+0000),23d=snap(23d 0x100000017b1 'v0.69' 2023-04-06T05:25:28.490131+0000),23e=snap(23e 0x100000017b1 'v0.70' 2023-04-06T05:25:32.994396+0000),23f=snap(23f 0x100000017b1 'v0.71' 2023-04-06T05:25:41.236814+0000),240=snap(240 0x100000017b1 'v0.72' 2023-04-06T05:25:47.854169+0000)} last_modified 2023-04-06T05:25:47.854169+0000 change_attr 71 0x55f112179b00) parent snaprealm(0x1 seq 1 lc 0 cr 0 cps 1 snaps={} last_modified 2023-04-06T05:07:56.696766+0000 change_attr 0 0x55f1110cad80)
That means the snapshot v0.72 0x240 was still in the projected cache, not in the snaprealm yet.
Updated by Xiubo Li 12 months ago
Xiubo Li wrote:
vshankar-2023-04-06_04:14:11-fs-wip-vshankar-testing-20230330.105356-testing-default-smithi/7233705/teuthology.log
A recent issue the same with this.
The make snapshot reqeust finished successfully:
[...]
It failed to lookup the snapshot v0.72 0x240:
[...]
While the snapshot v0.72 0x240 was popped from the project to snaprealm was at 2023-04-06T05:25:47.874+0000, just after the lookup reqeust:
[...]
That means the snapshot v0.72 0x240 was still in the projected cache, not in the snaprealm yet.
Okay, the above analsys is incorrect, that's normal before mksnap to do a lookup. So please ignore this.
Actions