osd.3 and osd.5 are both running 0.94.1-111-gb69fb89 (a version of hammer).
2015-05-15 13:49:39.677006 7f41d9d5a700 10 osd.5 180 dequeue_op 0x5c08000 prio 127 cost 0 latency 0.000405 osd_sub_op(unknown.0.0:0 0.2e 0//0//-1 [scrub-reserve] v 0'0 snapset=0=[]:[] snapc=0=[]) v11 pg pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=1 lpr=165 pi=144-164/3 crt=0'0 active]
2015-05-15 13:49:39.677072 7f41d9d5a700 10 osd.5 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=1 lpr=165 pi=144-164/3 crt=0'0 active] handle_message: 0x5c08000
2015-05-15 13:49:39.677095 7f41d9d5a700 15 osd.5 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=1 lpr=165 pi=144-164/3 crt=0'0 active] do_sub_op osd_sub_op(unknown.0.0:0 0.2e 0//0//-1 [scrub-reserve] v 0'0 snapset=0=[]:[] snapc=0=[]) v11
2015-05-15 13:49:39.677134 7f41d9d5a700 7 osd.5 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=1 lpr=165 pi=144-164/3 crt=0'0 active] sub_op_scrub_reserve
2015-05-15 13:49:39.676088 7f2ee2e40700 20 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean] sched_scrub: reserved locally, reserving replicas
2015-05-15 13:49:39.676120 7f2ee2e40700 10 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean] scrub requesting reserve from osd.2
2015-05-15 13:49:39.676212 7f2ee2e40700 10 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean] scrub requesting reserve from osd.5
2015-05-15 13:49:39.676291 7f2ee2e40700 20 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean] sched_scrub: reserved 3, waiting for replicas
2015-05-15 13:49:39.678028 7f2ecec8d700 10 osd.3 180 dequeue_op 0x8fce400 prio 127 cost 1 latency 0.000518 osd_sub_op_reply(unknown.0.0:0 0.2e 0//0//0 [scrub-reserve] ack, result = 0) v2 pg pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean]
2015-05-15 13:49:39.678100 7f2ecec8d700 10 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean] handle_message: 0x8fce400
2015-05-15 13:49:39.678132 7f2ecec8d700 7 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean] sub_op_scrub_reserve_reply
2015-05-15 13:49:39.678198 7f2ecec8d700 10 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean] osd.5 scrub reserve = success
2015-05-15 13:49:39.678230 7f2ecec8d700 20 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean] sched_scrub: reserved 3,5, waiting for replicas
2015-05-15 13:49:39.680833 7f2ed1492700 10 osd.3 180 dequeue_op 0x65ee600 prio 127 cost 1 latency 0.003395 osd_sub_op_reply(unknown.0.0:0 0.2e 0//0//0 [scrub-reserve] ack, result = 0) v2 pg pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean]
2015-05-15 13:49:39.680906 7f2ed1492700 10 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean] handle_message: 0x65ee600
2015-05-15 13:49:39.680934 7f2ed1492700 7 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean] sub_op_scrub_reserve_reply
2015-05-15 13:49:39.680978 7f2ed1492700 10 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean] osd.2 scrub reserve = success
2015-05-15 13:49:39.681007 7f2ed1492700 20 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean] sched_scrub: success, reserved self and replicas
2015-05-15 13:50:03.670169 7f41eb708700 -1 osd.5 180 heartbeat_check: no reply from osd.3 since back 2015-05-15 13:49:36.121526 front 2015-05-15 13:49:36.121526 (cutoff 2015-05-15 13:49:43.670166)
2015-05-15 13:50:05.453118 7f41dad5c700 10 osd.5 pg_epoch: 181 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [5,2] r=0 lpr=181 pi=144-180/4 crt=0'0 mlcod 0'0 active] start_peering_interval: check_new_interval output: generate_past_intervals interval(165-180 up [3,5,2](3) acting [3,5,2](3)): not rw, up_thru 172 up_from 6 last_epoch_clean 176
generate_past_intervals interval(165-180 up [3,5,2](3) acting [3,5,2](3) maybe_went_rw) : primary up 6-172 includes interval
2015-05-15 13:50:10.526044 7f2ecc488700 20 osd.3 pg_epoch: 180 pg[0.2e( empty local-les=171 n=0 ec=1 les/c 171/176 165/165/153) [3,5,2] r=0 lpr=165 crt=0'0 mlcod 0'0 active+clean+scrubbing] OSD 5 does not support chunky scrubs, falling back to classic
The scenario here is that we are getting an incorrect set of features back from the Connection. We can remove the code checking for the CEPH_FEATURE_CHUNKY_SCRUB because any connecting osd must have it set. However, I want to understand the use of get_con_osd_cluster() to get information about a specific remote peer. I infer from the results of has_feature() and that osd.5 wasn't getting ping responses from osd.3 several things. We see that osd.5 was advancing to epoch 181 with osd.3 out. So should get_con_osd_cluster() have checked is_down(self) or is_out(self) or does the caller need to before trusting information from the returned connection?