Actions
Fix #3630
closedmds: broken closed connection cleanup
Added by Sage Weil over 11 years ago. Updated almost 8 years ago.
Source:
Development
Tags:
Backport:
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(FS):
MDS
Labels (FS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
Consider:
- client->mds REQUEST_CLOSE
- mds->client CLOSE
- client closes con
- mds see fault, goes to standbyThis was changed recently to avoid broken semantics in the non-close case, but an all-out leak isn't good either.
In particular, if a client reconnects with the same addr/nonce, they will inherit the old session.
Updated by Sage Weil over 11 years ago
The con re-use looks like this:
- client connects
- mds ms_verify_authorizer creates a new session
- msgr see existing session, throws out new con, attaches us to the old con
- session continues, but the pipe source inst is client.new, but the session is the old one from client.old
- confusion!
Updated by Sage Weil over 11 years ago
2012-12-30 02:11:13.022384 7f1762ffd700 20 accepter.accepter calling poll
2012-12-30 02:11:13.022380 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> :/0 pipe(0x7f175cd60db0 sd=957 :0 pgs=0 cs=0 l=0).accept
2012-12-30 02:11:13.022625 7f16d4d7c700 1 -- 10.3.64.22:6804/32728 >> :/0 pipe(0x7f175cd60db0 sd=957 :6804 pgs=0 cs=0 l=0).accept sd=957 10.3.64.22:56188/0
2012-12-30 02:11:13.022721 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=0 cs=0 l=0).accept peer addr is 10.3.64.22:0/1002076
2012-12-30 02:11:13.022878 7f16d4d7c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=0 cs=0 l=0).accept got peer connect_seq 0 global_seq 2
2012-12-30 02:11:13.022909 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=0 cs=0 l=0).accept of host_type 8, policy.lossy=0
2012-12-30 02:11:13.022917 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=0 cs=0 l=0).accept my proto 32, their proto 32
2012-12-30 02:11:13.022952 7f16d4d7c700 10 cephx: verify_authorizer decrypted service mds secret_id=7
2012-12-30 02:11:13.023049 7f16d4d7c700 10 cephx: verify_authorizer global_id=5043
2012-12-30 02:11:13.023111 7f16d4d7c700 10 cephx: verify_authorizer ok nonce 6633487374b0dc51 reply_bl.length()=36
2012-12-30 02:11:13.023135 7f16d4d7c700 10 mds.0.1 new session 0x315c1b0 for client.5043 10.3.64.22:0/1002076 con 0x7f175c50d510
2012-12-30 02:11:13.023159 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=0 cs=0 l=0).accept: setting up session_security.
2012-12-30 02:11:13.023176 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=0 cs=0 l=0).accept existing 0x7f1754d23bf0.gseq 2 <= 2, looks ok
2012-12-30 02:11:13.023192 7f16d4d7c700 0 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=0 cs=0 l=0).accept connect_seq 0 vs existing 1 state standby
2012-12-30 02:11:13.023215 7f16d4d7c700 0 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=0 cs=0 l=0).accept peer reset, then tried to connect to us, replacing
2012-12-30 02:11:13.023229 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f1754d23bf0 sd=64 :6804 pgs=2 cs=1 l=0).was_session_reset
2012-12-30 02:11:13.023251 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f1754d23bf0 sd=64 :6804 pgs=2 cs=1 l=0).discard_queue
2012-12-30 02:11:13.023260 7f16d4d7c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f1754d23bf0 sd=64 :6804 pgs=2 cs=1 l=0). discard 0x34c1a80
2012-12-30 02:11:13.023393 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f1754d23bf0 sd=64 :6804 pgs=2 cs=1 l=0).randomize_out_seq 120388906
2012-12-30 02:11:13.023421 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=0 cs=0 l=0).accept replacing 0x7f1754d23bf0
2012-12-30 02:11:13.023429 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f1754d23bf0 sd=64 :6804 pgs=2 cs=0 l=0).stop
2012-12-30 02:11:13.023468 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f1754d23bf0 sd=64 :6804 pgs=2 cs=0 l=0).unregister_pipe
2012-12-30 02:11:13.023433 7f17637fe700 0 mds.0.1 ms_handle_remote_reset on 10.3.64.22:0/1002076
2012-12-30 02:11:13.030801 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=0 cs=0 l=0).accept re-queuing on out_seq 120388906 in_seq 0
2012-12-30 02:11:13.030827 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).accept success, connect_seq = 1, sending READY
2012-12-30 02:11:13.030837 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).accept features 134217727
2012-12-30 02:11:13.030843 7f16d4d7c700 10 In get_auth_session_handler for protocol 2
2012-12-30 02:11:13.030832 7f174e7e7700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f1754d23bf0 sd=64 :6804 pgs=2 cs=0 l=0).writer finishing
2012-12-30 02:11:13.030866 7f174e7e7700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f1754d23bf0 sd=64 :6804 pgs=2 cs=0 l=0).writer done
2012-12-30 02:11:13.030899 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).register_pipe
2012-12-30 02:11:13.030897 7f174e8e8700 10 -- 10.3.64.22:6804/32728 queue_reap 0x7f1754d23bf0
2012-12-30 02:11:13.030972 7f17637fe700 10 mds.0.1 ms_handle_accept 10.3.64.22:0/1002076 con 0x7f1754cdf780 session 0x7f17500fc4e0
2012-12-30 02:11:13.031110 7f174e8e8700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f1754d23bf0 sd=64 :6804 pgs=2 cs=0 l=0).reader done
2012-12-30 02:11:13.031113 7f1768a0e700 10 -- 10.3.64.22:6804/32728 reaper
2012-12-30 02:11:13.031139 7f1768a0e700 10 -- 10.3.64.22:6804/32728 reaper reaping pipe 0x7f1754d23bf0 10.3.64.22:0/1002076
2012-12-30 02:11:13.031159 7f1768a0e700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f1754d23bf0 sd=64 :6804 pgs=2 cs=0 l=0).discard_queue
2012-12-30 02:11:13.031213 7f1768a0e700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f1754d23bf0 sd=64 :6804 pgs=2 cs=0 l=0).unregister_pipe - not registered
2012-12-30 02:11:13.031294 7f1768a0e700 10 -- 10.3.64.22:6804/32728 reaper reaped pipe 0x7f1754d23bf0 10.3.64.22:0/1002076
2012-12-30 02:11:13.031341 7f1768a0e700 10 -- 10.3.64.22:6804/32728 reaper deleted pipe 0x7f1754d23bf0
2012-12-30 02:11:13.031359 7f1768a0e700 10 -- 10.3.64.22:6804/32728 reaper done
2012-12-30 02:11:13.031949 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).accept starting writer, state open
2012-12-30 02:11:13.031999 7f16d4d7c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).accept done
2012-12-30 02:11:13.032042 7f174e8e8700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).writer: state = open policy.server=1
2012-12-30 02:11:13.032079 7f174e8e8700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).writer sleeping
2012-12-30 02:11:13.032102 7f16d4d7c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).reader reading tag...
2012-12-30 02:11:13.032131 7f16d4d7c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).reader got MSG
2012-12-30 02:11:13.032152 7f16d4d7c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).reader got envelope type=22 src client.5043 front=28 data=0 off 0
2012-12-30 02:11:13.032164 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).reader wants 28 from dispatch throttler 0/104857600
2012-12-30 02:11:13.032189 7f16d4d7c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).reader got front 28
2012-12-30 02:11:13.032211 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).aborted = 0
2012-12-30 02:11:13.032223 7f16d4d7c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).reader got 28 + 0 + 0 byte message
2012-12-30 02:11:13.032238 7f16d4d7c700 10 check_message_signature: seq # = 1 front_crc_ = 0 middle_crc = 0 data_crc = 0
2012-12-30 02:11:13.032305 7f16d4d7c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).reader got message 1 0x34c1a80 client_session(request_open) v1
2012-12-30 02:11:13.032329 7f16d4d7c700 20 -- 10.3.64.22:6804/32728 queue 0x34c1a80 prio 127
2012-12-30 02:11:13.032351 7f16d4d7c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).reader reading tag...
2012-12-30 02:11:13.032355 7f174e8e8700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).writer: state = open policy.server=1
2012-12-30 02:11:13.032357 7f17637fe700 1 -- 10.3.64.22:6804/32728 <== client.5043 10.3.64.22:0/1002076 1 ==== client_session(request_open) v1 ==== 28+0+0 (0 0 0) 0x34c1a80 con 0x7f1754cdf780
2012-12-30 02:11:13.032369 7f174e8e8700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).write_ack 1
2012-12-30 02:11:13.032391 7f17637fe700 20 mds.0.server get_session have 0x7f17500fc4e0 *client.4150* 10.3.64.22:0/1002076 state closed
2012-12-30 02:11:13.032394 7f174e8e8700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).writer: state = open policy.server=1
2012-12-30 02:11:13.032409 7f17637fe700 3 mds.0.server handle_client_session client_session(request_open) v1 from client.5043
2012-12-30 02:11:13.032411 7f174e8e8700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:0/1002076 pipe(0x7f175cd60db0 sd=957 :6804 pgs=2 cs=1 l=0).writer sleeping
2012-12-30 02:11:13.032590 7f17637fe700 5 mds.0.log submit_entry 222773544~179 : ESession client.5043 10.3.64.22:0/1002076 open cmapv 113620
2012-12-30 02:11:13.032657 7f17637fe700 10 mds.0.cache create_subtree_map 2 subtrees, 2 fullauth
2012-12-30 02:11:13.032703 7f17637fe700 15 mds.0.cache show_subtrees
2012-12-30 02:11:13.032725 7f17637fe700 10 mds.0.cache |__ 0 auth [dir 1 / [2,head] auth v=225524 cv=225162/225162 REP dir_auth=0 state=1610612738|complete f(v0 m2012-12-30 02:10:48.794482 56341=56340+1) n(v0 rc2012-12-30 02:10:48.794482 b115384320 56341=56340+1)/n(v0 1=0+
1) hs=56341+0,ss=0+0 dirty=120 | child subtree dirty 0x7f175c023c70]
2012-12-30 02:11:13.032766 7f17637fe700 10 mds.0.cache |__ 0 auth [dir 100 ~mds0/ [2,head] auth v=1 cv=1/1 dir_auth=0 state=1073741826|complete f(v0 11=1+10) n(v0 11=1+10) hs=11+0,ss=0+0 | child subtree 0x7f175c024460]
2012-12-30 02:11:13.032795 7f17637fe700 15 mds.0.cache subtree [dir 1 / [2,head] auth v=225524 cv=225162/225162 REP dir_auth=0 state=1610612738|complete f(v0 m2012-12-30 02:10:48.794482 56341=56340+1) n(v0 rc2012-12-30 02:10:48.794482 b115384320 56341=56340+1)/n(v0 1=0+1) hs
=56341+0,ss=0+0 dirty=120 | child subtree dirty 0x7f175c023c70]
2012-12-30 02:11:13.032826 7f17637fe700 20 mds.0.journal EMetaBlob::add_dir_context final:
2012-12-30 02:11:13.032844 7f17637fe700 15 mds.0.cache subtree [dir 100 ~mds0/ [2,head] auth v=1 cv=1/1 dir_auth=0 state=1073741826|complete f(v0 11=1+10) n(v0 11=1+10) hs=11+0,ss=0+0 | child subtree 0x7f175c024460]
2012-12-30 02:11:13.032861 7f17637fe700 20 mds.0.journal EMetaBlob::add_dir_context final:
2012-12-30 02:11:13.032871 7f17637fe700 15 mds.0.cache subtrees {1=[],100=[]}
2012-12-30 02:11:13.032877 7f17637fe700 15 mds.0.cache ambiguous_subtrees
2012-12-30 02:11:13.032928 7f17637fe700 5 mds.0.log submit_entry 222773727~667 : ESubtreeMap 2 subtrees , 0 ambiguous [metablob 1, 2 dirs]
2012-12-30 02:11:13.033239 7f17637fe700 1 -- 10.3.64.22:6804/32728 --> 10.3.64.22:6800/32705 -- osd_op(mds.0.1:60416 200.00000035 [write 475432~854] 1.20779f7e) v4 -- ?+0 0x7f1764882d20 con 0x7f176404dba0
2012-12-30 02:11:13.033270 7f17637fe700 20 -- 10.3.64.22:6804/32728 submit_message osd_op(mds.0.1:60416 200.00000035 [write 475432~854] 1.20779f7e) v4 remote, 10.3.64.22:6800/32705, have pipe.
2012-12-30 02:11:13.033320 7f176810c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).writer: state = open policy.server=0
2012-12-30 02:11:13.033351 7f17637fe700 10 -- 10.3.64.22:6804/32728 dispatch_throttle_release 28 to dispatch throttler 28/104857600
2012-12-30 02:11:13.033430 7f17637fe700 20 -- 10.3.64.22:6804/32728 done calling dispatch on 0x34c1a80
2012-12-30 02:11:13.033418 7f176810c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).writer encoding 60416 0x7f1764882d20 osd_op(mds.0.1:60416 200.00000035 [write 475432~854] 1.20779f7e) v4
2012-12-30 02:11:13.033717 7f176810c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).writer sending 60416 0x7f1764882d20
2012-12-30 02:11:13.033741 7f176810c700 10 sign_message: seq # 60416 CRCs are: header 923201328 front 2647792622 middle 0 data 1008856504
2012-12-30 02:11:13.033860 7f176810c700 20 Putting signature in client message(seq # 60416): sig = 5802819893737233050
2012-12-30 02:11:13.033876 7f176810c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).Put signature in client message (seq # 60416): sig = 5802819893737233050
2012-12-30 02:11:13.033890 7f176810c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).write_message 0x7f1764882d20
2012-12-30 02:11:13.033899 7f176810c700 30 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1). bl_pos 0 b_off 0 leftinchunk 1005 buffer len 151 writing 151
2012-12-30 02:11:13.033907 7f176810c700 30 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1). bl_pos 151 b_off 0 leftinchunk 854 buffer len 4 writing 4
2012-12-30 02:11:13.033914 7f176810c700 30 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1). bl_pos 155 b_off 0 leftinchunk 850 buffer len 179 writing 179
2012-12-30 02:11:13.033922 7f176810c700 30 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1). bl_pos 334 b_off 0 leftinchunk 671 buffer len 4 writing 4
2012-12-30 02:11:13.033928 7f176810c700 30 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1). bl_pos 338 b_off 0 leftinchunk 667 buffer len 276 writing 276
2012-12-30 02:11:13.033936 7f176810c700 30 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1). bl_pos 614 b_off 0 leftinchunk 391 buffer len 12 writing 12
2012-12-30 02:11:13.033943 7f176810c700 30 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1). bl_pos 626 b_off 0 leftinchunk 379 buffer len 230 writing 230
2012-12-30 02:11:13.033950 7f176810c700 30 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1). bl_pos 856 b_off 0 leftinchunk 149 buffer len 12 writing 12
2012-12-30 02:11:13.033957 7f176810c700 30 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1). bl_pos 868 b_off 0 leftinchunk 137 buffer len 137 writing 137
2012-12-30 02:11:13.034023 7f176810c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).writer: state = open policy.server=0
2012-12-30 02:11:13.034042 7f176810c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).writer sleeping
2012-12-30 02:11:13.038810 7f1760ff9700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).reader got ACK
2012-12-30 02:11:13.038859 7f1760ff9700 15 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).reader got ack seq 60416
2012-12-30 02:11:13.038872 7f1760ff9700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).reader reading tag...
2012-12-30 02:11:13.038905 7f1760ff9700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).reader got MSG
2012-12-30 02:11:13.038932 7f1760ff9700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).reader got envelope type=43 src osd.0 front=111 data=0 off 0
2012-12-30 02:11:13.038958 7f1760ff9700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).reader wants 111 from dispatch throttler 0/104857600
2012-12-30 02:11:13.039006 7f1760ff9700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).reader got front 111
2012-12-30 02:11:13.039021 7f1760ff9700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).aborted = 0
2012-12-30 02:11:13.039029 7f1760ff9700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).reader got 111 + 0 + 0 byte message
2012-12-30 02:11:13.039107 7f1760ff9700 10 check_message_signature: seq # = 60416 front_crc_ = 2822794530 middle_crc = 0 data_crc = 0
2012-12-30 02:11:13.039220 7f1760ff9700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).reader got message 60416 0x7f175ce68c80 osd_op_reply(60416 200.00000035 [write 475432~854] ondisk = 0) v4
2012-12-30 02:11:13.039256 7f1760ff9700 20 -- 10.3.64.22:6804/32728 queue 0x7f175ce68c80 prio 127
2012-12-30 02:11:13.039298 7f1760ff9700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).reader reading tag...
2012-12-30 02:11:13.039302 7f176810c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).writer: state = open policy.server=0
2012-12-30 02:11:13.039326 7f176810c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).write_ack 60416
2012-12-30 02:11:13.039309 7f17637fe700 1 -- 10.3.64.22:6804/32728 <== osd.0 10.3.64.22:6800/32705 60416 ==== osd_op_reply(60416 200.00000035 [write 475432~854] ondisk = 0) v4 ==== 111+0+0 (2822794530 0 0) 0x7f175ce68c80 con 0x7f176404dba0
2012-12-30 02:11:13.039373 7f176810c700 10 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).writer: state = open policy.server=0
2012-12-30 02:11:13.039393 7f176810c700 20 -- 10.3.64.22:6804/32728 >> 10.3.64.22:6800/32705 pipe(0x7f176404d610 sd=17 :51690 pgs=2 cs=1 l=1).writer sleeping
2012-12-30 02:11:13.039502 7f17637fe700 10 mds.0.server _session_logged *client.4150* 10.3.64.22:0/1002076 state_seq 5 open 113620
Actions