Ceph » CephFS

A similar (same?) issue was previously tracked at #4451, but that's resolved now:

2014-05-21 21:16:32.513331 7fca72e66780  2 client.4163 unmounting
2014-05-21 21:16:32.513342 7fca72e66780 10 client.4163 waiting on 1 requests
2014-05-21 21:16:32.817326 7fca6d092700 10 client.4163 insert_trace from 2014-05-21 21:16:32.370459 mds.0 is_target=0 is_dentry=0
2014-05-21 21:16:32.817334 7fca6d092700 10 client.4163 insert_trace -- no trace
2014-05-21 21:16:32.817337 7fca6d092700 10 client.4163 put_inode on 10000000000.head(ref=1 cap_refs={} open={} mode=40755 size=0 mtime=2014-05-21 21:16:32.183994 caps=pAsXs(0=pAsXs) 0x1829480)
2014-05-21 21:16:32.817348 7fca6d092700 10 client.4163 remove_cap mds.0 on 10000000000.head(ref=0 cap_refs={} open={} mode=40755 size=0 mtime=2014-05-21 21:16:32.183994 caps=pAsXs(0=pAsXs) 0x1829480)
2014-05-21 21:16:32.817357 7fca6d092700 10 client.4163 put_inode deleting 10000000000.head(ref=0 cap_refs={} open={} mode=40755 size=0 mtime=2014-05-21 21:16:32.183994 caps=- 0x1829480)
2014-05-21 21:16:32.817369 7fca6d092700 10 client.4163 unmounting: trim pass, size was 0+2
2014-05-21 21:16:32.817373 7fca6d092700 10 client.4163 unmounting: trim pass, size still 0+2
2014-05-21 21:16:32.817379 7fca72e66780 10 client.4163 put_inode on 1.head(ref=2 cap_refs={} open={} mode=41777 size=0 mtime=2014-05-21 20:31:55.282008 caps=pAsLsXs(0=pAsLsXs) has_dir_layout 0x17beb00)
2014-05-21 21:16:32.817403 7fca72e66780 10 client.4163 _ll_drop_pins
2014-05-21 21:16:32.817406 7fca72e66780 10 client.4163 put_inode on 1.head(ref=1 cap_refs={} open={} mode=41777 size=0 mtime=2014-05-21 20:31:55.282008 caps=pAsLsXs(0=pAsLsXs) has_dir_layout 0x17beb00)
2014-05-21 21:16:32.817414 7fca72e66780 10 client.4163 remove_cap mds.0 on 1.head(ref=0 cap_refs={} open={} mode=41777 size=0 mtime=2014-05-21 20:31:55.282008 caps=pAsLsXs(0=pAsLsXs) has_dir_layout 0x17beb00)
2014-05-21 21:16:32.817423 7fca72e66780 10 client.4163 put_inode deleting 1.head(ref=0 cap_refs={} open={} mode=41777 size=0 mtime=2014-05-21 20:31:55.282008 caps=- has_dir_layout 0x17beb00)
2014-05-21 21:16:32.817431 7fca72e66780 10 client.4163 _invalidate_inode_cache 10000000007.head(ref=2 cap_refs={1024=1,2048=0,4096=0,8192=0} open={3=0} mode=100664 size=7187789 mtime=2014-05-21 21:02:06.407306 caps=pAsXsFsxcrwb(0=pAsXsFsxcrwb) objectset[10000000007 ts 6825/7187789 objects 3 dirty_or_tx 0] 0x1818200)
2014-05-21 21:16:32.817529 7fca72e66780 10 client.4163 _flush 10000000007.head(ref=2 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=0} mode=100664 size=7187789 mtime=2014-05-21 21:02:06.407306 caps=pAsXsFsxcrwb(0=pAsXsFsxcrwb) objectset[10000000007 ts 6825/7187789 objects 0 dirty_or_tx 0] 0x1818200)
2014-05-21 21:16:32.817543 7fca72e66780 10 client.4163  nothing to flush
2014-05-21 21:16:32.817544 7fca72e66780 10 client.4163 put_inode on 10000000007.head(ref=2 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=0} mode=100664 size=7187789 mtime=2014-05-21 21:02:06.407306 caps=pAsXsFsxcrwb(0=pAsXsFsxcrwb) objectset[10000000007 ts 6825/7187789 objects 0 dirty_or_tx 0] 0x1818200)
2014-05-21 21:16:32.817556 7fca72e66780 10 client.4163 flush_caps
2014-05-21 21:16:32.817558 7fca72e66780 10 client.4163 check_caps on 10000000007.head(ref=1 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=0} mode=100664 size=7187789 mtime=2014-05-21 21:02:06.407306 caps=pAsXsFsxcrwb(0=pAsXsFsxcrwb) objectset[10000000007 ts 6825/7187789 objects 0 dirty_or_tx 0] 0x1818200) wanted - used - is_delayed=1
2014-05-21 21:16:32.817572 7fca72e66780 10 client.4163  cap mds.0 issued pAsXsFsxcrwb implemented pAsXsFsxcrwb revoking -
2014-05-21 21:16:32.817577 7fca72e66780 10 client.4163 send_cap 10000000007.head(ref=1 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=0} mode=100664 size=7187789 mtime=2014-05-21 21:02:06.407306 caps=pAsXsFsxcrwb(0=pAsXsFsxcrwb) objectset[10000000007 ts 6825/7187789 objects 0 dirty_or_tx 0] 0x1818200) mds.0 seq 46041 used - want - flush - retain p held pAsXsFsxcrwb revoking - dropping AsXsFsxcrwb
2014-05-21 21:16:32.817616 7fca72e66780 10 client.4163 wait_sync_caps want 24722 (last is 24722, 0 total flushing)
2014-05-21 21:16:32.817619 7fca72e66780  2 client.4163 cache still has 0+1 items, waiting (for caps to release?)
2014-05-21 21:16:37.817764 7fca72e66780  1 client.4163 dump_cache
2014-05-21 21:16:37.817778 7fca72e66780  1 client.4163 dump_inode: DISCONNECTED inode 10000000007 #10000000007 ref 110000000007.head(ref=1 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=0} mode=100664 size=7187789 mtime=2014-05-21 21:02:06.407306 caps=p(0=p) objectset[10000000007 ts 6825/7187789 objects 0 dirty_or_tx 0] 0x1818200)
2014-05-21 21:16:37.817805 7fca72e66780  2 client.4163 cache still has 0+1 items, waiting (for caps to release?)

/a/teuthology-2014-05-20_19:02:54-fs-dumpling-testing-basic-plana/267406