Quoting Gregory Farnum (gfar...@redhat.com):

> 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 / i...@bit.nl
_______________________________________________
ceph-users mailing list
ceph-users@lists.ceph.com
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com

Reply via email to