Re: ceph-fuse slow cache?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 

Could you strace apacha process, check which syscall waits for a long time.
On Sat, Aug 25, 2018 at 3:04 AM Stefan Kooman <stefan@xxxxxx> wrote:
>
> 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
_______________________________________________
ceph-users mailing list
ceph-users@xxxxxxxxxxxxxx
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
[Index of Archives]     [Information on CEPH]     [Linux Filesystem Development]     [Ceph Development]     [Ceph Large]     [Linux USB Development]     [Video for Linux]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [xfs]

  Powered by Linux