Ceph

primary:

2012-06-22 22:24:34.191990 7f591c2dd700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.191922, event: header_read, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192014 7f591c2dd700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.191923, event: throttled, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192028 7f591c2dd700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.191939, event: all_read, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192032 7f591c2dd700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.191984, event: dispatched, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192037 7f591c2dd700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.192037, event: waiting_for_osdmap, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192063 7f591c2dd700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.192058, event: queued_for_pg, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192087 7f59190d5700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.192087, event: reached_pg, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192223 7f59190d5700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.192223, event: started, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192267 7f59190d5700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.192267, event: started, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192434 7f59190d5700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.192434, event: sub_op_sent, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192487 7f59190d5700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.192487, event: sub_op_sent, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192667 7f59190d5700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.192666, event: commit_queued_for_journal_write, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192716 7f5920ae6700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.192716, event: write_thread_in_journal_buffer, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192886 7f5920ae6700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.192885, event: journaled_completion_queued, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.192943 7f591d2df700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.192942, event: op_commit, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.193918 7f591badc700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394516, time: 2012-06-22 22:24:34.193863, event: header_read, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:24:34.193930 7f591badc700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394516, time: 2012-06-22 22:24:34.193864, event: throttled, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:24:34.193935 7f591badc700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394516, time: 2012-06-22 22:24:34.193873, event: all_read, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:24:34.193939 7f591badc700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394516, time: 2012-06-22 22:24:34.193915, event: dispatched, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:24:34.193944 7f591badc700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394516, time: 2012-06-22 22:24:34.193943, event: waiting_for_osdmap, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:24:34.193957 7f591badc700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394516, time: 2012-06-22 22:24:34.193956, event: queued_for_pg, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:24:34.193970 7f59188d4700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394516, time: 2012-06-22 22:24:34.193969, event: reached_pg, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:24:34.193983 7f59188d4700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394516, time: 2012-06-22 22:24:34.193983, event: started, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:24:34.193989 7f59188d4700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.193989, event: sub_op_commit_rec, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:24:34.193998 7f59188d4700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394516, time: 2012-06-22 22:24:34.193997, event: done, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:24:34.223450 7f591dae0700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:24:34.223449, event: op_applied, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:25:05.068186 7f5923aec700  0 log [WRN] : old request osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4 received at 2012-06-22 22:24:34.191922 currently waiting for sub ops
2012-06-22 22:25:35.073148 7f5923aec700  0 log [WRN] : old request osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4 received at 2012-06-22 22:24:34.191922 currently waiting for sub ops
2012-06-22 22:26:35.082525 7f5923aec700  0 log [WRN] : old request osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4 received at 2012-06-22 22:24:34.191922 currently waiting for sub ops
2012-06-22 22:27:19.776699 7f591badc700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394538, time: 2012-06-22 22:27:19.776658, event: header_read, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:27:19.776719 7f591badc700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394538, time: 2012-06-22 22:27:19.776659, event: throttled, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:27:19.776724 7f591badc700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394538, time: 2012-06-22 22:27:19.776668, event: all_read, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:27:19.776728 7f591badc700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394538, time: 2012-06-22 22:27:19.776696, event: dispatched, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:27:19.776745 7f591badc700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394538, time: 2012-06-22 22:27:19.776745, event: waiting_for_osdmap, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:27:19.776759 7f591badc700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394538, time: 2012-06-22 22:27:19.776759, event: queued_for_pg, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:27:19.776787 7f59188d4700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394538, time: 2012-06-22 22:27:19.776787, event: reached_pg, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:27:19.776804 7f59188d4700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394538, time: 2012-06-22 22:27:19.776804, event: started, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1
2012-06-22 22:27:19.776810 7f59188d4700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:27:19.776810, event: sub_op_commit_rec, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:27:19.776858 7f59188d4700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 394515, time: 2012-06-22 22:27:19.776858, event: done, request: osd_op(client.743671.0:14775700 .dir.743671.114383 [create 0~0,call rgw.bucket_init_index] 5.bb9279d5) v4
2012-06-22 22:27:19.776870 7f59188d4700  5 --OSD::tracker-- reqid: unknown.0.0:0, seq: 394538, time: 2012-06-22 22:27:19.776870, event: done, request: osd_sub_op_reply(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] ondisk, result = 0) v1

replica:

2012-06-22 22:24:34.208755 7f0d4b258700  0 -- [2607:f298:4:3243::6342]:6800/17872 >> [2607:f298:4:3243::7057]:6846/45821 pipe(0x4f5f500 sd=583 pgs=0 cs=0 l=0).accept connect_seq 204 vs existing 204 state 1
...
2012-06-22 22:27:19.777965 7f0d6c71e700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.777448, event: header_read, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.778014 7f0d6c71e700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.777449, event: throttled, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.778025 7f0d6c71e700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.777832, event: all_read, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.778034 7f0d6c71e700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.777956, event: dispatched, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.778044 7f0d6c71e700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.778043, event: waiting_for_osdmap, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.778102 7f0d6c71e700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.778102, event: queued_for_pg, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.778210 7f0d69e18700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.778210, event: reached_pg, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.778252 7f0d69e18700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.778251, event: started, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.778335 7f0d69e18700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.778335, event: commit_queued_for_journal_write, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.778503 7f0d71728700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.778502, event: write_thread_in_journal_buffer, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.779134 7f0d71728700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.779133, event: journaled_completion_queued, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.779510 7f0d6df21700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.779509, event: sub_op_commit, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.780413 7f0d6e722700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.780412, event: sub_op_applied, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6
2012-06-22 22:27:19.780458 7f0d6e722700  5 --OSD::tracker-- reqid: client.743671.0:14775700, seq: 325419, time: 2012-06-22 22:27:19.780457, event: done, request: osd_sub_op(client.743671.0:14775700 5.79d5 bb9279d5/.dir.743671.114383/head [] v 36105'580 snapset=0=[]:[] snapc=0=[]) v6