Ceph » RADOS

This test shouldn't loop forever so that teuthology has to time-out. I'll fix that elsewhere.

The mon received the size change for test3 pool, but there is no corresponding handle_advance_map message at the OSD.

2019-02-13 02:33:07.069 7f13ef545700  0 log_channel(audit) log [INF] : from='client.? v1:127.0.0.1:0/1343403815' entity='client.admin' cmd='[{"var": "size", "prefix": "osd pool set" 
, "pool": "test3", "val": "2"}]': finished
2019-02-13 02:33:07.069 7f13ef545700  1 -- v2:127.0.0.1:7114/0 --> v2:127.0.0.1:7114/0 -- log(1 entries from seq 437 at 2019-02-13 02:33:07.070214) v1 -- 0x556c75b80b40 con 0x556c74
61e400
2019-02-13 02:33:07.069 7f13ef545700 20 -- v2:127.0.0.1:7114/0 >> v2:127.0.0.1:7114/0 conn(0x556c7461e400 msgr2=0x556c74620b00 :-1 s=STATE_NONE l=0).send_message log(1 entries from
seq 437 at 2019-02-13 02:33:07.070214) v1 local
2019-02-13 02:33:07.069 7f13ef545700  2 mon.a@0(leader) e1 send_reply 0x556c75aca1a0 0x556c75cd4a00 mon_command_ack([{"var": "size", "prefix": "osd pool set", "pool": "test3", "val" 
: "2"}]=0 set pool 3 size to 2 v105) v1
2019-02-13 02:33:07.069 7f13ef545700  1 -- v2:127.0.0.1:7114/0 --> v1:127.0.0.1:0/1343403815 -- mon_command_ack([{"var": "size", "prefix": "osd pool set", "pool": "test3", "val": "2
"}]=0 set pool 3 size to 2 v105) v1 -- 0x556c75cd4a00 con 0x556c76480c00
2019-02-13 02:33:07.069 7f13ef545700  5 --2- v2:127.0.0.1:7114/0 >> v1:127.0.0.1:0/1343403815 conn(0x556c76480c00 0x556c75bc3200 :-1 s=READY pgs=2 cs=0 l=1).send_message enqueueing
message m=0x556c75cd4a00 type=51 mon_command_ack([{"var": "size", "prefix": "osd pool set", "pool": "test3", "val": "2"}]=0 set pool 3 size to 2 v105) v1
2019-02-13 02:33:07.069 7f13ef545700 15 --2- v2:127.0.0.1:7114/0 >> v1:127.0.0.1:0/1343403815 conn(0x556c76480c00 0x556c75bc3200 :-1 s=READY pgs=2 cs=0 l=1).send_message inline writ
e is denied, reschedule m=0x556c75cd4a00
2019-02-13 02:33:07.069 7f13ef545700 20 Event(0x556c74627480 nevent=5000 time_id=169).wakeup
2019-02-13 02:33:07.069 7f13ef545700 10 mon.a@0(leader).osd e105 update_logger
2019-02-13 02:33:07.069 7f13ef545700  0 log_channel(cluster) log [DBG] : osdmap e105: 5 total, 5 up, 4 in
2019-02-13 02:33:07.069 7f13ef545700  1 -- v2:127.0.0.1:7114/0 --> v2:127.0.0.1:7114/0 -- log(1 entries from seq 438 at 2019-02-13 02:33:07.070249) v1 -- 0x556c75b80000 con 0x556c74
61e400
2019-02-13 02:33:07.069 7f13ef545700 20 -- v2:127.0.0.1:7114/0 >> v2:127.0.0.1:7114/0 conn(0x556c7461e400 msgr2=0x556c74620b00 :-1 s=STATE_NONE l=0).send_message log(1 entries from
seq 438 at 2019-02-13 02:33:07.070249) v1 local
2019-02-13 02:33:07.069 7f13ef545700 20 queue 0x556c75da91e0 1 [0,1)
2019-02-13 02:33:07.069 7f13ef545700 20 queue 0x556c75da91e0 3 [0,1)
2019-02-13 02:33:07.069 7f13ef545700 20 queue 0x556c75da91e0 7 [0,1)
2019-02-13 02:33:07.069 7f13ef545700 10 mon.a@0(leader).osd e105 start_mapping started mapping job 0x556c75da91e0 at 2019-02-13 02:33:07.070258
2019-02-13 02:33:07.069 7f13ef545700 20 mon.a@0(leader).paxos(paxos active c 1..479) finish_round waiting_for_readable
2019-02-13 02:33:07.069 7f13ef545700 20 mon.a@0(leader).paxos(paxos active c 1..479) finish_round waiting_for_writeable
2019-02-13 02:33:07.069 7f13ef545700 10 mon.a@0(leader).paxos(paxos active c 1..479) finish_round done w/ waiters, state active
2019-02-13 02:33:07.069 7f13ef545700 10 mon.a@0(leader).paxos(paxos active c 1..479) propose_pending 480 21476 bytes
2019-02-13 02:33:07.069 7f13ef545700 10 mon.a@0(leader).paxos(paxos updating c 1..479) begin for 480 21476 bytes

After this handle_advance_map there is none that shows the size increase.

2019-02-13 02:31:20.710 7f56306be700 10 osd.1 pg_epoch: 86 pg[3.0( empty local-lis/les=36/38 n=0 ec=33/33 lis/c 36/36 les/c/f 38/38/0 36/36/33) [1,2] r=0 lpr=36 crt=0'0 mlcod 0'0 active+clean] handle_advance_map [1]/[1] -- 1/1