|
2014-07-03 10:00:24.603542 7fc565e69700 10 osd.1 132 new session 0x2ee0d80 con=0x46152c0 addr=10.214.134.38:0/3279519475
|
|
2014-07-03 10:00:24.603603 7fc565e69700 10 osd.1 132 session 0x2ee0d80 client.admin has caps osdcap[grant(*)] 'allow *'
|
|
2014-07-03 10:00:24.603990 7fc565e69700 1 -- 10.214.134.38:6810/3145 <== client.4234 10.214.134.38:0/3279519475 1 ==== osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4 ==== 162+0+0 (3398229483 0 0) 0x2ee0b40 con 0x46152c0
|
|
2014-07-03 10:00:24.604243 7fc565e69700 15 osd.1 132 enqueue_op 0x2e9af00 prio 127 cost 0 latency 0.000332 osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4
|
|
2014-07-03 10:00:24.604309 7fc565e69700 0 -- 10.214.134.38:6810/3145 >> 10.214.134.38:0/3279519475 pipe(0x4962280 sd=123 :6810 s=2 pgs=3 cs=1 l=1 c=0x46152c0).injecting socket failure
|
|
2014-07-03 10:00:24.604326 7fc570880700 10 osd.1 132 dequeue_op 0x2e9af00 prio 127 cost 0 latency 0.000415 osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4 pg pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean]
|
|
2014-07-03 10:00:24.604368 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] handle_message: 0x2e9af00
|
|
2014-07-03 10:00:24.604381 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] do_op osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4 may_write -> write-ordered flags ondisk+write
|
|
2014-07-03 10:00:24.604403 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] get_object_context: found obc in cache: 0x374f600
|
|
2014-07-03 10:00:24.604414 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] get_object_context: 0x374f600 c6ad1270/rbd_header.100d2c0e7506/head//3 rwstate(none n=0 w=0) oi: c6ad1270/rbd_header.100d2c0e7506/head//3(132'1915 client.4109.0:60415 wrlock_by=unknown.0.0:0 dirty|omap s 0 uv1913) ssc: 0x30e31c0 snapset: 0=[]:[]+head
|
|
2014-07-03 10:00:24.604433 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] find_object_context c6ad1270/rbd_header.100d2c0e7506/head//3 @head oi=c6ad1270/rbd_header.100d2c0e7506/head//3(132'1915 client.4109.0:60415 wrlock_by=unknown.0.0:0 dirty|omap s 0 uv1913)
|
|
2014-07-03 10:00:24.604462 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] execute_ctx 0x3d59800
|
|
2014-07-03 10:00:24.604484 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] do_op c6ad1270/rbd_header.100d2c0e7506/head//3 [watch add cookie 1 ver 0] ov 132'1915 av 132'1916 snapc 0=[] snapset 0=[]:[]+head
|
|
2014-07-03 10:00:24.604499 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] do_osd_op c6ad1270/rbd_header.100d2c0e7506/head//3 [watch add cookie 1 ver 0]
|
|
2014-07-03 10:00:24.604511 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] do_osd_op watch add cookie 1 ver 0
|
|
2014-07-03 10:00:24.604522 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] watch: ctx->obc=0x374f600 cookie=1 oi.version=1915 ctx->at_version=132'1916
|
|
2014-07-03 10:00:24.604533 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] watch: oi.user_version=1913
|
|
2014-07-03 10:00:24.604543 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] watch: peer_addr=10.214.134.38:0/3279519475
|
|
2014-07-03 10:00:24.604557 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] registered new watch watch(cookie 1 30s 10.214.134.38:0/3279519475) by client.4234
|
|
2014-07-03 10:00:24.604575 7fc570880700 15 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] do_osd_op_effects on session 0x2ee0d80
|
|
2014-07-03 10:00:24.604586 7fc570880700 15 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] do_osd_op_effects applying watch connect on session 0x2ee0d80 watcher 1,client.4234
|
|
2014-07-03 10:00:24.604597 7fc570880700 15 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] do_osd_op_effects new watcher 1,client.4234
|
|
2014-07-03 10:00:24.604608 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] -- Watch(1,client.4234) Watch()
|
|
2014-07-03 10:00:24.604622 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] -- Watch(1,client.4234) connecting
|
|
2014-07-03 10:00:24.604635 7fc570880700 15 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] -- Watch(1,client.4234) unregister_cb
|
|
2014-07-03 10:00:24.604651 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] set mtime to 2014-07-03 10:00:24.600026
|
|
2014-07-03 10:00:24.604678 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] final snapset 0=[]:[]+head in c6ad1270/rbd_header.100d2c0e7506/head//3
|
|
2014-07-03 10:00:24.604700 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] new_repop rep_tid 6410 on osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4
|
|
2014-07-03 10:00:24.604717 7fc570880700 7 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] issue_repop rep_tid 6410 o c6ad1270/rbd_header.100d2c0e7506/head//3
|
|
2014-07-03 10:00:24.604758 7fc570880700 1 -- 10.214.134.38:6811/3145 --> osd.2 10.214.134.38:6801/3144 -- osd_sub_op(client.4234.1:2 3.0 c6ad1270/rbd_header.100d2c0e7506/head//3 [] v 132'1916 snapset=0=[]:[] snapc=0=[]) v11 -- ?+1184 0x31a5c00
|
|
2014-07-03 10:00:24.604791 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1915 (0'0,132'1915] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] append_log log((0'0,132'1915], crt=132'1913) [132'1916 (132'1915) modify c6ad1270/rbd_header.100d2c0e7506/head//3 by client.4234.1:2 2014-07-03 10:00:24.600026]
|
|
2014-07-03 10:00:24.604814 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1913 lcod 132'1914 mlcod 132'1914 active+clean] add_log_entry 132'1916 (132'1915) modify c6ad1270/rbd_header.100d2c0e7506/head//3 by client.4234.1:2 2014-07-03 10:00:24.600026
|
|
2014-07-03 10:00:24.604837 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] append_log adding 1 keys
|
|
2014-07-03 10:00:24.604851 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] append_log: trimming to 132'1914 entries 132'1914 (132'1913) modify c6ad1270/rbd_header.100d2c0e7506/head//3 by client.4109.0:60406 2014-07-03 10:00:24.512372
|
|
2014-07-03 10:00:24.604895 7fc570880700 10 write_log with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, dirty_divergent_priors: 0, writeout_from: 132'1916, trimmed:
|
|
2014-07-03 10:00:24.607449 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] eval_repop repgather(0x2595780 132'1916 rep_tid=6410 committed?=0 applied?=0 lock=0 op=osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4) wants=d
|
|
2014-07-03 10:00:24.607476 7fc570880700 10 osd.1 132 dequeue_op 0x2e9af00 finish
|
|
2014-07-03 10:00:24.607495 7fc57b095700 1 osd.1 132 ms_handle_reset con 0x46152c0 session 0x2ee0d80
|
|
2014-07-03 10:00:24.607500 7fc57b095700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] -- Watch(1,client.4234) disconnect
|
|
2014-07-03 10:00:24.607515 7fc57b095700 15 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] -- Watch(1,client.4234) registering callback, timeout: 30
|
|
2014-07-03 10:00:24.608260 7fc56434f700 1 -- 10.214.134.38:6810/3145 >> :/0 pipe(0x4556780 sd=169 :6810 s=0 pgs=0 cs=0 l=0 c=0x3b919a0).accept sd=169 10.214.134.38:51040/0
|
|
2014-07-03 10:00:24.608347 7fc56434f700 0 -- 10.214.134.38:6810/3145 >> 10.214.134.38:0/3279519475 pipe(0x4556780 sd=169 :6810 s=0 pgs=0 cs=0 l=0 c=0x3b919a0).accept peer addr is really 10.214.134.38:0/3279519475 (socket is 10.214.134.38:51040/0)
|
|
2014-07-03 10:00:24.608521 7fc56434f700 10 osd.1 132 new session 0x2ee0480 con=0x3b919a0 addr=10.214.134.38:0/3279519475
|
|
2014-07-03 10:00:24.608599 7fc56434f700 10 osd.1 132 session 0x2ee0480 client.admin has caps osdcap[grant(*)] 'allow *'
|
|
2014-07-03 10:00:24.609102 7fc56434f700 1 -- 10.214.134.38:6810/3145 <== client.4234 10.214.134.38:0/3279519475 1 ==== osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4 ==== 162+0+0 (3398229483 0 0) 0x23b4240 con 0x3b919a0
|
|
2014-07-03 10:00:24.609324 7fc56434f700 15 osd.1 132 enqueue_op 0x2e9ab00 prio 127 cost 0 latency 0.000267 osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4
|
|
2014-07-03 10:00:24.609397 7fc56e07b700 10 osd.1 132 dequeue_op 0x2e9ab00 prio 127 cost 0 latency 0.000340 osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4 pg pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean]
|
|
2014-07-03 10:00:24.609468 7fc56e07b700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] handle_message: 0x2e9ab00
|
|
2014-07-03 10:00:24.609493 7fc56e07b700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] do_op osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4 may_write -> write-ordered flags ondisk+write
|
|
2014-07-03 10:00:24.609521 7fc56e07b700 3 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] do_op dup client.4234.1:2 was 132'1916
|
|
2014-07-03 10:00:24.609538 7fc56e07b700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] waiting for 132'1916 to commit
|
|
2014-07-03 10:00:24.609569 7fc56e07b700 10 osd.1 132 dequeue_op 0x2e9ab00 finish
|
|
2014-07-03 10:00:24.617327 7fc57d9c8700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] op_commit: 6410
|
|
2014-07-03 10:00:24.618050 7fc57e1c9700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] op_applied: 6410
|
|
2014-07-03 10:00:24.618108 7fc57e1c9700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] op_applied on primary on version 132'1916
|
|
2014-07-03 10:00:24.625000 7fc565c67700 1 -- 10.214.134.38:6811/3145 <== osd.2 10.214.134.38:6801/3144 11215 ==== osd_sub_op_reply(client.4234.1:2 3.0 c6ad1270/rbd_header.100d2c0e7506/head//3 [] ondisk, result = 0) v2 ==== 161+0+0 (1297969669 0 0) 0x31c4a00 con 0x241f6e0
|
|
2014-07-03 10:00:24.625051 7fc565c67700 10 osd.1 132 handle_replica_op osd_sub_op_reply(client.4234.1:2 3.0 c6ad1270/rbd_header.100d2c0e7506/head//3 [] ondisk, result = 0) v2 epoch 132
|
|
2014-07-03 10:00:24.625057 7fc565c67700 15 osd.1 132 enqueue_op 0x4975b00 prio 196 cost 0 latency 0.000100 osd_sub_op_reply(client.4234.1:2 3.0 c6ad1270/rbd_header.100d2c0e7506/head//3 [] ondisk, result = 0) v2
|
|
2014-07-03 10:00:24.625109 7fc570880700 10 osd.1 132 dequeue_op 0x4975b00 prio 196 cost 0 latency 0.000151 osd_sub_op_reply(client.4234.1:2 3.0 c6ad1270/rbd_header.100d2c0e7506/head//3 [] ondisk, result = 0) v2 pg pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean]
|
|
2014-07-03 10:00:24.625189 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] handle_message: 0x4975b00
|
|
2014-07-03 10:00:24.625239 7fc570880700 7 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] sub_op_modify_reply: tid 6410 op ack_type 4 from 2
|
|
2014-07-03 10:00:24.625298 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] repop_all_applied: repop tid 6410 all applied
|
|
2014-07-03 10:00:24.625324 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] eval_repop repgather(0x2595780 132'1916 rep_tid=6410 committed?=0 applied?=1 lock=0 op=osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4) wants=d
|
|
2014-07-03 10:00:24.625366 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 luod=132'1915 crt=132'1914 lcod 132'1914 mlcod 132'1914 active+clean] repop_all_committed: repop tid 6410 all committed
|
|
2014-07-03 10:00:24.625393 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1914 lcod 132'1915 mlcod 132'1914 active+clean] eval_repop repgather(0x2595780 132'1916 rep_tid=6410 committed?=1 applied?=1 lock=0 op=osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4) wants=d
|
|
2014-07-03 10:00:24.625432 7fc570880700 15 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1914 lcod 132'1915 mlcod 132'1914 active+clean] log_op_stats osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4 inb 37 outb 0 rlat 0.021453 lat 0.021518
|
|
2014-07-03 10:00:24.625471 7fc570880700 15 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1914 lcod 132'1915 mlcod 132'1914 active+clean] publish_stats_to_osd 132:24651
|
|
2014-07-03 10:00:24.625502 7fc570880700 1 -- 10.214.134.38:6810/3145 --> 10.214.134.38:0/3279519475 -- osd_op_reply(2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] v132'1916 uv1913 ondisk = 0) v6 -- ?+0 0x2fb1000 con 0x3b919a0
|
|
2014-07-03 10:00:24.625587 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1914 lcod 132'1915 mlcod 132'1914 active+clean] sending commit on repgather(0x2595780 132'1916 rep_tid=6410 committed?=1 applied?=1 lock=0 op=osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4) 0x3b74780
|
|
2014-07-03 10:00:24.625627 7fc570880700 1 -- 10.214.134.38:6810/3145 --> 10.214.134.38:0/3279519475 -- osd_op_reply(2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] v132'1916 uv1913 ondisk = 0) v6 -- ?+0 0x3b74780 con 0x46152c0
|
|
2014-07-03 10:00:24.625647 7fc570880700 0 -- 10.214.134.38:6810/3145 submit_message osd_op_reply(2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] v132'1916 uv1913 ondisk = 0) v6 remote, 10.214.134.38:0/3279519475, failed lossy con, dropping message 0x3b74780
|
|
2014-07-03 10:00:24.625691 7fc570880700 15 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1914 lcod 132'1915 mlcod 132'1914 active+clean] requeue_ops
|
|
2014-07-03 10:00:24.625719 7fc570880700 10 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1914 lcod 132'1915 mlcod 132'1915 active+clean] removing repgather(0x2595780 132'1916 rep_tid=6410 committed?=1 applied?=1 op=osd_op(client.4234.1:2 rbd_header.100d2c0e7506 [watch add cookie 1 ver 0] 3.c6ad1270 ondisk+write e132) v4)
|
|
2014-07-03 10:00:24.625754 7fc570880700 15 osd.1 pg_epoch: 132 pg[3.0( v 132'1916 (0'0,132'1916] local-les=7 n=221 ec=6 les/c 7/7 6/6/6) [1,2] r=0 lpr=6 crt=132'1914 lcod 132'1915 mlcod 132'1915 active+clean] requeue_ops
|
|
2014-07-03 10:00:24.625820 7fc570880700 10 osd.1 132 dequeue_op 0x4975b00 finish
|
|
2014-07-03 10:00:24.626056 7fc56434f700 1 -- 10.214.134.38:6810/3145 <== client.4234 10.214.134.38:0/3279519475 2 ==== osd_op(client.4234.1:3 rbd_header.100d2c0e7506 [call rbd.get_size] 3.c6ad1270 read e132) v4 ==== 162+0+19 (1712762158 0 2777843998) 0x2ee0240 con 0x3b919a0
|