Project

General

Profile

Bug #8427

ceph-fuse: Dumpling "cache still has 0+1 items, waiting (for caps to release?)" on shutdown

Added by Greg Farnum about 5 years ago. Updated almost 5 years ago.

Status:
Won't Fix
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
Start date:
05/22/2014
Due date:
% Done:

0%

Source:
Q/A
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(FS):
Labels (FS):
Pull request ID:

Description

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

History

#1 Updated by Greg Farnum almost 5 years ago

/a/teuthology-2014-09-09_19:06:01-fs-dumpling-testing-basic-multi/475752

I copied the server logs to it

#2 Updated by Greg Farnum almost 5 years ago

/a/teuthology-2014-09-22_19:06:01-fs-dumpling-testing-basic-multi/505408

Grabbed all the logs out of /var/log/ceph for each machine again before nuking.

I rather assume we've fixed this since then but I wish I could find when...

#3 Updated by Sage Weil almost 5 years ago

  • Status changed from New to Won't Fix

#4 Updated by Greg Farnum almost 5 years ago

Sage believes this is a bug with readahead that got fixed in subsequent releases.

Also available in: Atom PDF