Project

General

Profile

Actions
Copy link

Bug #7051

closed

mon: features aren't passed along for forwarded requests

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

Status:
Resolved
Priority:
Urgent
Assignee:
Joao Eduardo Luis
Category:
Monitor
Target version:
-
% Done:

0%

Source:
Q/A
Tags:
Backport:
Regression:
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

I thought this was implemented but it isn't. This is breaking the osd feature info in the OSDMap when the MOSDBoot request is forwarded.

need to add a features field to MForward, fill it in in Monitor.cc anywhere we create that message, and fill in the fake Connection's field in Monitor::handle_forward()

Actions
Copy link
 #1

Updated by Loïc Dachary over 10 years ago

I tried to reproduce the problem but could not. Using a 2 mon cluster created with vstart.sh and sending the osd pool create of type erasure to the peon succeeded and the message was handled by Monitor::handle_forward

2013-12-22 12:09:26.450150 7fcbe13f5700 10 mon.a@0(leader) e1  mesg 0x32d6b40 from 127.0.0.1:6790/0
2013-12-22 12:09:26.450153 7fcbe13f5700 20 mon.a@0(leader) e1 have connection
2013-12-22 12:09:26.450154 7fcbe13f5700 20 mon.a@0(leader) e1 ms_dispatch existing session MonSession: client.4099 :/0 is openallow * for client.4099 :/0
2013-12-22 12:09:26.450157 7fcbe13f5700 20 mon.a@0(leader) e1  caps allow *
2013-12-22 12:09:26.450287 7fcbe13f5700  0 mon.a@0(leader) e1 handle_command mon_command({"pool_type": "erasure", "prefix": "osd pool create", "pg_num": 12, "pool": "foo", "pgp_num": 12} v 0) v1
2013-12-22 12:09:26.450349 7fcbe13f5700 20 is_capable service=osd command=osd pool create read write on cap allow *
2013-12-22 12:09:26.450353 7fcbe13f5700 20  allow so far , doing grant allow *
2013-12-22 12:09:26.450355 7fcbe13f5700 20  allow all
2013-12-22 12:09:26.450356 7fcbe13f5700 10 mon.a@0(leader) e1 _allowed_command capable
2013-12-22 12:09:26.450365 7fcbe13f5700  1 mon.a@0(leader).paxos(paxos active c 1..49) is_readable now=2013-12-22 12:09:26.450366 lease_expire=2013-12-22 12:09:31.027196 has v0 lc 49
2013-12-22 12:09:26.450376 7fcbe13f5700 10 mon.a@0(leader).osd e9 preprocess_query mon_command({"pool_type": "erasure", "prefix": "osd pool create", "pg_num": 12, "pool": "foo", "pgp_num": 12} v 0) v1 from client.4099 127.0.0.1:0/1005410
2013-12-22 12:09:26.450519 7fcbe13f5700  7 mon.a@0(leader).osd e9 prepare_update mon_command({"pool_type": "erasure", "prefix": "osd pool create", "pg_num": 12, "pool": "foo", "pgp_num": 12} v 0) v1 from client.4099 127.0.0.1:0/1005410
2013-12-22 12:09:26.450691 7fcbe13f5700 10 mon.a@0(leader).osd e9 should_propose
2013-12-22 12:09:26.450719 7fcbe13f5700 10 -- 127.0.0.1:6789/0 dispatch_throttle_release 387 to dispatch throttler 387/104857600
2013-12-22 12:09:26.450729 7fcbe13f5700 20 -- 127.0.0.1:6789/0 done calling dispatch on 0x3688f00
2013-12-22 12:09:26.450740 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer: state = open policy.server=0
2013-12-22 12:09:26.450750 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).write_ack 162
2013-12-22 12:09:26.450761 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer: state = open policy.server=0
2013-12-22 12:09:26.450769 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer sleeping
2013-12-22 12:09:26.500804 7fcbe1c46700 10 mon.a@0(leader).osd e9 encode_pending e 10
2013-12-22 12:09:26.508399 7fcbe1c46700  1 -- 127.0.0.1:6789/0 --> mon.1 127.0.0.1:6790/0 -- paxos(begin lc 49 fc 0 pn 200 opn 0) v3 -- ?+0 0x3515400
2013-12-22 12:09:26.508432 7fcbe1c46700 20 -- 127.0.0.1:6789/0 submit_message paxos(begin lc 49 fc 0 pn 200 opn 0) v3 remote, 127.0.0.1:6790/0, have pipe.
2013-12-22 12:09:26.508464 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer: state = open policy.server=0
2013-12-22 12:09:26.508480 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer encoding 212 features 549755813887 0x3515400 paxos(begin lc 49 fc 0 pn 200 opn 0) v3
2013-12-22 12:09:26.508512 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer no session security
2013-12-22 12:09:26.508524 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer sending 212 0x3515400
2013-12-22 12:09:26.508532 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 0 b_off 0 leftinchunk 470 buffer len 92 writing 92
2013-12-22 12:09:26.508540 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 92 b_off 0 leftinchunk 378 buffer len 37 writing 37
2013-12-22 12:09:26.508547 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 129 b_off 0 leftinchunk 341 buffer len 286 writing 286
2013-12-22 12:09:26.508555 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 415 b_off 0 leftinchunk 55 buffer len 43 writing 43
2013-12-22 12:09:26.508562 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 458 b_off 0 leftinchunk 12 buffer len 8 writing 8
2013-12-22 12:09:26.508570 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 466 b_off 0 leftinchunk 4 buffer len 4 writing 4
2013-12-22 12:09:26.508614 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer: state = open policy.server=0
2013-12-22 12:09:26.508628 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer sleeping
2013-12-22 12:09:26.514086 7fcbdfb02700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got ACK
2013-12-22 12:09:26.514101 7fcbdfb02700 15 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got ack seq 212
2013-12-22 12:09:26.514111 7fcbdfb02700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got ack seq 212 >= 212 on 0x3515400 paxos(begin lc 49 fc 0 pn 200 opn 0) v3
2013-12-22 12:09:26.514128 7fcbdfb02700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader reading tag...
2013-12-22 12:09:26.514137 7fcbdfb02700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got MSG
2013-12-22 12:09:26.514143 7fcbdfb02700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got envelope type=66 src mon.1 front=80 data=0 off 0
2013-12-22 12:09:26.514148 7fcbdfb02700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader wants 80 from dispatch throttler 0/104857600
2013-12-22 12:09:26.514156 7fcbdfb02700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got front 80
2013-12-22 12:09:26.514162 7fcbdfb02700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).aborted = 0
2013-12-22 12:09:26.514165 7fcbdfb02700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got 80 + 0 + 0 byte message
2013-12-22 12:09:26.514175 7fcbdfb02700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).No session security set
2013-12-22 12:09:26.514183 7fcbdfb02700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got message 163 0x3515400 paxos(accept lc 49 fc 0 pn 200 opn 0) v3
2013-12-22 12:09:26.514192 7fcbdfb02700 20 -- 127.0.0.1:6789/0 queue 0x3515400 prio 196
2013-12-22 12:09:26.514202 7fcbdfb02700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader reading tag...
2013-12-22 12:09:26.514204 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer: state = open policy.server=0
2013-12-22 12:09:26.514213 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).write_ack 163
2013-12-22 12:09:26.514223 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer: state = open policy.server=0
2013-12-22 12:09:26.514224 7fcbe13f5700  1 -- 127.0.0.1:6789/0 <== mon.1 127.0.0.1:6790/0 163 ==== paxos(accept lc 49 fc 0 pn 200 opn 0) v3 ==== 80+0+0 (2206887093 0 0) 0x3515400 con 0x3247080
2013-12-22 12:09:26.514230 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer sleeping
2013-12-22 12:09:26.514235 7fcbe13f5700 20 mon.a@0(leader) e1 have connection
2013-12-22 12:09:26.514238 7fcbe13f5700 20 mon.a@0(leader) e1 ms_dispatch existing session MonSession: mon.1 127.0.0.1:6790/0 is openallow * for mon.1 127.0.0.1:6790/0
2013-12-22 12:09:26.514245 7fcbe13f5700 20 mon.a@0(leader) e1  caps allow *
2013-12-22 12:09:26.514248 7fcbe13f5700 20 is_capable service=mon command= exec on cap allow *
2013-12-22 12:09:26.514249 7fcbe13f5700 20  allow so far , doing grant allow *
2013-12-22 12:09:26.514250 7fcbe13f5700 20  allow all
2013-12-22 12:09:26.519204 7fcbe13f5700  1 -- 127.0.0.1:6789/0 --> mon.1 127.0.0.1:6790/0 -- paxos(commit lc 50 fc 0 pn 200 opn 0) v3 -- ?+0 0x3688f00
2013-12-22 12:09:26.519218 7fcbe13f5700 20 -- 127.0.0.1:6789/0 submit_message paxos(commit lc 50 fc 0 pn 200 opn 0) v3 remote, 127.0.0.1:6790/0, have pipe.
2013-12-22 12:09:26.519249 7fcbe13f5700 10 mon.a@0(leader) e1 refresh_from_paxos
2013-12-22 12:09:26.519257 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer: state = open policy.server=0
2013-12-22 12:09:26.519271 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer encoding 213 features 549755813887 0x3688f00 paxos(commit lc 50 fc 0 pn 200 opn 0) v3
2013-12-22 12:09:26.519292 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer no session security
2013-12-22 12:09:26.519303 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer sending 213 0x3688f00
2013-12-22 12:09:26.519311 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 0 b_off 0 leftinchunk 470 buffer len 92 writing 92
2013-12-22 12:09:26.519319 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 92 b_off 0 leftinchunk 378 buffer len 37 writing 37
2013-12-22 12:09:26.519327 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 129 b_off 0 leftinchunk 341 buffer len 286 writing 286
2013-12-22 12:09:26.519346 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 415 b_off 0 leftinchunk 55 buffer len 43 writing 43
2013-12-22 12:09:26.519355 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 458 b_off 0 leftinchunk 12 buffer len 8 writing 8
2013-12-22 12:09:26.519361 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 466 b_off 0 leftinchunk 4 buffer len 4 writing 4
2013-12-22 12:09:26.519385 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer: state = open policy.server=0
2013-12-22 12:09:26.519391 7fcbe13f5700 15 mon.a@0(leader).osd e9 update_from_paxos paxos e 10, my e 9
2013-12-22 12:09:26.519394 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer sleeping
2013-12-22 12:09:26.519448 7fcbe13f5700  7 mon.a@0(leader).osd e9 update_from_paxos  applying incremental 10
2013-12-22 12:09:26.519602 7fcbe13f5700  1 mon.a@0(leader).osd e10 e10: 3 osds: 3 up, 3 in
2013-12-22 12:09:26.522878 7fcbe13f5700 10 mon.a@0(leader).pg v16 check_osd_map -- osdmap not readable, waiting
2013-12-22 12:09:26.522887 7fcbe13f5700 10 mon.a@0(leader).osd e10 check_subs
2013-12-22 12:09:26.522895 7fcbe13f5700 10 mon.a@0(leader).osd e10 committed, telling random osd.1 127.0.0.1:6808/5039 all about it
2013-12-22 12:09:26.522903 7fcbe13f5700 10 mon.a@0(leader).osd e10 build_incremental [9..10]
2013-12-22 12:09:26.522927 7fcbe13f5700 20 mon.a@0(leader).osd e10 build_incremental    inc 10 286 bytes
2013-12-22 12:09:26.522950 7fcbe13f5700 20 mon.a@0(leader).osd e10 build_incremental    inc 9 152 bytes
2013-12-22 12:09:26.522956 7fcbe13f5700  1 -- 127.0.0.1:6789/0 --> osd.1 127.0.0.1:6808/5039 -- osd_map(9..10 src has 1..10) v3 -- ?+0 0x3235cc0
2013-12-22 12:09:26.522969 7fcbe13f5700 20 -- 127.0.0.1:6789/0 submit_message osd_map(9..10 src has 1..10) v3 remote, 127.0.0.1:6808/5039, have pipe.
2013-12-22 12:09:26.522982 7fcbe13f5700 10 mon.a@0(leader).osd e10 update_logger
2013-12-22 12:09:26.522993 7fcbe13f5700  0 mon.a@0(leader).osd e10 crush map has features 275985465344, adjusting msgr requires
2013-12-22 12:09:26.522998 7fcbe13f5700  0 mon.a@0(leader).osd e10 crush map has features 275985465344, adjusting msgr requires
2013-12-22 12:09:26.523003 7fcbe13f5700  0 mon.a@0(leader).osd e10 crush map has features 275985465344, adjusting msgr requires
2013-12-22 12:09:26.523007 7fcbe13f5700  0 mon.a@0(leader).osd e10 crush map has features 275985465344, adjusting msgr requires
2013-12-22 12:09:26.523057 7fcbe13f5700 10 mon.a@0(leader).log v17 update_from_paxos
2013-12-22 12:09:26.523061 7fcbe13f5700 10 mon.a@0(leader).log v17 update_from_paxos version 17 summary v 17
2013-12-22 12:09:26.523153 7fcbe13f5700 10 mon.a@0(leader).auth v5 update_from_paxos
2013-12-22 12:09:26.523158 7fcbe13f5700 10 mon.a@0(leader).pg v16 map_pg_creates to 0 pgs osdmap epoch 10
2013-12-22 12:09:26.523162 7fcbe13f5700 10 mon.a@0(leader).pg v16 send_pg_creates to 0 pgs
2013-12-22 12:09:26.523185 7fcbe13f5700 10 mon.a@0(leader).osd e10 create_pending e 11
2013-12-22 12:09:26.523189 7fcbe13f5700 10 mon.a@0(leader).osd e10 remove_redundant_pg_temp
2013-12-22 12:09:26.523192 7fcbe13f5700 10 mon.a@0(leader).osd e10 remove_down_pg_temp
2013-12-22 12:09:26.523223 7fcbe13f5700 15 mon.a@0(leader) e1 send_reply routing reply to 127.0.0.1:0/1005410 via 127.0.0.1:6790/0 for request mon_command({"pool_type": "erasure", "prefix": "osd pool create", "pg_num": 12, "pool": "foo", "pgp_num": 12} v 0) v1
2013-12-22 12:09:26.523235 7fcbe13f5700  1 -- 127.0.0.1:6789/0 --> 127.0.0.1:6790/0 -- route(mon_command_ack([{"pool_type": "erasure", "prefix": "osd pool create", "pg_num": 12, "pool": "foo", "pgp_num": 12}]=0 pool 'foo' created v9) v1 tid 4) v2 -- ?+0 0x32338c0 con 0x3247080
2013-12-22 12:09:26.523244 7fcbe13f5700 20 -- 127.0.0.1:6789/0 submit_message route(mon_command_ack([{"pool_type": "erasure", "prefix": "osd pool create", "pg_num": 12, "pool": "foo", "pgp_num": 12}]=0 pool 'foo' created v9) v1 tid 4) v2 remote, 127.0.0.1:6790/0, have pipe.
2013-12-22 12:09:26.523261 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer: state = open policy.server=0
2013-12-22 12:09:26.523265 7fcbe13f5700  1 mon.a@0(leader).paxos(paxos updating c 1..50) is_readable now=2013-12-22 12:09:26.523266 lease_expire=0.000000 has v0 lc 50
2013-12-22 12:09:26.523275 7fcbe13f5700 10 mon.a@0(leader).pg v16 check_osd_map -- osdmap not readable, waiting
2013-12-22 12:09:26.523277 7fcbe13f5700  1 mon.a@0(leader).paxos(paxos updating c 1..50) is_readable now=2013-12-22 12:09:26.523278 lease_expire=0.000000 has v0 lc 50
2013-12-22 12:09:26.523274 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer encoding 214 features 549755813887 0x32338c0 route(mon_command_ack([{"pool_type": "erasure", "prefix": "osd pool create", "pg_num": 12, "pool": "foo", "pgp_num": 12}]=0 pool 'foo' created v9) v1 tid 4) v2
2013-12-22 12:09:26.523285 7fcbe13f5700 10 mon.a@0(leader).osd e10 update_logger
2013-12-22 12:09:26.523294 7fcbe13f5700  0 log [INF] : osdmap e10: 3 osds: 3 up, 3 in
2013-12-22 12:09:26.523299 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer no session security
2013-12-22 12:09:26.523308 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer sending 214 0x32338c0
2013-12-22 12:09:26.523314 7fcbe13f5700  1 -- 127.0.0.1:6789/0 --> mon.0 127.0.0.1:6789/0 -- log(1 entries) v1 -- ?+0 0x3234880
2013-12-22 12:09:26.523315 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 0 b_off 0 leftinchunk 381 buffer len 224 writing 224
2013-12-22 12:09:26.523322 7fcbe13f5700 20 -- 127.0.0.1:6789/0 submit_message log(1 entries) v1 local
2013-12-22 12:09:26.523322 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 224 b_off 0 leftinchunk 157 buffer len 149 writing 149
2013-12-22 12:09:26.523329 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 373 b_off 0 leftinchunk 8 buffer len 8 writing 8
2013-12-22 12:09:26.523352 7fcbe13f5700  1 -- 127.0.0.1:6789/0 --> mon.1 127.0.0.1:6790/0 -- paxos(lease lc 50 fc 1 pn 0 opn 0) v3 -- ?+0 0x3515680
2013-12-22 12:09:26.523360 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer: state = open policy.server=0
2013-12-22 12:09:26.523368 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer sleeping
2013-12-22 12:09:26.523365 7fcbdfb02700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got ACK
2013-12-22 12:09:26.523369 7fcbdf4fc700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6808/5039 pipe(0x342ec80 sd=24 :6789 s=2 pgs=1 cs=1 l=1 c=0x3528dc0).writer: state = open policy.server=1
2013-12-22 12:09:26.523380 7fcbdfb02700 15 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got ack seq 213
2013-12-22 12:09:26.523380 7fcbdf4fc700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6808/5039 pipe(0x342ec80 sd=24 :6789 s=2 pgs=1 cs=1 l=1 c=0x3528dc0).writer encoding 24 features 549755813887 0x3235cc0 osd_map(9..10 src has 1..10) v3
2013-12-22 12:09:26.523388 7fcbdfb02700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got ack seq 213 >= 213 on 0x3688f00 paxos(commit lc 50 fc 0 pn 200 opn 0) v3
2013-12-22 12:09:26.523402 7fcbdf4fc700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6808/5039 pipe(0x342ec80 sd=24 :6789 s=2 pgs=1 cs=1 l=1 c=0x3528dc0).writer signed seq # 24): sig = 0
2013-12-22 12:09:26.523406 7fcbdfb02700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader reading tag...
2013-12-22 12:09:26.523412 7fcbdf4fc700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6808/5039 pipe(0x342ec80 sd=24 :6789 s=2 pgs=1 cs=1 l=1 c=0x3528dc0).writer sending 24 0x3235cc0
2013-12-22 12:09:26.523420 7fcbdf4fc700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6808/5039 pipe(0x342ec80 sd=24 :6789 s=2 pgs=1 cs=1 l=1 c=0x3528dc0). bl_pos 0 b_off 0 leftinchunk 486 buffer len 28 writing 28
2013-12-22 12:09:26.523427 7fcbdf4fc700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6808/5039 pipe(0x342ec80 sd=24 :6789 s=2 pgs=1 cs=1 l=1 c=0x3528dc0). bl_pos 28 b_off 0 leftinchunk 458 buffer len 152 writing 152
2013-12-22 12:09:26.523434 7fcbdf4fc700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6808/5039 pipe(0x342ec80 sd=24 :6789 s=2 pgs=1 cs=1 l=1 c=0x3528dc0). bl_pos 180 b_off 0 leftinchunk 306 buffer len 8 writing 8
2013-12-22 12:09:26.523441 7fcbdf4fc700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6808/5039 pipe(0x342ec80 sd=24 :6789 s=2 pgs=1 cs=1 l=1 c=0x3528dc0). bl_pos 188 b_off 0 leftinchunk 298 buffer len 286 writing 286
2013-12-22 12:09:26.523447 7fcbdf4fc700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6808/5039 pipe(0x342ec80 sd=24 :6789 s=2 pgs=1 cs=1 l=1 c=0x3528dc0). bl_pos 474 b_off 0 leftinchunk 12 buffer len 12 writing 12
2013-12-22 12:09:26.523480 7fcbdf4fc700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6808/5039 pipe(0x342ec80 sd=24 :6789 s=2 pgs=1 cs=1 l=1 c=0x3528dc0).writer: state = open policy.server=1
2013-12-22 12:09:26.523488 7fcbdf4fc700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6808/5039 pipe(0x342ec80 sd=24 :6789 s=2 pgs=1 cs=1 l=1 c=0x3528dc0).writer sleeping
2013-12-22 12:09:26.523498 7fcbe13f5700 20 -- 127.0.0.1:6789/0 submit_message paxos(lease lc 50 fc 1 pn 0 opn 0) v3 remote, 127.0.0.1:6790/0, have pipe.
2013-12-22 12:09:26.523517 7fcbe13f5700  1 mon.a@0(leader).paxos(paxos active c 1..50) is_readable now=2013-12-22 12:09:26.523519 lease_expire=2013-12-22 12:09:31.523348 has v0 lc 50
2013-12-22 12:09:26.523529 7fcbe13f5700 10 mon.a@0(leader).pg v16 check_osd_map applying osdmap e10 to pg_map
2013-12-22 12:09:26.523584 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs checking pg pools for osdmap epoch 10, last_pg_scan 1
2013-12-22 12:09:26.523590 7fcbe13f5700 10 mon.a@0(leader).pg v16  no change in pool 0 replicated size 3 min_size 1 crush_ruleset 0 object_hash rjenkins pg_num 8 pgp_num 8 last_change 1 owner 0 flags hashpspool crash_replay_interval 45
2013-12-22 12:09:26.523598 7fcbe13f5700 10 mon.a@0(leader).pg v16  no change in pool 1 replicated size 3 min_size 1 crush_ruleset 1 object_hash rjenkins pg_num 8 pgp_num 8 last_change 1 owner 0 flags hashpspool
2013-12-22 12:09:26.523604 7fcbe13f5700 10 mon.a@0(leader).pg v16  no change in pool 2 replicated size 3 min_size 1 crush_ruleset 2 object_hash rjenkins pg_num 8 pgp_num 8 last_change 1 owner 0 flags hashpspool
2013-12-22 12:09:26.523609 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs scanning pool 3 erasure size 3 min_size 1 crush_ruleset 0 object_hash rjenkins pg_num 12 pgp_num 12 last_change 10 owner 0 flags hashpspool
2013-12-22 12:09:26.523625 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs  will create 3.0
2013-12-22 12:09:26.523633 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs  will create 3.1
2013-12-22 12:09:26.523640 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs  will create 3.2
2013-12-22 12:09:26.523647 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs  will create 3.3
2013-12-22 12:09:26.523654 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs  will create 3.4
2013-12-22 12:09:26.523661 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs  will create 3.5
2013-12-22 12:09:26.523668 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs  will create 3.6
2013-12-22 12:09:26.523675 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs  will create 3.7
2013-12-22 12:09:26.523682 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs  will create 3.8
2013-12-22 12:09:26.523689 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs  will create 3.9
2013-12-22 12:09:26.523696 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs  will create 3.a
2013-12-22 12:09:26.523706 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs  will create 3.b
2013-12-22 12:09:26.523718 7fcbe13f5700 10 mon.a@0(leader).pg v16 register_new_pgs registered 12 new pgs, removed 0 uncreated pgs
2013-12-22 12:09:26.523723 7fcbe13f5700 10 mon.a@0(leader).pg v16 encode_pending v 17
2013-12-22 12:09:26.523803 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer: state = open policy.server=0
2013-12-22 12:09:26.523816 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer encoding 215 features 549755813887 0x3515680 paxos(lease lc 50 fc 1 pn 0 opn 0) v3
2013-12-22 12:09:26.523832 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer no session security
2013-12-22 12:09:26.523841 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer sending 215 0x3515680
2013-12-22 12:09:26.523849 7fcbe659c700 30 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080). bl_pos 0 b_off 0 leftinchunk 80 buffer len 80 writing 80
2013-12-22 12:09:26.523874 7fcbe659c700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer: state = open policy.server=0
2013-12-22 12:09:26.523883 7fcbe659c700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).writer sleeping
2013-12-22 12:09:26.523894 7fcbdfb02700 20 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got ACK
2013-12-22 12:09:26.523904 7fcbdfb02700 15 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got ack seq 214
2013-12-22 12:09:26.523911 7fcbdfb02700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6790/0 pipe(0x3288280 sd=21 :57541 s=2 pgs=2 cs=1 l=0 c=0x3247080).reader got ack seq 214 >= 214 on 0x32338c0 route(mon_command_ack([{"pool_type": "erasure", "prefix": "osd pool create", "pg_num": 12, "pool": "foo", "pgp_num": 12}]=0 pool 'foo' created v9) v1 tid 4) v2

Actions
Copy link
 #2

Updated by Joao Eduardo Luis over 10 years ago

  • Status changed from New to In Progress
  • Assignee set to Joao Eduardo Luis
Actions
Copy link
 #3

Updated by Joao Eduardo Luis over 10 years ago

  • Status changed from In Progress to Fix Under Review

Loic, you were attempting to reproduce it the wrong way.

This issue is triggered when a peon forwards an MOSDBoot message to the leader. Given we are relying on the message's connection features to track OSD supported features, this issue is only triggered when an OSD sends its boot message to a peon instead of sending it to the leader. In such case the peon will forward the MOSDBoot message to the leader but the connection features (m->get_connection()->get_features()) won't be populated, as it is a fake connection created for the purpose of handling the message (MOSDBoot) encapsulated in MForward.

I had a hard time reproducing it as well, until I magically started having a given osd always forwarding its boot message to a peon monitor. That allowed me to make sure the fix was working.

wip-7051, pull request https://github.com/ceph/ceph/pull/984

Actions
Copy link
 #4

Updated by Loïc Dachary over 10 years ago

Thanks for explaining, crystal clear now :-)

Actions
Copy link
 #5

Updated by Sage Weil over 10 years ago

  • Status changed from Fix Under Review to Resolved
Actions
Copy link

Also available in: Atom PDF