Bug #8092: multimds ceph-fuse hang on write waiting for max size - CephFS - Ceph

Actions

Copy link

Bug #8092

closed

multimds ceph-fuse hang on write waiting for max size

Added by Sage Weil about 10 years ago. Updated about 10 years ago.

Status:

Resolved

Priority:

High

Assignee:

Category:

Target version:

% Done:

Source:

Q/A

Tags:

Backport:

Regression:

Severity:

3 - minor

Reviewed:

Affected Versions:

ceph-qa-suite:

Component(FS):

Labels (FS):

Pull request ID:

Crash signature (v1):

Crash signature (v2):

Description

2014-04-12 17:50:33.869375 4035880 10 client.4143 cur file size is 260096
2014-04-12 17:50:33.869504 4035880 10 client.4143 wanted_max_size 0 -> 4096
2014-04-12 17:50:33.869606 4035880 10 client.4143 check_caps on 10000000018.head(ref=3 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=1} mode=100600 size=260096 mtime=2014-04-12 17:43:33.938099 caps=pAsLsXsFsxcrwb(0=pLs,3=pAsLsXsFsxcrwb) objectset[10000000018 ts 0/0 objects 1 dirty_or_tx 0] parents=0xfabfae0 0xfb0f5d0) wanted pAsxXsxFsxcrwb used Fc is_delayed=0
2014-04-12 17:50:33.870797 4035880 10 client.4143 cap_delay_requeue on 10000000018.head(ref=3 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=1} mode=100600 size=260096 mtime=2014-04-12 17:43:33.938099 caps=pAsLsXsFsxcrwb(0=pLs,3=pAsLsXsFsxcrwb) objectset[10000000018 ts 0/0 objects 1 dirty_or_tx 0] parents=0xfabfae0 0xfb0f5d0)
2014-04-12 17:50:33.871786 4035880 10 client.4143  cap mds.0 issued pLs implemented pLs revoking -
2014-04-12 17:50:33.872001 4035880 10 client.4143  cap mds.3 issued pAsLsXsFsxcrwb implemented pAsLsXsFsxcrwb revoking -
2014-04-12 17:50:33.872485 4035880 10 client.4143 send_cap 10000000018.head(ref=3 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=1} mode=100600 size=260096 mtime=2014-04-12 17:43:33.938099 caps=pAsLsXsFsxcrwb(0=pLs,3=pAsLsXsFsxcrwb) objectset[10000000018 ts 0/0 objects 1 dirty_or_tx 0] parents=0xfabfae0 0xfb0f5d0) mds.3 seq 8 used Fc want pAsxXsxFsxcrwb flush - retain pAsxLsxXsxFsxcrwbl held pAsLsXsFsxcrwb revoking - dropping -
2014-04-12 17:50:33.874197 4035880  1 -- 10.214.133.26:0/29495 --> 10.214.133.28:6813/10251 -- client_caps(update ino 10000000018 25 seq 8 caps=pAsLsXsFsxcrwb dirty=- wanted=pAsxXsxFsxcrwb follows 0 mseq 3 size 260096/4096 ts 1 mtime 2014-04-12 17:43:33.938099) v4 -- ?+0 0x715bae0 con 0xe422760
2014-04-12 17:50:33.875202 4035880 10 client.4143 waiting on max_size, endoff 4096 max_size 0 on 10000000018.head(ref=3 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=1} mode=100600 size=260096 mtime=2014-04-12 17:43:33.938099 caps=pAsLsXsFsxcrwb(0=pLs,3=pAsLsXsFsxcrwb) objectset[10000000018 ts 0/0 objects 1 dirty_or_tx 0] parents=0xfabfae0 0xfb0f5d0)
2014-04-12 17:50:33.881165 b172700  1 -- 10.214.133.26:0/29495 <== mds.3 10.214.133.28:6813/10251 150 ==== client_caps(revoke ino 10000000018 25 seq 9 caps=pAsLsXsFrw dirty=- wanted=pAsxXsxFsxcrwb follows 0 mseq 3 size 260096/0 ts 1 mtime 2014-04-12 17:43:33.938099) v4 ==== 192+0+0 (2757105202 0 0) 0xd5c5830 con 0xe422760
2014-04-12 17:50:33.882109 b172700 10 client.4143  mds.3 seq now 123
2014-04-12 17:50:33.882248 b172700  5 client.4143 handle_cap_grant on in 10000000018 mds.3 seq 9 caps now pAsLsXsFrw was pAsLsXsFsxcrwb
2014-04-12 17:50:33.882668 b172700 10 client.4143 update_inode_file_bits 10000000018.head(ref=3 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=1} mode=100600 size=260096 mtime=2014-04-12 17:43:33.938099 caps=pAsLsXsFsxcrwb(0=pLs,3=pAsLsXsFsxcrwb) objectset[10000000018 ts 0/0 objects 1 dirty_or_tx 0] parents=0xfabfae0 0xfb0f5d0) pAsLsXsFsxcrwb mtime 2014-04-12 17:43:33.938099
2014-04-12 17:50:33.883818 b172700 10 client.4143   revocation of Fsxcb
2014-04-12 17:50:33.885593 b172700 10 client.4143 _invalidate_inode_cache 10000000018.head(ref=3 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=1} mode=100600 size=260096 mtime=2014-04-12 17:43:33.938099 caps=pAsLsXsFrw(0=pLs,3=pAsLsXsFrw) objectset[10000000018 ts 0/0 objects 1 dirty_or_tx 0] parents=0xfabfae0 0xfb0f5d0)
2014-04-12 17:50:33.886621 b172700 10 client.4143 check_caps on 10000000018.head(ref=3 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=1} mode=100600 size=260096 mtime=2014-04-12 17:43:33.938099 caps=pAsLsXsFrw(0=pLs,3=pAsLsXsFrw) objectset[10000000018 ts 0/0 objects 0 dirty_or_tx 0] parents=0xfabfae0 0xfb0f5d0) wanted pAsxXsxFsxcrwb used - is_delayed=0
2014-04-12 17:50:33.887813 b172700 10 client.4143 cap_delay_requeue on 10000000018.head(ref=3 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=1} mode=100600 size=260096 mtime=2014-04-12 17:43:33.938099 caps=pAsLsXsFrw(0=pLs,3=pAsLsXsFrw) objectset[10000000018 ts 0/0 objects 0 dirty_or_tx 0] parents=0xfabfae0 0xfb0f5d0)
2014-04-12 17:50:33.888733 b172700 10 client.4143  cap mds.0 issued pLs implemented pLs revoking -
2014-04-12 17:50:33.888950 b172700 10 client.4143  cap mds.3 issued pAsLsXsFrw implemented pAsLsXsFsxcrwb revoking Fsxcb
2014-04-12 17:50:33.889442 b172700 10 client.4143 completed revocation of Fsxcb
2014-04-12 17:50:33.889588 b172700 10 client.4143 send_cap 10000000018.head(ref=3 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=1} mode=100600 size=260096 mtime=2014-04-12 17:43:33.938099 caps=pAsLsXsFrw(0=pLs,3=pAsLsXsFrw) objectset[10000000018 ts 0/0 objects 0 dirty_or_tx 0] parents=0xfabfae0 0xfb0f5d0) mds.3 seq 9 used - want pAsxXsxFsxcrwb flush - retain pAsxLsxXsxFrwl held pAsLsXsFsxcrwb revoking Fsxcb dropping -
2014-04-12 17:50:33.891197 b172700  1 -- 10.214.133.26:0/29495 --> 10.214.133.28:6813/10251 -- client_caps(update ino 10000000018 25 seq 9 caps=pAsLsXsFrw dirty=- wanted=pAsxXsxFsxcrwb follows 0 mseq 3 size 260096/4096 ts 1 mtime 2014-04-12 17:43:33.938099) v4 -- ?+0 0xdc117e0 con 0xe422760
2014-04-12 17:50:33.894898 4035880 10 client.4143 waiting on max_size, endoff 4096 max_size 0 on 10000000018.head(ref=3 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=1} mode=100600 size=260096 mtime=2014-04-12 17:43:33.938099 caps=pAsLsXsFrw(0=pLs,3=pAsLsXsFrw) objectset[10000000018 ts 0/0 objects 0 dirty_or_tx 0] parents=0xfabfae0 0xfb0f5d0)
2014-04-12 17:50:34.018020 b172700  1 -- 10.214.133.26:0/29495 <== mds.0 10.214.131.10:6800/5127 2492 ==== client_caps(grant ino 10000000018 223 seq 4 caps=pAsLsXsFr dirty=- wanted=pAsXsFscr follows 0 size 260096/4194304 ts 1 mtime 2014-04-12 17:43:33.938099) v4 ==== 192+0+0 (3821352483 0 0) 0xda39600 con 0x6edc480
2014-04-12 17:50:34.018914 b172700 10 client.4143  mds.0 seq now 1005
2014-04-12 17:50:34.019048 b172700  5 client.4143 handle_cap_grant on in 10000000018 mds.0 seq 4 caps now pAsLsXsFr was pLs
2014-04-12 17:50:34.019343 b172700 10 client.4143 update_inode_file_bits 10000000018.head(ref=3 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=1} mode=100600 size=260096 mtime=2014-04-12 17:43:33.938099 caps=pAsLsXsFrw(0=pLs,3=pAsLsXsFrw) objectset[10000000018 ts 0/0 objects 0 dirty_or_tx 0] parents=0xfabfae0 0xfb0f5d0) pAsLsXsFrw mtime 2014-04-12 17:43:33.938099
2014-04-12 17:50:34.020393 b172700 10 client.4143   grant, new caps are AsXsFr
2014-04-12 17:50:34.020821 4035880 10 client.4143 waiting on max_size, endoff 4096 max_size 0 on 10000000018.head(ref=3 cap_refs={1024=0,2048=0,4096=0,8192=0} open={3=1} mode=100600 size=260096 mtime=2014-04-12 17:43:33.938099 caps=pAsLsXsFrw(0=pAsLsXsFr,3=pAsLsXsFrw) objectset[10000000018 ts 0/0 objects 0 dirty_or_tx 0] parents=0xfabfae0 0xfb0f5d0)
...

ubuntu@teuthology:/var/lib/teuthworker/archive/teuthology-2014-04-11_23:01:29-multimds-master-testing-basic-plana/187172