Quoting Gregory Farnum (gfarnum@xxxxxxxxxx):
> Hmm, these aren't actually the start and end times to the same operation.
> put_inode() is literally adjusting a refcount, which can happen for reasons
> ranging from the VFS doing something that drops it to an internal operation
> completing to a response coming back from the MDS. You should be able to
> find requests coming in from the kernel and a response going back out (the
> function names will be prefixed with "ll_", eg "ll_lookup").
Ok, next try. One page visit and grepped "sess_". See results below:
2018-08-25 11:10:42.142 7ff2a0c2c700 3 client.15224195 ll_lookup 0x1000068547c.head sess_bss8rh5bug6bffvj6s67vnsce5
2018-08-25 11:10:42.142 7ff2a0c2c700 10 client.15224195 _lookup concluded ENOENT locally for 0x1000068547c.head(faked_ino=0 ref=2 ll_ref=4 cap_refs={} open={} mode=40755 size=0/0 nlink=1 btime=2018-08-23 14:23:09.291832 mtime=2018-08-25 11:08:11.025085 ctime=2018-08-25 11:08:11.025085 caps=pAsLsXsFs(0=pAsLsXsFs) COMPLETE parents=0x100005218bb.head["sessions"] 0x557ddecc6100) dn 'sess_bss8rh5bug6bffvj6s67vnsce5'
2018-08-25 11:10:42.142 7ff2a0c2c700 3 client.15224195 ll_lookup 0x1000068547c.head sess_bss8rh5bug6bffvj6s67vnsce5 -> -2 (0)
2018-08-25 11:10:42.142 7ff2a142d700 3 client.15224195 ll_lookup 0x1000068547c.head sess_bss8rh5bug6bffvj6s67vnsce5
2018-08-25 11:10:42.142 7ff2a142d700 10 client.15224195 _lookup concluded ENOENT locally for 0x1000068547c.head(faked_ino=0 ref=2 ll_ref=5 cap_refs={} open={} mode=40755 size=0/0 nlink=1 btime=2018-08-23 14:23:09.291832 mtime=2018-08-25 11:08:11.025085 ctime=2018-08-25 11:08:11.025085 caps=pAsLsXsFs(0=pAsLsXsFs) COMPLETE parents=0x100005218bb.head["sessions"] 0x557ddecc6100) dn 'sess_bss8rh5bug6bffvj6s67vnsce5'
2018-08-25 11:10:42.142 7ff2a142d700 3 client.15224195 ll_lookup 0x1000068547c.head sess_bss8rh5bug6bffvj6s67vnsce5 -> -2 (0)
2018-08-25 11:10:42.142 7ff2a0c2c700 8 client.15224195 _ll_create 0x1000068547c.head sess_bss8rh5bug6bffvj6s67vnsce5 0100600 131138, uid 5003, gid 5003
2018-08-25 11:10:42.142 7ff2a0c2c700 10 client.15224195 _lookup concluded ENOENT locally for 0x1000068547c.head(faked_ino=0 ref=2 ll_ref=5 cap_refs={} open={} mode=40755 size=0/0 nlink=1 btime=2018-08-23 14:23:09.291832 mtime=2018-08-25 11:08:11.025085 ctime=2018-08-25 11:08:11.025085 caps=pAsLsXsFs(0=pAsLsXsFs) COMPLETE parents=0x100005218bb.head["sessions"] 0x557ddecc6100) dn 'sess_bss8rh5bug6bffvj6s67vnsce5'
^^ check for existing session file, which does not exist, yet.
2018-08-25 11:10:42.142 7ff2a0c2c700 8 client.15224195 _create(0x1000068547c sess_bss8rh5bug6bffvj6s67vnsce5, 0100600)
2018-08-25 11:10:42.142 7ff2a0c2c700 20 client.15224195 get_or_create 0x1000068547c.head(faked_ino=0 ref=3 ll_ref=5 cap_refs={} open={} mode=40755 size=0/0 nlink=1 btime=2018-08-23 14:23:09.291832 mtime=2018-08-25 11:08:11.025085 ctime=2018-08-25 11:08:11.025085 caps=pAsLsXsFs(0=pAsLsXsFs) COMPLETE parents=0x100005218bb.head["sessions"] 0x557ddecc6100) name sess_bss8rh5bug6bffvj6s67vnsce5
2018-08-25 11:10:42.142 7ff2a0c2c700 15 client.15224195 link dir 0x557ddecc6100 'sess_bss8rh5bug6bffvj6s67vnsce5' to inode 0 dn 0x557ddf053de0 (new dn)
2018-08-25 11:10:42.142 7ff2a0c2c700 20 client.15224195 choose_target_mds inode dir hash is 2 on sess_bss8rh5bug6bffvj6s67vnsce5 => 3288169645
2018-08-25 11:10:42.142 7ff2a0c2c700 10 client.15224195 send_request client_request(unknown.0:872 create #0x1000068547c/sess_bss8rh5bug6bffvj6s67vnsce5 2018-08-25 11:10:42.148081 caller_uid=5003, caller_gid=5003{5003,}) v4 to mds.0
2018-08-25 11:10:42.142 7ff2a0c2c700 1 -- [2001:7b8:81:6::18]:0/4024171085 --> [2001:7b8:80:3:0:2c:3:2]:6800/1086374448 -- client_request(unknown.0:872 create #0x1000068547c/sess_bss8rh5bug6bffvj6s67vnsce5 2018-08-25 11:10:42.148081 caller_uid=5003, caller_gid=5003{5003,}) v4 -- 0x557ddf884080 con 0
2018-08-25 11:10:42.142 7ff2a5c36700 12 client.15224195 insert_dentry_inode 'sess_bss8rh5bug6bffvj6s67vnsce5' vino 0x100006d9844.head in dir 0x1000068547c.head dn 0x557ddf053de0
2018-08-25 11:10:42.142 7ff2a5c36700 15 client.15224195 link dir 0x557ddecc6100 'sess_bss8rh5bug6bffvj6s67vnsce5' to inode 0x557ddfaa0680 dn 0x557ddf053de0 (old dn)
2018-08-25 11:10:42.142 7ff2a5c36700 10 client.15224195 put_inode on 0x100006d9844.head(faked_ino=0 ref=3 ll_ref=0 cap_refs={} open={} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:42.142 7ff2a5c36700 20 client.15224195 link inode 0x557ddfaa0680 parents now 0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"]
2018-08-25 11:10:42.142 7ff2a5c36700 10 client.15224195 put_inode on 0x100006d9844.head(faked_ino=0 ref=2 ll_ref=0 cap_refs={} open={} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:42.142 7ff2a5c36700 10 client.15224195 got dentry lease on sess_bss8rh5bug6bffvj6s67vnsce5 dur 30000ms ttl 2018-08-25 11:11:12.148118
2018-08-25 11:10:42.142 7ff2a0c2c700 20 client.15224195 make_request target is 0x100006d9844.head(faked_ino=0 ref=3 ll_ref=0 cap_refs={} open={} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:42.142 7ff2a0c2c700 10 break_deleg: breaking delegs on 0x100006d9844.head(faked_ino=0 ref=3 ll_ref=0 cap_refs={} open={3=1} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:42.142 7ff2a0c2c700 10 delegations_broken: delegations empty on 0x100006d9844.head(faked_ino=0 ref=3 ll_ref=0 cap_refs={} open={3=1} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
^^ I interpret these as requesting the MDS for a new inode and update
it's dentry for the "session" directory holding this file. Breaking
delegations because directory content is going to change.
2018-08-25 11:10:42.142 7ff2a0c2c700 10 client.15224195 put_inode on 0x100006d9844.head(faked_ino=0 ref=5 ll_ref=0 cap_refs={} open={3=1} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:42.142 7ff2a0c2c700 8 client.15224195 create(#0x1000068547c/sess_bss8rh5bug6bffvj6s67vnsce5, 0100600 layout 0 0 0) = 0
2018-08-25 11:10:42.142 7ff2a0c2c700 8 client.15224195 _ll_create 0x1000068547c.head sess_bss8rh5bug6bffvj6s67vnsce5 0100600 131138 = 0 (0x557ddf727c20 100006d9844)
2018-08-25 11:10:42.142 7ff2a0c2c700 10 client.15224195 put_inode on 0x100006d9844.head(faked_ino=0 ref=5 ll_ref=1 cap_refs={} open={3=1} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:42.146 7ff2a042b700 20 client.15224195 choose_target_mds starting with req->inode 0x100006d9844.head(faked_ino=0 ref=5 ll_ref=1 cap_refs={} open={3=1} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:42.146 7ff2a042b700 20 client.15224195 choose_target_mds 0x100006d9844.head(faked_ino=0 ref=5 ll_ref=1 cap_refs={} open={3=1} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680) is_hash=0 hash=0
2018-08-25 11:10:42.146 7ff2a042b700 10 client.15224195 choose_target_mds from caps on inode 0x100006d9844.head(faked_ino=0 ref=5 ll_ref=1 cap_refs={} open={3=1} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:42.146 7ff2a5c36700 10 client.15224195 put_inode on 0x100006d9844.head(faked_ino=0 ref=5 ll_ref=1 cap_refs={} open={3=1} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
^^ Actually creating the file on reserved inode.
2018-08-25 11:10:42.462 7ff2a5c36700 10 client.15224195 update_inode_file_time 0x100006d9844.head(faked_ino=0 ref=4 ll_ref=1 cap_refs={} open={3=1} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680) pAsxLsXsxFsxcrwb ctime 2018-08-25 11:10:42.148081 mtime 2018-08-25 11:10:42.148081
^^ Adjust mtime of inode
2018-08-25 11:10:42.462 7ff2a5c36700 10 client.15224195 put_inode on 0x100006d9844.head(faked_ino=0 ref=4 ll_ref=1 cap_refs={} open={3=1} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:44.654 7ff2a142d700 10 client.15224195 _flush: 0x557ddf727c20 on inode 0x100006d9844.head(faked_ino=0 ref=3 ll_ref=1 cap_refs={} open={3=1} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680) no async_err state
^^ flush cache? This does take quite some time.
2018-08-25 11:10:44.658 7ff29ec28700 8 client.15224195 _release_fh 0x557ddf727c20 mode 3 on 0x100006d9844.head(faked_ino=0 ref=3 ll_ref=1 cap_refs={} open={3=1} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:44.658 7ff29ec28700 10 client.15224195 _flush 0x100006d9844.head(faked_ino=0 ref=4 ll_ref=1 cap_refs={} open={3=0} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:44.658 7ff29ec28700 10 client.15224195 put_inode on 0x100006d9844.head(faked_ino=0 ref=4 ll_ref=1 cap_refs={} open={3=0} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:44.658 7ff29ec28700 10 client.15224195 check_caps on 0x100006d9844.head(faked_ino=0 ref=3 ll_ref=1 cap_refs={} open={3=0} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680) wanted - used - issued pAsxLsXsxFsxcrwb revoking - flags=0
2018-08-25 11:10:44.658 7ff29ec28700 10 client.15224195 cap_delay_requeue on 0x100006d9844.head(faked_ino=0 ref=3 ll_ref=1 cap_refs={} open={3=0} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:44.658 7ff29ec28700 20 client.15224195 choose_target_mds starting with req->inode 0x100006d9844.head(faked_ino=0 ref=4 ll_ref=1 cap_refs={} open={3=0} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:44.658 7ff29ec28700 20 client.15224195 choose_target_mds 0x100006d9844.head(faked_ino=0 ref=4 ll_ref=1 cap_refs={} open={3=0} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680) is_hash=0 hash=0
2018-08-25 11:10:44.658 7ff29ec28700 10 client.15224195 choose_target_mds from caps on inode 0x100006d9844.head(faked_ino=0 ref=4 ll_ref=1 cap_refs={} open={3=0} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:44.658 7ff29ec28700 10 client.15224195 _release_fh 0x557ddf727c20 on inode 0x100006d9844.head(faked_ino=0 ref=4 ll_ref=1 cap_refs={} open={3=0} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680) no async_err state
2018-08-25 11:10:44.658 7ff29ec28700 10 client.15224195 put_inode on 0x100006d9844.head(faked_ino=0 ref=4 ll_ref=1 cap_refs={} open={3=0} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:44.658 7ff2a5c36700 10 client.15224195 put_inode on 0x100006d9844.head(faked_ino=0 ref=3 ll_ref=1 cap_refs={} open={3=0} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680)
2018-08-25 11:10:50.414 7ff2a6c38700 10 client.15224195 check_caps on 0x100006d9844.head(faked_ino=0 ref=2 ll_ref=1 cap_refs={} open={3=0} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680) wanted - used - issued pAsxLsXsxFsxcrwb revoking - flags=1
2018-08-25 11:10:50.414 7ff2a6c38700 10 client.15224195 send_cap 0x100006d9844.head(faked_ino=0 ref=2 ll_ref=1 cap_refs={} open={3=0} mode=100600 size=0/4194304 nlink=1 btime=2018-08-25 11:10:42.148081 mtime=2018-08-25 11:10:42.148081 ctime=2018-08-25 11:10:42.148081 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[0x100006d9844 ts 0/0 objects 0 dirty_or_tx 0] parents=0x1000068547c.head["sess_bss8rh5bug6bffvj6s67vnsce5"] 0x557ddfaa0680) mds.0 seq 2 async used - want - flush - retain pAsLsXsFs held pAsxLsXsxFsxcrwb revoking - dropping AxXxFxcrwb
^^ Obtaining new caps?
Please let me now if I'm misinterpreting this. Is this Enough info to figure
out what action is taking so much time?
Thanks for looking into it.
Gr. Stefan
--
| BIT BV http://www.bit.nl/ Kamer van Koophandel 09090351
| GPG: 0xD14839C6 +31 318 648 688 / info@xxxxxx
_______________________________________________
ceph-users mailing list
ceph-users@xxxxxxxxxxxxxx
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
