Actions
Bug #65614
openclient: resends request to same MDS it just received a forward from if it does not have an open session with the target
Status:
Pending Backport
Priority:
High
Assignee:
Category:
Correctness/Safety
Target version:
% Done:
0%
Source:
Q/A
Tags:
backport_processed
Backport:
squid,reef
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(FS):
Client
Labels (FS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
2024-04-21T03:58:00.663+0000 7f48c60ef700 8 client.15615 _mkdir(0x1 scheduled-2024-04-21-03_58_00_UTC, 0755, uid 0, gid 0)
2024-04-21T03:58:00.663+0000 7f48c60ef700 20 client.15615 get_or_create 0x1.snapdir(faked_ino=0 nref=4 ll_ref=0 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:07.488227+0000 ctime=2024-04-21T03:55:07.488227+0000 change_attr=0 caps=- 0x564333892600) name scheduled-2024-04-21-03_58_00_UTC
2024-04-21T03:58:00.663+0000 7f48c60ef700 15 open_dir 0x5643322a3ce0 on 0x564333892600
2024-04-21T03:58:00.663+0000 7f48c60ef700 15 client.15615 link dir 0x1.snapdir(faked_ino=0 nref=5 ll_ref=0 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:07.488227+0000 ctime=2024-04-21T03:55:07.488227+0000 change_attr=0 caps=- 0x564333892600) 'scheduled-2024-04-21-03_58_00_UTC' dn 0x1.snapdir["scheduled-2024-04-21-03_58_00_UTC"] (new dn)
2024-04-21T03:58:00.663+0000 7f48c60ef700 10 client.15615 _mkdir: making request
2024-04-21T03:58:00.663+0000 7f48c60ef700 20 client.15615 choose_target_mds starting with req->inode 0x1.snapdir(faked_ino=0 nref=5 ll_ref=0 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:07.488227+0000 ctime=2024-04-21T03:55:07.488227+0000 change_attr=0 caps=- 0x564333892600)
2024-04-21T03:58:00.663+0000 7f48c60ef700 20 client.15615 choose_target_mds inode dir hash is 0 on => 0
2024-04-21T03:58:00.663+0000 7f48c60ef700 10 client.15615 choose_target_mds 0x1.snapdir(faked_ino=0 nref=5 ll_ref=0 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:07.488227+0000 ctime=2024-04-21T03:55:07.488227+0000 change_attr=0 caps=- 0x564333892600) is snapped, using nonsnap parent
2024-04-21T03:58:00.663+0000 7f48c60ef700 20 client.15615 choose_target_mds 0x1.head(faked_ino=0 nref=13 ll_ref=1 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:33.786838+0000 ctime=2024-04-21T03:55:33.786838+0000 change_attr=2 caps=pAsLsXsFs(1=pAsLsXsFs) has_dir_layout 0x564333892000) is_hash=0 hash=0
2024-04-21T03:58:00.663+0000 7f48c60ef700 10 client.15615 choose_target_mds from caps on inode 0x1.head(faked_ino=0 nref=13 ll_ref=1 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:33.786838+0000 ctime=2024-04-21T03:55:33.786838+0000 change_attr=2 caps=pAsLsXsFs(1=pAsLsXsFs) has_dir_layout 0x564333892000)
2024-04-21T03:58:00.663+0000 7f48c60ef700 20 client.15615 mds is 1
2024-04-21T03:58:00.663+0000 7f48c60ef700 10 client.15615 send_request rebuilding request 3 for mds.1
2024-04-21T03:58:00.663+0000 7f48c60ef700 20 client.15615 encode_cap_releases enter (req: 0x564332fe5c00, mds: 1)
2024-04-21T03:58:00.663+0000 7f48c60ef700 20 client.15615 encode_dentry_release enter(dn:0x564332fdcd20)
2024-04-21T03:58:00.663+0000 7f48c60ef700 20 client.15615 encode_inode_release enter(in:0x1.snapdir(faked_ino=0 nref=5 ll_ref=0 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:07.488227+0000 ctime=2024-04-21T03:55:07.488227+0000 change_attr=0 caps=- 0x564333892600), req:0x564332fe5c00 mds:1, drop:Fs, unless:Fx, force:1)
2024-04-21T03:58:00.663+0000 7f48c60ef700 20 client.15615 send_request set sent_stamp to 2024-04-21T03:58:00.664253+0000
2024-04-21T03:58:00.663+0000 7f48c60ef700 10 client.15615 send_request client_request(unknown.0:3 mksnap #0x1//scheduled-2024-04-21-03_58_00_UTC 2024-04-21T03:58:00.664205+0000 caller_uid=0, caller_gid=0{}) to mds.1
2024-04-21T03:58:00.663+0000 7f48c60ef700 1 -- 172.21.15.80:0/477720029 --> [v2:172.21.15.121:6836/2901487594,v1:172.21.15.121:6837/2901487594] -- client_request(unknown.0:3 mksnap #0x1//scheduled-2024-04-21-03_58_00_UTC 2024-04-21T03:58:00.664205+0000 caller_uid=0, caller_gid=0{}) -- 0x564333896000 con 0x5643330f5a80
2024-04-21T03:58:00.663+0000 7f48c60ef700 20 client.15615 awaiting reply|forward|kick on 0x7f48c60ea4b0
2024-04-21T03:58:00.663+0000 7f48bf822700 20 client.15615 put_inode on 0x1.head(faked_ino=0 nref=13 ll_ref=1 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:33.786838+0000 ctime=2024-04-21T03:55:33.786838+0000 change_attr=2 caps=pAsLsXsFs(1=pAsLsXsFs) has_dir_layout 0x564333892000) n = 1
2024-04-21T03:58:00.663+0000 7f48bf822700 20 client.15615 put_inode on 0x1.snapdir(faked_ino=0 nref=5 ll_ref=0 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:07.488227+0000 ctime=2024-04-21T03:55:07.488227+0000 change_attr=0 caps=- 0x564333892600) n = 1
2024-04-21T03:58:00.664+0000 7f48bf822700 20 client.15615 put_inode on 0x1.head(faked_ino=0 nref=13 ll_ref=1 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:33.786838+0000 ctime=2024-04-21T03:55:33.786838+0000 change_attr=2 caps=pAsLsXsFs(1=pAsLsXsFs) has_dir_layout 0x564333892000) n = 1
2024-04-21T03:58:00.664+0000 7f48bf822700 1 -- 172.21.15.80:0/477720029 <== mds.1 v2:172.21.15.121:6836/2901487594 5 ==== client_request_forward(3 to mds.0 num_fwd=1 client_must_resend) ==== 9+0+0 (secure 0 0 0) 0x5643329e2820 con 0x5643330f5a80
2024-04-21T03:58:00.664+0000 7f48bf822700 10 client.15615 handle_client_request_forward tid 3 fwd 1 to mds.0, resending to 0
2024-04-21T03:58:00.664+0000 7f48c60ef700 10 client.15615 choose_target_mds resend_mds specified as mds.0
2024-04-21T03:58:00.664+0000 7f48c60ef700 20 client.15615 mds is 0
2024-04-21T03:58:00.664+0000 7f48c60ef700 10 client.15615 _open_mds_session mds.0
2024-04-21T03:58:00.664+0000 7f48c60ef700 1 --2- 172.21.15.80:0/477720029 >> [v2:172.21.15.121:6838/3852179462,v1:172.21.15.121:6839/3852179462] conn(0x5643330f5180 0x564332f8ac00 unknown :-1 s=NONE pgs=0 cs=0 l=0 rev1=0 crypto rx=0 tx=0 comp rx=0 tx=0).connect
2024-04-21T03:58:00.664+0000 7f48c60ef700 1 -- 172.21.15.80:0/477720029 --> [v2:172.21.15.121:6838/3852179462,v1:172.21.15.121:6839/3852179462] -- client_session(request_open) -- 0x564332feab40 con 0x5643330f5180
2024-04-21T03:58:00.664+0000 7f48c60ef700 10 client.15615 waiting for session to mds.0 to open
2024-04-21T03:58:00.664+0000 7f49816c4700 1 --2- 172.21.15.80:0/477720029 >> [v2:172.21.15.121:6838/3852179462,v1:172.21.15.121:6839/3852179462] conn(0x5643330f5180 0x564332f8ac00 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=0 rev1=0 crypto rx=0 tx=0 comp rx=0 tx=0)._handle_peer_banner_payload supported=3 required=0
2024-04-21T03:58:00.664+0000 7f48bf822700 10 client.15615 ms_handle_connect on v2:172.21.15.121:6838/3852179462
2024-04-21T03:58:00.664+0000 7f49816c4700 1 --2- 172.21.15.80:0/477720029 >> [v2:172.21.15.121:6838/3852179462,v1:172.21.15.121:6839/3852179462] conn(0x5643330f5180 0x564332f8ac00 secure :-1 s=READY pgs=39 cs=0 l=0 rev1=1 crypto rx=0x564333070150 tx=0x5643330135c0 comp rx=0 tx=0).ready entity=mds.0 client_cookie=cb4e6d156680e9bf server_cookie=fbcf01663791af8f in_seq=0 out_seq=0
2024-04-21T03:58:00.667+0000 7f48bf822700 1 -- 172.21.15.80:0/477720029 <== mds.0 v2:172.21.15.121:6838/3852179462 1 ==== client_session(open cap_auths [MDSCapAuth(readable=1, writeable=1)]) ==== 113+0+0 (secure 0 0 0) 0x564332feab40 con 0x5643330f5180
2024-04-21T03:58:00.667+0000 7f48bf822700 10 client.15615 handle_client_session client_session(open cap_auths [MDSCapAuth(readable=1, writeable=1)]) from mds.0
2024-04-21T03:58:00.667+0000 7f48bf822700 10 client.15615 renew_caps mds.0
2024-04-21T03:58:00.667+0000 7f48bf822700 1 -- 172.21.15.80:0/477720029 --> [v2:172.21.15.121:6838/3852179462,v1:172.21.15.121:6839/3852179462] -- client_session(request_renewcaps seq 1) -- 0x56433290c240 con 0x5643330f5180
2024-04-21T03:58:00.667+0000 7f48bf822700 10 client.15615 connect_mds_targets for mds.0
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 choose_target_mds starting with req->inode 0x1.snapdir(faked_ino=0 nref=5 ll_ref=0 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:07.488227+0000 ctime=2024-04-21T03:55:07.488227+0000 change_attr=0 caps=- 0x564333892600)
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 choose_target_mds inode dir hash is 0 on => 0
2024-04-21T03:58:00.667+0000 7f48c60ef700 10 client.15615 choose_target_mds 0x1.snapdir(faked_ino=0 nref=5 ll_ref=0 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:07.488227+0000 ctime=2024-04-21T03:55:07.488227+0000 change_attr=0 caps=- 0x564333892600) is snapped, using nonsnap parent
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 choose_target_mds 0x1.head(faked_ino=0 nref=13 ll_ref=1 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:33.786838+0000 ctime=2024-04-21T03:55:33.786838+0000 change_attr=2 caps=pAsLsXsFs(1=pAsLsXsFs) has_dir_layout 0x564333892000) is_hash=0 hash=0
2024-04-21T03:58:00.667+0000 7f48c60ef700 10 client.15615 choose_target_mds from caps on inode 0x1.head(faked_ino=0 nref=13 ll_ref=1 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:33.786838+0000 ctime=2024-04-21T03:55:33.786838+0000 change_attr=2 caps=pAsLsXsFs(1=pAsLsXsFs) has_dir_layout 0x564333892000)
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 mds is 1
2024-04-21T03:58:00.667+0000 7f48c60ef700 10 client.15615 send_request rebuilding request 3 for mds.1
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 encode_cap_releases enter (req: 0x564332fe5c00, mds: 1)
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 encode_dentry_release enter(dn:0x564332fdcd20)
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 encode_inode_release enter(in:0x1.snapdir(faked_ino=0 nref=5 ll_ref=0 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:07.488227+0000 ctime=2024-04-21T03:55:07.488227+0000 change_attr=0 caps=- 0x564333892600), req:0x564332fe5c00 mds:1, drop:Fs, unless:Fx, force:1)
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 send_request set sent_stamp to 2024-04-21T03:58:00.667720+0000
2024-04-21T03:58:00.667+0000 7f48c60ef700 10 client.15615 send_request client_request(unknown.0:3 mksnap #0x1//scheduled-2024-04-21-03_58_00_UTC 2024-04-21T03:58:00.664205+0000 FWD=1 caller_uid=0, caller_gid=0{}) to mds.1
2024-04-21T03:58:00.667+0000 7f48c60ef700 1 -- 172.21.15.80:0/477720029 --> [v2:172.21.15.121:6836/2901487594,v1:172.21.15.121:6837/2901487594] -- client_request(unknown.0:3 mksnap #0x1//scheduled-2024-04-21-03_58_00_UTC 2024-04-21T03:58:00.664205+0000 FWD=1 caller_uid=0, caller_gid=0{}) -- 0x564333896380 con 0x5643330f5a80
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 awaiting reply|forward|kick on 0x7f48c60ea4b0
2024-04-21T03:58:00.667+0000 7f48bf822700 1 -- 172.21.15.80:0/477720029 <== mds.0 v2:172.21.15.121:6838/3852179462 2 ==== client_session(renewcaps seq 1) ==== 28+0+0 (secure 0 0 0) 0x56433290c240 con 0x5643330f5180
2024-04-21T03:58:00.667+0000 7f48bf822700 10 client.15615 handle_client_session client_session(renewcaps seq 1) from mds.0
2024-04-21T03:58:00.667+0000 7f48bf822700 1 -- 172.21.15.80:0/477720029 <== mds.1 v2:172.21.15.121:6836/2901487594 6 ==== client_request_forward(3 to mds.0 num_fwd=2 client_must_resend) ==== 9+0+0 (secure 0 0 0) 0x5643318c9d40 con 0x5643330f5a80
2024-04-21T03:58:00.667+0000 7f48bf822700 10 client.15615 handle_client_request_forward tid 3 fwd 2 to mds.0, resending to 0
2024-04-21T03:58:00.667+0000 7f48c60ef700 10 client.15615 choose_target_mds resend_mds specified as mds.0
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 mds is 0
2024-04-21T03:58:00.667+0000 7f48c60ef700 10 client.15615 send_request rebuilding request 3 for mds.0
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 encode_cap_releases enter (req: 0x564332fe5c00, mds: 0)
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 encode_dentry_release enter(dn:0x564332fdcd20)
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 encode_inode_release enter(in:0x1.snapdir(faked_ino=0 nref=5 ll_ref=0 cap_refs={} open={} mode=41777 size=0/0 nlink=1 btime=2024-04-21T03:55:07.488227+0000 mtime=2024-04-21T03:55:07.488227+0000 ctime=2024-04-21T03:55:07.488227+0000 change_attr=0 caps=- 0x564333892600), req:0x564332fe5c00 mds:0, drop:Fs, unless:Fx, force:1)
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 send_request set sent_stamp to 2024-04-21T03:58:00.667977+0000
2024-04-21T03:58:00.667+0000 7f48c60ef700 10 client.15615 send_request client_request(unknown.0:3 mksnap #0x1//scheduled-2024-04-21-03_58_00_UTC 2024-04-21T03:58:00.664205+0000 FWD=2 caller_uid=0, caller_gid=0{}) to mds.0
2024-04-21T03:58:00.667+0000 7f48c60ef700 1 -- 172.21.15.80:0/477720029 --> [v2:172.21.15.121:6838/3852179462,v1:172.21.15.121:6839/3852179462] -- client_request(unknown.0:3 mksnap #0x1//scheduled-2024-04-21-03_58_00_UTC 2024-04-21T03:58:00.664205+0000 FWD=2 caller_uid=0, caller_gid=0{}) -- 0x564333896700 con 0x5643330f5180
2024-04-21T03:58:00.667+0000 7f48c60ef700 20 client.15615 awaiting reply|forward|kick on 0x7f48c60ea4b0
From: /teuthology/pdonnell-2024-04-20_23:33:17-fs-wip-pdonnell-testing-20240420.180737-debug-distro-default-smithi/7665987/remote/smithi080/log/a63c2bca-ff91-11ee-bc93-c7b262605968/ceph-mgr.x.log.gz
Updated by Patrick Donnelly 12 days ago
- Status changed from In Progress to Fix Under Review
- Pull request ID set to 57043
Updated by Patrick Donnelly 4 days ago
- Status changed from Fix Under Review to Pending Backport
Updated by Backport Bot 4 days ago
- Copied to Backport #65708: squid: client: resends request to same MDS it just received a forward from if it does not have an open session with the target added
Updated by Backport Bot 4 days ago
- Copied to Backport #65709: reef: client: resends request to same MDS it just received a forward from if it does not have an open session with the target added
Actions