Project

General

Profile

Bug #46381 » osd.24.debug_07061841.txt

osd error log - Amine Liu, 07/07/2020 06:41 AM

 
-273> 2020-07-06 18:40:14.306835 7f83a92be700 10 osd.24 45014 do_waiters -- start
-272> 2020-07-06 18:40:14.306840 7f83a92be700 10 osd.24 45014 do_waiters -- finish
-271> 2020-07-06 18:40:14.306842 7f83a92be700 20 osd.24 45014 _dispatch 0x7f83cef418c0 osd_map(45014..45014 src has 38101..45014) v3
-270> 2020-07-06 18:40:14.306852 7f83a92be700 3 osd.24.objecter handle_osd_map ignoring epochs [45014,45014] <= 45014
-269> 2020-07-06 18:40:14.306856 7f83a92be700 20 osd.24.objecter dump_active .. 0 homeless
-268> 2020-07-06 18:40:14.306862 7f83a92be700 3 osd.24 45014 handle_osd_map epochs [45014,45014], i have 45014, src has [38101,45014]
-267> 2020-07-06 18:40:14.306865 7f83a92be700 10 osd.24 45014 no new maps here, dropping
-266> 2020-07-06 18:40:14.306869 7f83a92be700 10 osd.24 45014 do_waiters -- start
-265> 2020-07-06 18:40:14.306871 7f83a92be700 10 osd.24 45014 do_waiters -- finish
-264> 2020-07-06 18:40:14.306874 7f83a92be700 10 osd.24 45014 do_waiters -- start
-263> 2020-07-06 18:40:14.306876 7f83a92be700 10 osd.24 45014 do_waiters -- finish
-262> 2020-07-06 18:40:14.306878 7f83a92be700 20 osd.24 45014 _dispatch 0x7f83cf0d8760 pg_notify(2.29(8) epoch 45014) v5
-261> 2020-07-06 18:40:14.306894 7f83a92be700 7 osd.24 45014 handle_pg_notify from osd.135
-260> 2020-07-06 18:40:14.306898 7f83a92be700 15 osd.24 45014 require_same_or_newer_map 45014 (i am 45014) 0x7f83cf0d8760
-259> 2020-07-06 18:40:14.306902 7f8389c90700 10 log is not dirty
-258> 2020-07-06 18:40:14.306942 7f83a92be700 10 osd.24 45014 do_waiters -- start
-257> 2020-07-06 18:40:14.306947 7f83a92be700 10 osd.24 45014 do_waiters -- finish
-256> 2020-07-06 18:40:14.306938 7f838ac92700 10 osd.24 pg_epoch: 45014 pg[2.29( v 24074'367 (0'0,24074'367] local-les=45014 n=78 ec=224 les/c/f 44999/44646/0 45012/45013/45013) [24,144,11] r=0 lpr=45013 pi=44298-45012/25 crt=24074'367 lcod 0'0 mlcod 0'0 activating+degraded] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 MNotifyRec from 135 notify: (query_epoch:45014, epoch_sent:45014, info:2.29( v 24074'367 (0'0,24074'367] local-les=44646 n=78 ec=224 les/c/f 44646/44646/0 45012/45013/45013)) features: 0x7ffffffefdfbfff
-255> 2020-07-06 18:40:14.306960 7f838ac92700 10 osd.24 pg_epoch: 45014 pg[2.29( v 24074'367 (0'0,24074'367] local-les=45014 n=78 ec=224 les/c/f 44999/44646/0 45012/45013/45013) [24,144,11] r=0 lpr=45013 pi=44298-45012/25 crt=24074'367 lcod 0'0 mlcod 0'0 activating+degraded] state<Started/Primary/Active>: Active: got notify from 135, already have info from that osd, ignoring
-254> 2020-07-06 18:40:14.306970 7f838ac92700 10 log is not dirty
-253> 2020-07-06 18:40:14.307580 7f83a8abd700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.197:6818/3452362 conn(0x7f83d0d9d000 sd=1494 :6805 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=96695 cs=1 l=0). == rx == osd.28 seq 5 0x7f83cf9b9200 osd_map(45014..45014 src has 38101..45014) v3
-252> 2020-07-06 18:40:14.307618 7f83a8abd700 10 osd.24 45014 do_waiters -- start
-251> 2020-07-06 18:40:14.307620 7f83a8abd700 10 osd.24 45014 do_waiters -- finish
-250> 2020-07-06 18:40:14.307622 7f83a8abd700 20 osd.24 45014 _dispatch 0x7f83cf9b9200 osd_map(45014..45014 src has 38101..45014) v3
-249> 2020-07-06 18:40:14.307628 7f83a8abd700 3 osd.24.objecter handle_osd_map ignoring epochs [45014,45014] <= 45014
-248> 2020-07-06 18:40:14.307631 7f83a8abd700 20 osd.24.objecter dump_active .. 0 homeless
-247> 2020-07-06 18:40:14.307634 7f83a8abd700 3 osd.24 45014 handle_osd_map epochs [45014,45014], i have 45014, src has [38101,45014]
-246> 2020-07-06 18:40:14.307637 7f83a8abd700 10 osd.24 45014 no new maps here, dropping
-245> 2020-07-06 18:40:14.307639 7f83a8abd700 10 osd.24 45014 do_waiters -- start
-244> 2020-07-06 18:40:14.307641 7f83a8abd700 10 osd.24 45014 do_waiters -- finish
-243> 2020-07-06 18:40:14.307698 7f83a8abd700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.197:6818/3452362 conn(0x7f83d0d9d000 sd=1494 :6805 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=96695 cs=1 l=0). == rx == osd.28 seq 6 0x7f83d1110760 pg_notify(1.42c(8) epoch 45014) v5
-242> 2020-07-06 18:40:14.307722 7f83a8abd700 10 osd.24 45014 do_waiters -- start
-241> 2020-07-06 18:40:14.307726 7f83a8abd700 10 osd.24 45014 do_waiters -- finish
-240> 2020-07-06 18:40:14.307727 7f83a8abd700 20 osd.24 45014 _dispatch 0x7f83d1110760 pg_notify(1.42c(8) epoch 45014) v5
-239> 2020-07-06 18:40:14.307732 7f83a8abd700 7 osd.24 45014 handle_pg_notify from osd.28
-238> 2020-07-06 18:40:14.307734 7f83a8abd700 15 osd.24 45014 require_same_or_newer_map 45014 (i am 45014) 0x7f83d1110760
-237> 2020-07-06 18:40:14.307785 7f83a8abd700 10 osd.24 45014 do_waiters -- start
-236> 2020-07-06 18:40:14.307788 7f83a8abd700 10 osd.24 45014 do_waiters -- finish
-235> 2020-07-06 18:40:14.307785 7f838cc96700 10 osd.24 pg_epoch: 45014 pg[1.42c( v 44756'19846432 lc 44133'19846430 (33550'19843351,44756'19846432] local-les=44999 n=5552 ec=30458 les/c/f 44999/44790/0 45012/45012/45012) [24,150,4]/[24,4,12] r=0 lpr=45012 pi=44281-45011/21 crt=44756'19846432 lcod 0'0 mlcod 0'0 remapped+peering m=2] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 MNotifyRec from 28 notify: (query_epoch:45014, epoch_sent:45014, info:1.42c( v 44756'19846432 (33550'19843431,44756'19846432] local-les=44790 n=5552 ec=30458 les/c/f 44790/44790/0 45012/45012/45012)) features: 0x7ffffffefdfbfff
-234> 2020-07-06 18:40:14.307832 7f838cc96700 10 osd.24 pg_epoch: 45014 pg[1.42c( v 44756'19846432 lc 44133'19846430 (33550'19843351,44756'19846432] local-les=44999 n=5552 ec=30458 les/c/f 44999/44790/0 45012/45012/45012) [24,150,4]/[24,4,12] r=0 lpr=45012 pi=44281-45011/21 crt=44756'19846432 lcod 0'0 mlcod 0'0 remapped+peering m=2] got dup osd.28 info 1.42c( v 44756'19846432 (33550'19843431,44756'19846432] local-les=44790 n=5552 ec=30458 les/c/f 44790/44790/0 45012/45012/45012), identical to ours
-233> 2020-07-06 18:40:14.307895 7f838cc96700 10 log is not dirty
-232> 2020-07-06 18:40:14.310047 7f83ad2c6700 1 -- 172.26.224.197:6806/2876125 >> 172.26.224.166:0/629113 conn(0x7f83d083f800 sd=1424 :6806 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=12138 cs=1 l=1). == rx == osd.23 seq 1 0x7f83c38fea00 osd_ping(ping e45014 stamp 2020-07-06 18:40:14.307073) v2
-231> 2020-07-06 18:40:14.310054 7f83adac7700 1 -- 172.26.216.197:6815/2876125 >> 172.26.224.166:0/629113 conn(0x7f83d0eae000 sd=1531 :6815 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=12139 cs=1 l=1). == rx == osd.23 seq 1 0x7f83cf97a400 osd_ping(ping e45014 stamp 2020-07-06 18:40:14.307073) v2
-230> 2020-07-06 18:40:14.310105 7f83ad2c6700 1 -- 172.26.224.197:6806/2876125 >> 172.26.224.166:0/629113 conn(0x7f83d083f800 sd=1424 :6806 s=STATE_OPEN pgs=12138 cs=1 l=1). == tx == 0x7f83c38fe800 osd_ping(ping_reply e45014 stamp 2020-07-06 18:40:14.307073) v2
-229> 2020-07-06 18:40:14.310142 7f83ad2c6700 20 osd.24 45014 share_map_peer 0x7f83d07be800 already has epoch 45014
-228> 2020-07-06 18:40:14.310165 7f83adac7700 1 -- 172.26.216.197:6815/2876125 >> 172.26.224.166:0/629113 conn(0x7f83d0eae000 sd=1531 :6815 s=STATE_OPEN pgs=12139 cs=1 l=1). == tx == 0x7f83cfb85e00 osd_ping(ping_reply e45014 stamp 2020-07-06 18:40:14.307073) v2
-227> 2020-07-06 18:40:14.310205 7f83adac7700 20 osd.24 45014 share_map_peer 0x7f83d07be800 already has epoch 45014
-226> 2020-07-06 18:40:14.335432 7f83a72ba700 1 -- 172.26.224.197:6806/2876125 >> 172.26.216.143:0/32319 conn(0x7f83d079b000 sd=1404 :6806 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=9638 cs=1 l=1). == rx == osd.139 seq 1 0x7f83d098d600 osd_ping(ping e45014 stamp 2020-07-06 18:40:14.331379) v2
-225> 2020-07-06 18:40:14.335478 7f83a72ba700 1 -- 172.26.224.197:6806/2876125 >> 172.26.216.143:0/32319 conn(0x7f83d079b000 sd=1404 :6806 s=STATE_OPEN pgs=9638 cs=1 l=1). == tx == 0x7f83d02ed600 osd_ping(ping_reply e45014 stamp 2020-07-06 18:40:14.331379) v2
-224> 2020-07-06 18:40:14.335504 7f83a72ba700 20 osd.24 45014 share_map_peer 0x7f83d0719000 already has epoch 45014
-223> 2020-07-06 18:40:14.335489 7f83aaac1700 1 -- 172.26.216.197:6815/2876125 >> 172.26.216.143:0/32319 conn(0x7f83d0e8c000 sd=1521 :6815 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=9639 cs=1 l=1). == rx == osd.139 seq 1 0x7f83cf7a9000 osd_ping(ping e45014 stamp 2020-07-06 18:40:14.331379) v2
-222> 2020-07-06 18:40:14.335547 7f83aaac1700 1 -- 172.26.216.197:6815/2876125 >> 172.26.216.143:0/32319 conn(0x7f83d0e8c000 sd=1521 :6815 s=STATE_OPEN pgs=9639 cs=1 l=1). == tx == 0x7f83cfea4200 osd_ping(ping_reply e45014 stamp 2020-07-06 18:40:14.331379) v2
-221> 2020-07-06 18:40:14.335592 7f83aaac1700 20 osd.24 45014 share_map_peer 0x7f83d0719000 already has epoch 45014
-220> 2020-07-06 18:40:14.343119 7f83a82bc700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.176:6810/536802 conn(0x7f83d09af800 sd=1460 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=621 cs=1 l=0). == rx == osd.153 seq 32 0x7f83d1719b00 osd_map(45014..45014 src has 38101..45014) v3
-219> 2020-07-06 18:40:14.343221 7f83a82bc700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.176:6810/536802 conn(0x7f83d09af800 sd=1460 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=621 cs=1 l=0). == rx == osd.153 seq 33 0x7f83d1a090e0 pg_notify(1.23e(25) epoch 45014) v5
-218> 2020-07-06 18:40:14.343247 7f83a82bc700 10 osd.24 45014 do_waiters -- start
-217> 2020-07-06 18:40:14.343254 7f83a82bc700 10 osd.24 45014 do_waiters -- finish
-216> 2020-07-06 18:40:14.343256 7f83a82bc700 20 osd.24 45014 _dispatch 0x7f83d1719b00 osd_map(45014..45014 src has 38101..45014) v3
-215> 2020-07-06 18:40:14.343264 7f83a82bc700 3 osd.24.objecter handle_osd_map ignoring epochs [45014,45014] <= 45014
-214> 2020-07-06 18:40:14.343267 7f83a82bc700 20 osd.24.objecter dump_active .. 0 homeless
-213> 2020-07-06 18:40:14.343272 7f83a82bc700 3 osd.24 45014 handle_osd_map epochs [45014,45014], i have 45014, src has [38101,45014]
-212> 2020-07-06 18:40:14.343274 7f83a82bc700 10 osd.24 45014 no new maps here, dropping
-211> 2020-07-06 18:40:14.343278 7f83a82bc700 10 osd.24 45014 do_waiters -- start
-210> 2020-07-06 18:40:14.343279 7f83a82bc700 10 osd.24 45014 do_waiters -- finish
-209> 2020-07-06 18:40:14.343281 7f83a82bc700 10 osd.24 45014 do_waiters -- start
-208> 2020-07-06 18:40:14.343282 7f83a82bc700 10 osd.24 45014 do_waiters -- finish
-207> 2020-07-06 18:40:14.343284 7f83a82bc700 20 osd.24 45014 _dispatch 0x7f83d1a090e0 pg_notify(1.23e(25) epoch 45014) v5
-206> 2020-07-06 18:40:14.343290 7f83a82bc700 7 osd.24 45014 handle_pg_notify from osd.153
-205> 2020-07-06 18:40:14.343292 7f83a82bc700 15 osd.24 45014 require_same_or_newer_map 45014 (i am 45014) 0x7f83d1a090e0
-204> 2020-07-06 18:40:14.343358 7f83a82bc700 10 osd.24 45014 do_waiters -- start
-203> 2020-07-06 18:40:14.343361 7f83a82bc700 10 osd.24 45014 do_waiters -- finish
-202> 2020-07-06 18:40:14.343374 7f839049d700 10 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 44999/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 activating+degraded+remapped m=2] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 MNotifyRec from 153 notify: (query_epoch:45014, epoch_sent:45014, info:1.23e( v 44314'17115402 (33550'17112402,44314'17115402] lb MIN (bitwise) local-les=44984 n=0 ec=30458 les/c/f 44999/44645/0 45012/45013/45013)) features: 0x7ffffffefdfbfff
-201> 2020-07-06 18:40:14.343416 7f839049d700 10 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 44999/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 activating+degraded+remapped m=2] state<Started/Primary/Active>: Active: got notify from 153, already have info from that osd, ignoring
-200> 2020-07-06 18:40:14.343468 7f839049d700 10 log is not dirty
-199> 2020-07-06 18:40:14.344584 7f83a82bc700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.176:6810/536802 conn(0x7f83d09af800 sd=1460 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=621 cs=1 l=0). == rx == osd.153 seq 34 0x7f83d1a090e0 pg_info(1 pgs e45014:2.26a(8)) v4
-198> 2020-07-06 18:40:14.344613 7f83a82bc700 10 osd.24 45014 do_waiters -- start
-197> 2020-07-06 18:40:14.344615 7f83a82bc700 10 osd.24 45014 do_waiters -- finish
-196> 2020-07-06 18:40:14.344619 7f83a82bc700 20 osd.24 45014 _dispatch 0x7f83d1a090e0 pg_info(1 pgs e45014:2.26a(8)) v4
-195> 2020-07-06 18:40:14.344626 7f83a82bc700 7 osd.24 45014 handle_pg_info pg_info(1 pgs e45014:2.26a(8)) v4 from osd.153
-194> 2020-07-06 18:40:14.344629 7f83a82bc700 15 osd.24 45014 require_same_or_newer_map 45014 (i am 45014) 0x7f83d1a090e0
-193> 2020-07-06 18:40:14.344659 7f83a82bc700 10 osd.24 45014 do_waiters -- start
-192> 2020-07-06 18:40:14.344663 7f83a82bc700 10 osd.24 45014 do_waiters -- finish
-191> 2020-07-06 18:40:14.344662 7f838d497700 10 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=44999 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 crt=24074'356 lcod 0'0 inactive NOTIFY] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 MInfoRec from 153 info: 2.26a( v 24074'356 (0'0,24074'356] local-les=45014 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970)
-190> 2020-07-06 18:40:14.344686 7f838d497700 10 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=44999 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 crt=24074'356 lcod 0'0 inactive NOTIFY] state<Started/Stray>: got info from osd.153 2.26a( v 24074'356 (0'0,24074'356] local-les=45014 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970)
-189> 2020-07-06 18:40:14.344700 7f838d497700 5 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=44999 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 crt=24074'356 lcod 0'0 inactive NOTIFY] exit Started/Stray 1.133501 7 0.000605
-188> 2020-07-06 18:40:14.344713 7f838d497700 5 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=44999 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 crt=24074'356 lcod 0'0 inactive NOTIFY] enter Started/ReplicaActive
-187> 2020-07-06 18:40:14.344724 7f838d497700 5 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=44999 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 crt=24074'356 lcod 0'0 inactive NOTIFY] enter Started/ReplicaActive/RepNotRecovering
-186> 2020-07-06 18:40:14.344735 7f838d497700 10 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=44999 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 crt=24074'356 lcod 0'0 inactive NOTIFY] state<Started/ReplicaActive>: In ReplicaActive, about to call activate
-185> 2020-07-06 18:40:14.344746 7f838d497700 10 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=45014 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 crt=24074'356 lcod 0'0 inactive] activate - no missing, moving last_complete 24074'356 -> 24074'356
-184> 2020-07-06 18:40:14.344778 7f838d497700 10 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=45014 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 crt=24074'356 lcod 0'0 inactive] state<Started/ReplicaActive>: Activate Finished
-183> 2020-07-06 18:40:14.344853 7f838d497700 10 log is not dirty
-182> 2020-07-06 18:40:14.345087 7f8394bc9700 10 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=45014 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 crt=24074'356 lcod 0'0 inactive] _activate_committed 45014 telling primary
-181> 2020-07-06 18:40:14.345148 7f8394bc9700 20 osd.24 45014 share_map_peer 0x7f83d09af800 already has epoch 45014
-180> 2020-07-06 18:40:14.345154 7f8394bc9700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.176:6810/536802 conn(0x7f83d09af800 sd=1460 :-1 s=STATE_OPEN pgs=621 cs=1 l=0). == tx == 0x7f83d04d7a40 pg_info(1 pgs e45014:2.26a) v4
-179> 2020-07-06 18:40:14.345241 7f8394bc9700 10 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=45014 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 luod=0'0 crt=24074'356 lcod 0'0 active] flushed
-178> 2020-07-06 18:40:14.345300 7f838bc94700 10 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=45014 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 luod=0'0 crt=24074'356 lcod 0'0 active] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 FlushedEvt
-177> 2020-07-06 18:40:14.345335 7f838bc94700 15 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=45014 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 luod=0'0 crt=24074'356 lcod 0'0 active] requeue_ops
-176> 2020-07-06 18:40:14.345352 7f838bc94700 10 log is not dirty
-175> 2020-07-06 18:40:14.345577 7f83a82bc700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.176:6810/536802 conn(0x7f83d09af800 sd=1460 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=621 cs=1 l=0). == rx == osd.153 seq 35 0x7f83d04d7a40 pg_info(1 pgs e45014:2.26a) v4
-174> 2020-07-06 18:40:14.345605 7f83a82bc700 10 osd.24 45014 do_waiters -- start
-173> 2020-07-06 18:40:14.345612 7f83a82bc700 10 osd.24 45014 do_waiters -- finish
-172> 2020-07-06 18:40:14.345614 7f83a82bc700 20 osd.24 45014 _dispatch 0x7f83d04d7a40 pg_info(1 pgs e45014:2.26a) v4
-171> 2020-07-06 18:40:14.345620 7f83a82bc700 7 osd.24 45014 handle_pg_info pg_info(1 pgs e45014:2.26a) v4 from osd.153
-170> 2020-07-06 18:40:14.345626 7f83a82bc700 15 osd.24 45014 require_same_or_newer_map 45014 (i am 45014) 0x7f83d04d7a40
-169> 2020-07-06 18:40:14.345652 7f83a82bc700 10 osd.24 45014 do_waiters -- start
-168> 2020-07-06 18:40:14.345655 7f83a82bc700 10 osd.24 45014 do_waiters -- finish
-167> 2020-07-06 18:40:14.345700 7f838a491700 10 osd.24 pg_epoch: 45014 pg[2.26a( v 24074'356 (0'0,24074'356] local-les=45014 n=76 ec=24411 les/c/f 44999/44660/0 45012/45013/43970) [153,24,7] r=1 lpr=45013 pi=43869-45012/63 luod=0'0 crt=24074'356 lcod 0'0 active] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 MInfoRec from 153 info: 2.26a( v 24074'356 (0'0,24074'356] local-les=45014 n=76 ec=24411 les/c/f 45014/44660/0 45012/45013/43970)
-166> 2020-07-06 18:40:14.345741 7f83a82bc700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.176:6810/536802 conn(0x7f83d09af800 sd=1460 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=621 cs=1 l=0). == rx == osd.153 seq 36 0x7f83d04d7a40 pg_info(1 pgs e45014:1.23e) v4
-165> 2020-07-06 18:40:14.345765 7f838a491700 10 log is not dirty
-164> 2020-07-06 18:40:14.345767 7f83a82bc700 10 osd.24 45014 do_waiters -- start
-163> 2020-07-06 18:40:14.345775 7f83a82bc700 10 osd.24 45014 do_waiters -- finish
-162> 2020-07-06 18:40:14.345776 7f83a82bc700 20 osd.24 45014 _dispatch 0x7f83d04d7a40 pg_info(1 pgs e45014:1.23e) v4
-161> 2020-07-06 18:40:14.345782 7f83a82bc700 7 osd.24 45014 handle_pg_info pg_info(1 pgs e45014:1.23e) v4 from osd.153
-160> 2020-07-06 18:40:14.345785 7f83a82bc700 15 osd.24 45014 require_same_or_newer_map 45014 (i am 45014) 0x7f83d04d7a40
-159> 2020-07-06 18:40:14.345860 7f83a82bc700 10 osd.24 45014 do_waiters -- start
-158> 2020-07-06 18:40:14.345864 7f83a82bc700 10 osd.24 45014 do_waiters -- finish
-157> 2020-07-06 18:40:14.345877 7f838fc9c700 10 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 44999/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 activating+degraded+remapped m=2] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 MInfoRec from 153 info: 1.23e( v 44314'17115402 (33550'17112402,44314'17115402] lb MIN (bitwise) local-les=44984 n=0 ec=30458 les/c/f 45014/44645/0 45012/45013/45013)
-156> 2020-07-06 18:40:14.345925 7f838fc9c700 10 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 44999/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 activating+degraded+remapped m=2] state<Started/Primary/Active>: peer osd.153 activated and committed
-155> 2020-07-06 18:40:14.345944 7f838fc9c700 15 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 44999/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 activating+degraded+remapped m=2] publish_stats_to_osd 45014: no change since 2020-07-06 18:40:14.211834
-154> 2020-07-06 18:40:14.345966 7f838fc9c700 10 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 44999/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 activating+degraded+remapped m=2] all_activated_and_committed
-153> 2020-07-06 18:40:14.346006 7f838fc9c700 10 log is not dirty
-152> 2020-07-06 18:40:14.346017 7f838fc9c700 10 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 44999/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 activating+degraded+remapped m=2] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 AllReplicasActivated
-151> 2020-07-06 18:40:14.346034 7f838fc9c700 10 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] share_pg_info
-150> 2020-07-06 18:40:14.346065 7f838fc9c700 20 osd.24 45014 share_map_peer 0x7f83d0807800 already has epoch 45014
-149> 2020-07-06 18:40:14.346070 7f838fc9c700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.133:6800/201624 conn(0x7f83d0807800 sd=1417 :6805 s=STATE_OPEN pgs=5113 cs=1 l=0). == tx == 0x7f83d19ffde0 pg_info(1 pgs e45014:1.23e) v4
-148> 2020-07-06 18:40:14.346187 7f838fc9c700 20 osd.24 45014 share_map_peer 0x7f83d09e0800 already has epoch 45014
-147> 2020-07-06 18:40:14.346196 7f838fc9c700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.133:6816/2554898 conn(0x7f83d09e0800 sd=1485 :-1 s=STATE_OPEN pgs=3957 cs=1 l=0). == tx == 0x7f83d00fcd00 pg_info(1 pgs e45014:1.23e) v4
-146> 2020-07-06 18:40:14.346265 7f838fc9c700 20 osd.24 45014 share_map_peer 0x7f83d07e8800 already has epoch 45014
-145> 2020-07-06 18:40:14.346272 7f838fc9c700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.165:6806/1500877 conn(0x7f83d07e8800 sd=1415 :6805 s=STATE_OPEN pgs=81733 cs=1 l=0). == tx == 0x7f83d00fad20 pg_info(1 pgs e45014:1.23e) v4
-144> 2020-07-06 18:40:14.346345 7f838fc9c700 20 osd.24 45014 share_map_peer 0x7f83d09af800 already has epoch 45014
-143> 2020-07-06 18:40:14.346351 7f838fc9c700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.176:6810/536802 conn(0x7f83d09af800 sd=1460 :-1 s=STATE_OPEN pgs=621 cs=1 l=0). == tx == 0x7f83d00faf00 pg_info(1 pgs e45014:1.23e) v4
-142> 2020-07-06 18:40:14.346407 7f838fc9c700 20 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] _update_calc_stats osd.153 misplaced 5618 but partially backfilled 0
-141> 2020-07-06 18:40:14.346431 7f838fc9c700 20 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] _update_calc_stats osd.7 misplaced 5618 but partially backfilled 0
-140> 2020-07-06 18:40:14.346449 7f838fc9c700 15 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] publish_stats_to_osd 45014:12255689
-139> 2020-07-06 18:40:14.346465 7f838fc9c700 10 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] check_local
-138> 2020-07-06 18:40:14.346480 7f838fc9c700 15 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] requeue_ops
-137> 2020-07-06 18:40:14.346494 7f838fc9c700 10 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] needs_recovery primary has 2 missing
-136> 2020-07-06 18:40:14.346509 7f838fc9c700 10 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] activate not all replicas are up-to-date, queueing recovery
-135> 2020-07-06 18:40:14.346532 7f838fc9c700 20 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] _update_calc_stats osd.153 misplaced 5618 but partially backfilled 0
-134> 2020-07-06 18:40:14.346548 7f838fc9c700 20 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] _update_calc_stats osd.7 misplaced 5618 but partially backfilled 0
-133> 2020-07-06 18:40:14.346565 7f838fc9c700 15 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] publish_stats_to_osd 45014: no change since 2020-07-06 18:40:14.346401
-132> 2020-07-06 18:40:14.346589 7f838fc9c700 5 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] on activate: bft=7,153 from MIN
-131> 2020-07-06 18:40:14.346610 7f838fc9c700 5 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] target shard 7 from MIN
-130> 2020-07-06 18:40:14.346624 7f838fc9c700 5 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] target shard 153 from MIN
-129> 2020-07-06 18:40:14.346638 7f838fc9c700 20 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] hit_set_clear
-128> 2020-07-06 18:40:14.346654 7f838fc9c700 20 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] agent_stop
-127> 2020-07-06 18:40:14.346681 7f838fc9c700 10 log is not dirty
-126> 2020-07-06 18:40:14.346732 7f838fc9c700 10 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 DoRecovery
-125> 2020-07-06 18:40:14.346752 7f838fc9c700 5 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] exit Started/Primary/Active/Activating 0.134821 13 0.004127
-124> 2020-07-06 18:40:14.346772 7f838fc9c700 5 osd.24 pg_epoch: 45014 pg[1.23e( v 44314'17115402 lc 44024'17115400 (33550'17112378,44314'17115402] local-les=45014 n=5618 ec=30458 les/c/f 45014/44645/0 45012/45013/45013) [24,153,7]/[24,10,4] r=0 lpr=45013 pi=44281-45012/25 bft=7,153 crt=44314'17115402 lcod 0'0 mlcod 0'0 active+degraded+remapped m=2] enter Started/Primary/Active/WaitLocalRecoveryReserved
-123> 2020-07-06 18:40:14.346792 7f838fc9c700 10 log is not dirty
-122> 2020-07-06 18:40:14.361510 7f83a72ba700 1 -- 172.26.216.197:6815/2876125 >> 172.26.216.176:0/53417 conn(0x7f83d12e5000 sd=1594 :6815 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=10590 cs=1 l=1). == rx == osd.155 seq 1 0x7f83d098d400 osd_ping(ping e45014 stamp 2020-07-06 18:40:14.357832) v2
-121> 2020-07-06 18:40:14.361585 7f83a72ba700 1 -- 172.26.216.197:6815/2876125 >> 172.26.216.176:0/53417 conn(0x7f83d12e5000 sd=1594 :6815 s=STATE_OPEN pgs=10590 cs=1 l=1). == tx == 0x7f83d02ed600 osd_ping(ping_reply e45014 stamp 2020-07-06 18:40:14.357832) v2
-120> 2020-07-06 18:40:14.361542 7f83a6ab9700 1 -- 172.26.224.197:6806/2876125 >> 172.26.216.176:0/53417 conn(0x7f83d0d55000 sd=1595 :6806 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=10589 cs=1 l=1). == rx == osd.155 seq 1 0x7f83d061ba00 osd_ping(ping e45014 stamp 2020-07-06 18:40:14.357832) v2
-119> 2020-07-06 18:40:14.361638 7f83a72ba700 20 osd.24 45014 share_map_peer 0x7f83d079f800 already has epoch 45014
-118> 2020-07-06 18:40:14.361655 7f83a6ab9700 1 -- 172.26.224.197:6806/2876125 >> 172.26.216.176:0/53417 conn(0x7f83d0d55000 sd=1595 :6806 s=STATE_OPEN pgs=10589 cs=1 l=1). == tx == 0x7f83d061ce00 osd_ping(ping_reply e45014 stamp 2020-07-06 18:40:14.357832) v2
-117> 2020-07-06 18:40:14.361749 7f83a6ab9700 20 osd.24 45014 share_map_peer 0x7f83d079f800 already has epoch 45014
-116> 2020-07-06 18:40:14.418434 7f83a6ab9700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.145:6800/60236 conn(0x7f83d109c000 sd=1581 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=77152 cs=1 l=0). == rx == osd.140 seq 17 0x7f83d06b41c0 osd_map(45014..45014 src has 38101..45014) v3
-115> 2020-07-06 18:40:14.418523 7f83a6ab9700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.145:6800/60236 conn(0x7f83d109c000 sd=1581 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=77152 cs=1 l=0). == rx == osd.140 seq 18 0x7f83cfe723c0 pg_notify(2.157(23) epoch 45014) v5
-114> 2020-07-06 18:40:14.418555 7f83a6ab9700 10 osd.24 45014 do_waiters -- start
-113> 2020-07-06 18:40:14.418564 7f83a6ab9700 10 osd.24 45014 do_waiters -- finish
-112> 2020-07-06 18:40:14.418566 7f83a6ab9700 20 osd.24 45014 _dispatch 0x7f83d06b41c0 osd_map(45014..45014 src has 38101..45014) v3
-111> 2020-07-06 18:40:14.418577 7f83a6ab9700 3 osd.24.objecter handle_osd_map ignoring epochs [45014,45014] <= 45014
-110> 2020-07-06 18:40:14.418582 7f83a6ab9700 20 osd.24.objecter dump_active .. 0 homeless
-109> 2020-07-06 18:40:14.418587 7f83a6ab9700 3 osd.24 45014 handle_osd_map epochs [45014,45014], i have 45014, src has [38101,45014]
-108> 2020-07-06 18:40:14.418590 7f83a6ab9700 10 osd.24 45014 no new maps here, dropping
-107> 2020-07-06 18:40:14.418594 7f83a6ab9700 10 osd.24 45014 do_waiters -- start
-106> 2020-07-06 18:40:14.418595 7f83a6ab9700 10 osd.24 45014 do_waiters -- finish
-105> 2020-07-06 18:40:14.418598 7f83a6ab9700 10 osd.24 45014 do_waiters -- start
-104> 2020-07-06 18:40:14.418599 7f83a6ab9700 10 osd.24 45014 do_waiters -- finish
-103> 2020-07-06 18:40:14.418601 7f83a6ab9700 20 osd.24 45014 _dispatch 0x7f83cfe723c0 pg_notify(2.157(23) epoch 45014) v5
-102> 2020-07-06 18:40:14.418607 7f83a6ab9700 7 osd.24 45014 handle_pg_notify from osd.140
-101> 2020-07-06 18:40:14.418610 7f83a6ab9700 15 osd.24 45014 require_same_or_newer_map 45014 (i am 45014) 0x7f83cfe723c0
-100> 2020-07-06 18:40:14.418656 7f83a6ab9700 10 osd.24 45014 do_waiters -- start
-99> 2020-07-06 18:40:14.418660 7f83a6ab9700 10 osd.24 45014 do_waiters -- finish
-98> 2020-07-06 18:40:14.418680 7f838948f700 10 osd.24 pg_epoch: 45014 pg[2.157( v 29677'2317 (0'0,29677'2317] local-les=45013 n=87 ec=224 les/c/f 45013/44734/0 45012/45012/45012) [24,23,143] r=0 lpr=45012 pi=44298-45011/23 crt=29677'2317 lcod 0'0 mlcod 0'0 active+recovery_wait+degraded] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 MNotifyRec from 140 notify: (query_epoch:45014, epoch_sent:45014, info:2.157( v 29677'2317 (0'0,29677'2317] local-les=44646 n=87 ec=224 les/c/f 44646/44734/0 45012/45012/45012)) features: 0x7ffffffefdfbfff
-97> 2020-07-06 18:40:14.418715 7f838948f700 10 osd.24 pg_epoch: 45014 pg[2.157( v 29677'2317 (0'0,29677'2317] local-les=45013 n=87 ec=224 les/c/f 45013/44734/0 45012/45012/45012) [24,23,143] r=0 lpr=45012 pi=44298-45011/23 crt=29677'2317 lcod 0'0 mlcod 0'0 active+recovery_wait+degraded] state<Started/Primary/Active>: Active: got notify from 140, already have info from that osd, ignoring
-96> 2020-07-06 18:40:14.418736 7f838948f700 10 log is not dirty
-95> 2020-07-06 18:40:14.419270 7f83a6ab9700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.145:6800/60236 conn(0x7f83d109c000 sd=1581 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=77152 cs=1 l=0). == rx == osd.140 seq 19 0x7f83cfe723c0 pg_notify(1.367(137) epoch 45014) v5
-94> 2020-07-06 18:40:14.419312 7f83a6ab9700 10 osd.24 45014 do_waiters -- start
-93> 2020-07-06 18:40:14.419319 7f83a6ab9700 10 osd.24 45014 do_waiters -- finish
-92> 2020-07-06 18:40:14.419321 7f83a6ab9700 20 osd.24 45014 _dispatch 0x7f83cfe723c0 pg_notify(1.367(137) epoch 45014) v5
-91> 2020-07-06 18:40:14.419329 7f83a6ab9700 7 osd.24 45014 handle_pg_notify from osd.140
-90> 2020-07-06 18:40:14.419331 7f83a6ab9700 15 osd.24 45014 require_same_or_newer_map 45014 (i am 45014) 0x7f83cfe723c0
-89> 2020-07-06 18:40:14.419406 7f83a6ab9700 10 osd.24 45014 do_waiters -- start
-88> 2020-07-06 18:40:14.419411 7f83a6ab9700 10 osd.24 45014 do_waiters -- finish
-87> 2020-07-06 18:40:14.419409 7f838ec9a700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45009/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 activating+undersized+degraded+remapped] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 MNotifyRec from 140 notify: (query_epoch:45014, epoch_sent:45014, info:1.367( v 43961'42232566 (34902'42229566,43961'42232566] lb MIN (bitwise) local-les=44012 n=0 ec=30458 les/c/f 45009/44607/0 45012/45013/45013)) features: 0x7ffffffefdfbfff
-86> 2020-07-06 18:40:14.419444 7f838ec9a700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45009/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 activating+undersized+degraded+remapped] state<Started/Primary/Active>: Active: got notify from 140, already have info from that osd, ignoring
-85> 2020-07-06 18:40:14.419470 7f838ec9a700 10 log is not dirty
-84> 2020-07-06 18:40:14.420684 7f83a6ab9700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.145:6800/60236 conn(0x7f83d109c000 sd=1581 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=77152 cs=1 l=0). == rx == osd.140 seq 20 0x7f83cfe723c0 pg_info(1 pgs e45014:1.367) v4
-83> 2020-07-06 18:40:14.420728 7f83a6ab9700 10 osd.24 45014 do_waiters -- start
-82> 2020-07-06 18:40:14.420736 7f83a6ab9700 10 osd.24 45014 do_waiters -- finish
-81> 2020-07-06 18:40:14.420738 7f83a6ab9700 20 osd.24 45014 _dispatch 0x7f83cfe723c0 pg_info(1 pgs e45014:1.367) v4
-80> 2020-07-06 18:40:14.420746 7f83a6ab9700 7 osd.24 45014 handle_pg_info pg_info(1 pgs e45014:1.367) v4 from osd.140
-79> 2020-07-06 18:40:14.420749 7f83a6ab9700 15 osd.24 45014 require_same_or_newer_map 45014 (i am 45014) 0x7f83cfe723c0
-78> 2020-07-06 18:40:14.420818 7f83a6ab9700 10 osd.24 45014 do_waiters -- start
-77> 2020-07-06 18:40:14.420823 7f83a6ab9700 10 osd.24 45014 do_waiters -- finish
-76> 2020-07-06 18:40:14.420831 7f838b493700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45009/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 activating+undersized+degraded+remapped] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 MInfoRec from 140 info: 1.367( v 43961'42232566 (34902'42229566,43961'42232566] lb MIN (bitwise) local-les=44012 n=0 ec=30458 les/c/f 45014/44607/0 45012/45013/45013)
-75> 2020-07-06 18:40:14.420864 7f838b493700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45009/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 activating+undersized+degraded+remapped] state<Started/Primary/Active>: peer osd.140 activated and committed
-74> 2020-07-06 18:40:14.420881 7f838b493700 15 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45009/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 activating+undersized+degraded+remapped] publish_stats_to_osd 45014: no change since 2020-07-06 18:40:14.212296
-73> 2020-07-06 18:40:14.420917 7f838b493700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45009/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 activating+undersized+degraded+remapped] all_activated_and_committed
-72> 2020-07-06 18:40:14.420944 7f838b493700 10 log is not dirty
-71> 2020-07-06 18:40:14.420954 7f838b493700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45009/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 activating+undersized+degraded+remapped] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 AllReplicasActivated
-70> 2020-07-06 18:40:14.420968 7f838b493700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] share_pg_info
-69> 2020-07-06 18:40:14.420994 7f838b493700 20 osd.24 45014 share_map_peer 0x7f83d109c000 already has epoch 45014
-68> 2020-07-06 18:40:14.420999 7f838b493700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.145:6800/60236 conn(0x7f83d109c000 sd=1581 :-1 s=STATE_OPEN pgs=77152 cs=1 l=0). == tx == 0x7f83c31ded20 pg_info(1 pgs e45014:1.367) v4
-67> 2020-07-06 18:40:14.421078 7f838b493700 20 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] _update_calc_stats osd.140 misplaced 6476 but partially backfilled 0
-66> 2020-07-06 18:40:14.421099 7f838b493700 15 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] publish_stats_to_osd 45014:36179363
-65> 2020-07-06 18:40:14.421111 7f838b493700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] check_local
-64> 2020-07-06 18:40:14.421123 7f838b493700 15 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] requeue_ops 0x7f83d03a4300,0x7f83d07e3800,0x7f83d0f5e200,0x7f83d0f5e300,0x7f83d0f5d900,0x7f83d07e3000
-63> 2020-07-06 18:40:14.421165 7f838b493700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] needs_recovery is recovered
-62> 2020-07-06 18:40:14.421176 7f838b493700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] needs_backfill osd.140 has last_backfill MIN
-61> 2020-07-06 18:40:14.421187 7f838b493700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] activate queueing backfill
-60> 2020-07-06 18:40:14.421204 7f838b493700 20 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] _update_calc_stats osd.140 misplaced 6476 but partially backfilled 0
-59> 2020-07-06 18:40:14.421217 7f838b493700 15 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] publish_stats_to_osd 45014: no change since 2020-07-06 18:40:14.421076
-58> 2020-07-06 18:40:14.421238 7f838b493700 5 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] on activate: bft=140 from MIN
-57> 2020-07-06 18:40:14.421250 7f838b493700 5 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] target shard 140 from MIN
-56> 2020-07-06 18:40:14.421260 7f838b493700 20 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] hit_set_clear
-55> 2020-07-06 18:40:14.421269 7f838b493700 20 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] agent_stop
-54> 2020-07-06 18:40:14.421290 7f838b493700 10 log is not dirty
-53> 2020-07-06 18:40:14.421330 7f838b493700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] handle_peering_event: epoch_sent: 45014 epoch_requested: 45014 RequestBackfill
-52> 2020-07-06 18:40:14.421345 7f838b493700 5 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] exit Started/Primary/Active/Activating 0.208962 7 0.002408
-51> 2020-07-06 18:40:14.421359 7f838b493700 5 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped] enter Started/Primary/Active/WaitLocalBackfillReserved
-50> 2020-07-06 18:40:14.421373 7f838b493700 10 log is not dirty
-49> 2020-07-06 18:40:14.421387 7f8385487700 10 osd.24 45014 dequeue_op 0x7f83d03a4300 prio 63 cost 81 latency 1.064879 osd_op(osd.60.43950:1579 1.aad8e367 (undecoded) ondisk+retry+write+ignore_overlay+enforce_snapc+known_if_redirected e45013) v7 pg pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill]
-48> 2020-07-06 18:40:14.421430 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] handle_message: 0x7f83d03a4300
-47> 2020-07-06 18:40:14.421469 7f8385487700 20 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] op_has_sufficient_caps pool=1 (cinder ) owner=0 need_read_cap=0 need_write_cap=1 need_class_read_cap=0 need_class_write_cap=0 -> yes
-46> 2020-07-06 18:40:14.421529 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] do_op osd_op(osd.60.43950:1579 1.aad8e367 rbd_data.17fdbcbcf6f7e5be5.00000000000005c4 [copy-from ver 2117975801] snapc 0=[] RETRY=136 ondisk+retry+write+ignore_overlay+enforce_snapc+known_if_redirected e45013) v7 may_write -> write-ordered flags ondisk+retry+write+ignore_overlay+enforce_snapc+known_if_redirected
-45> 2020-07-06 18:40:14.422731 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] get_object_context: obc NOT found in cache: 1:e6c71b55:::rbd_data.17fdbcbcf6f7e5be5.00000000000005c4:head
-44> 2020-07-06 18:40:14.422910 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] populate_obc_watchers 1:e6c71b55:::rbd_data.17fdbcbcf6f7e5be5.00000000000005c4:head
-43> 2020-07-06 18:40:14.422935 7f8385487700 20 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] ReplicatedPG::check_blacklisted_obc_watchers for obc 1:e6c71b55:::rbd_data.17fdbcbcf6f7e5be5.00000000000005c4:head
-42> 2020-07-06 18:40:14.422953 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] get_object_context: creating obc from disk: 0x7f83d0e73980
-41> 2020-07-06 18:40:14.422968 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] get_object_context: 0x7f83d0e73980 1:e6c71b55:::rbd_data.17fdbcbcf6f7e5be5.00000000000005c4:head rwstate(none n=0 w=0) oi: 1:e6c71b55:::rbd_data.17fdbcbcf6f7e5be5.00000000000005c4:head(33550'42224045 client.882753258.0:622105207 dirty|omap_digest s 4194304 uv 2089023391 od ffffffff) ssc: 0x7f83d0caee00 snapset: 0=[]:[]+head
-40> 2020-07-06 18:40:14.422999 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] find_object_context 1:e6c71b55:::rbd_data.17fdbcbcf6f7e5be5.00000000000005c4:head @head oi=1:e6c71b55:::rbd_data.17fdbcbcf6f7e5be5.00000000000005c4:head(33550'42224045 client.882753258.0:622105207 dirty|omap_digest s 4194304 uv 2089023391 od ffffffff)
-39> 2020-07-06 18:40:14.423041 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] execute_ctx 0x7f83d11c7800
-38> 2020-07-06 18:40:14.423057 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] do_op 1:e6c71b55:::rbd_data.17fdbcbcf6f7e5be5.00000000000005c4:head [copy-from ver 2117975801] ov 33550'42224045 av 45014'42232567 snapc 0=[] snapset 0=[]:[]+head
-37> 2020-07-06 18:40:14.423083 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] do_osd_op 1:e6c71b55:::rbd_data.17fdbcbcf6f7e5be5.00000000000005c4:head [copy-from ver 2117975801]
-36> 2020-07-06 18:40:14.423099 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] do_osd_op copy-from ver 2117975801
-35> 2020-07-06 18:40:14.423127 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] start_copy 1:e6c71b55:::rbd_data.17fdbcbcf6f7e5be5.00000000000005c4:head from 11:e6c71b55:::rbd_data.17fdbcbcf6f7e5be5.00000000000005c4:head @11 v2117975801 flags 15
-34> 2020-07-06 18:40:14.423150 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] _copy_some 0x7f83d0e73980 0x7f83c21ce9d8
-33> 2020-07-06 18:40:14.423190 7f8385487700 10 osd.24.objecter _op_submit op 0x7f83d14b3600
-32> 2020-07-06 18:40:14.423215 7f8385487700 10 osd.24.objecter _calc_target pgid 11.aad8e367 acting [60,160,166]
-31> 2020-07-06 18:40:14.423234 7f8385487700 1 Event(0x7f83c01707c8 owner=140203506026240 nevent=5000 time_id=1).wakeup
-30> 2020-07-06 18:40:14.423249 7f8385487700 20 osd.24.objecter _get_session s=0x7f83d06cf000 osd=60 2
-29> 2020-07-06 18:40:14.423258 7f8385487700 20 osd.24.objecter note: not requesting commit
-28> 2020-07-06 18:40:14.423267 7f8385487700 10 osd.24.objecter _op_submit oid rbd_data.17fdbcbcf6f7e5be5.00000000000005c4 '@11' '@11' [assert-version v2117975801,copy-get max 8388608] tid 1 osd.60
-27> 2020-07-06 18:40:14.423278 7f8385487700 20 osd.24.objecter get_session s=0x7f83d06cf000 osd=60 2
-26> 2020-07-06 18:40:14.423281 7f8385487700 15 osd.24.objecter _session_op_assign 60 1
-25> 2020-07-06 18:40:14.423284 7f8385487700 15 osd.24.objecter _send_op 1 to osd.60
-24> 2020-07-06 18:40:14.423287 7f8385487700 1 -- :/2876125 >> 172.26.216.232:6800/2612269 conn(0x7f83d1abb000 sd=-1 :-1 s=STATE_CONNECTING pgs=0 cs=0 l=1). == tx == 0x7f83d15ade40 osd_op(unknown.0.45012:1 11.aad8e367 rbd_data.17fdbcbcf6f7e5be5.00000000000005c4 [assert-version v2117975801,copy-get max 8388608] snapc 0=[] ack+read+ignore_cache+ignore_overlay+flush+map_snap_clone+known_if_redirected e45014) v7
-23> 2020-07-06 18:40:14.423315 7f8385487700 1 Event(0x7f83c01707c8 owner=140203506026240 nevent=5000 time_id=1).wakeup
-22> 2020-07-06 18:40:14.423326 7f8385487700 20 osd.24.objecter put_session s=0x7f83d06cf000 osd=60 3
-21> 2020-07-06 18:40:14.423330 7f8385487700 5 osd.24.objecter 1 unacked, 0 uncommitted
-20> 2020-07-06 18:40:14.423337 7f8385487700 10 osd.24 45014 dequeue_op 0x7f83d03a4300 finish
-19> 2020-07-06 18:40:14.423348 7f8385487700 10 osd.24 45014 dequeue_op 0x7f83d07e3800 prio 63 cost 78 latency 1.066773 osd_op(osd.60.43950:1580 1.4cb91367 (undecoded) ondisk+retry+write+ignore_overlay+enforce_snapc+known_if_redirected e45013) v7 pg pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill]
-18> 2020-07-06 18:40:14.423373 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] handle_message: 0x7f83d07e3800
-17> 2020-07-06 18:40:14.423393 7f8385487700 20 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] op_has_sufficient_caps pool=1 (cinder ) owner=0 need_read_cap=0 need_write_cap=1 need_class_read_cap=0 need_class_write_cap=0 -> yes
-16> 2020-07-06 18:40:14.423418 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] do_op osd_op(osd.60.43950:1580 1.4cb91367 rbd_data.4670a6238e1f29.0000000000000e29 [copy-from ver 2213266406] snapc 0=[] RETRY=136 ondisk+retry+write+ignore_overlay+enforce_snapc+known_if_redirected e45013) v7 may_write -> write-ordered flags ondisk+retry+write+ignore_overlay+enforce_snapc+known_if_redirected
-15> 2020-07-06 18:40:14.423445 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] get_object_context: obc NOT found in cache: 1:e6c89d32:::rbd_data.4670a6238e1f29.0000000000000e29:head
-14> 2020-07-06 18:40:14.423527 7f83ac2c4700 1 -- 172.26.216.197:0/2876125 learned_addr learned my addr 172.26.216.197:0/2876125
-13> 2020-07-06 18:40:14.423540 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] populate_obc_watchers 1:e6c89d32:::rbd_data.4670a6238e1f29.0000000000000e29:head
-12> 2020-07-06 18:40:14.423558 7f8385487700 20 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] ReplicatedPG::check_blacklisted_obc_watchers for obc 1:e6c89d32:::rbd_data.4670a6238e1f29.0000000000000e29:head
-11> 2020-07-06 18:40:14.423578 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] get_object_context: creating obc from disk: 0x7f83d1940280
-10> 2020-07-06 18:40:14.423593 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] get_object_context: 0x7f83d1940280 1:e6c89d32:::rbd_data.4670a6238e1f29.0000000000000e29:head rwstate(none n=0 w=0) oi: 1:e6c89d32:::rbd_data.4670a6238e1f29.0000000000000e29:head(40787'42230661 client.4337709373.0:890373 dirty|omap_digest s 4194304 uv 2145699725 od ffffffff) ssc: 0x7f83d1113dc0 snapset: 0=[]:[]+head
-9> 2020-07-06 18:40:14.423615 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] find_object_context 1:e6c89d32:::rbd_data.4670a6238e1f29.0000000000000e29:head @head oi=1:e6c89d32:::rbd_data.4670a6238e1f29.0000000000000e29:head(40787'42230661 client.4337709373.0:890373 dirty|omap_digest s 4194304 uv 2145699725 od ffffffff)
-8> 2020-07-06 18:40:14.423642 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] execute_ctx 0x7f83d1532700
-7> 2020-07-06 18:40:14.423657 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] do_op 1:e6c89d32:::rbd_data.4670a6238e1f29.0000000000000e29:head [copy-from ver 2213266406] ov 40787'42230661 av 45014'42232567 snapc 0=[] snapset 0=[]:[]+head
-6> 2020-07-06 18:40:14.423674 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] do_osd_op 1:e6c89d32:::rbd_data.4670a6238e1f29.0000000000000e29:head [copy-from ver 2213266406]
-5> 2020-07-06 18:40:14.423690 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] do_osd_op copy-from ver 2213266406
-4> 2020-07-06 18:40:14.423706 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] start_copy 1:e6c89d32:::rbd_data.4670a6238e1f29.0000000000000e29:head from 11:e6c89d32:::rbd_data.4670a6238e1f29.0000000000000e29:head @11 v2213266406 flags 15
-3> 2020-07-06 18:40:14.423727 7f8385487700 10 osd.24 pg_epoch: 45014 pg[1.367( v 43961'42232566 (34902'42229517,43961'42232566] local-les=45014 n=6476 ec=30458 les/c/f 45014/44607/0 45012/45013/45013) [140,24]/[24] r=0 lpr=45013 pi=44605-45012/21 bft=140 crt=43961'42232566 lcod 0'0 mlcod 0'0 active+undersized+degraded+remapped+wait_backfill] _copy_some 0x7f83d1940280 0x7f83c21d1418
-2> 2020-07-06 18:40:14.423797 7f83ac2c4700 2 -- 172.26.216.197:0/2876125 >> 172.26.216.232:6800/2612269 conn(0x7f83d1abb000 sd=1637 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-1> 2020-07-06 18:40:14.423877 7f83ac2c4700 10 osd.24.objecter ms_handle_connect 0x7f83d1abb000
0> 2020-07-06 18:40:14.432978 7f8385487700 -1 common/Throttle.cc: In function 'int64_t Throttle::take(int64_t)' thread 7f8385487700 time 2020-07-06 18:40:14.423756
common/Throttle.cc: 148: FAILED assert(c >= 0)

ceph version 10.2.2 (45107e21c568dd033c2f0a3107dec8f0b0e58374)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x85) [0x7f83b5f8b5b5]
2: (Throttle::take(long)+0x2fc) [0x7f83b5f6f73c]
3: (Objecter::_op_submit_with_budget(Objecter::Op*, ceph::shunique_lock<boost::shared_mutex>&, unsigned long*, int*)+0x2d2) [0x7f83b5b48652]
4: (Objecter::op_submit(Objecter::Op*, unsigned long*, int*)+0xed) [0x7f83b5b488dd]
5: (ReplicatedPG::_copy_some(std::shared_ptr<ObjectContext>, std::shared_ptr<ReplicatedPG::CopyOp>)+0xfb0) [0x7f83b5a42420]
6: (ReplicatedPG::start_copy(ReplicatedPG::CopyCallback*, std::shared_ptr<ObjectContext>, hobject_t, object_locator_t, unsigned long, unsigned int, bool, unsigned int, unsigned int)+0x682) [0x7f83b5a433c2]
7: (ReplicatedPG::do_osd_ops(ReplicatedPG::OpContext*, std::vector<OSDOp, std::allocator<OSDOp> >&)+0xa34a) [0x7f83b5a7ccca]
8: (ReplicatedPG::prepare_transaction(ReplicatedPG::OpContext*)+0xbf) [0x7f83b5a8a83f]
9: (ReplicatedPG::execute_ctx(ReplicatedPG::OpContext*)+0x8f0) [0x7f83b5a8b6f0]
10: (ReplicatedPG::do_op(std::shared_ptr<OpRequest>&)+0x3740) [0x7f83b5a90560]
11: (ReplicatedPG::do_request(std::shared_ptr<OpRequest>&, ThreadPool::TPHandle&)+0x747) [0x7f83b5a4be57]
12: (OSD::dequeue_op(boost::intrusive_ptr<PG>, std::shared_ptr<OpRequest>, ThreadPool::TPHandle&)+0x41d) [0x7f83b5900a8d]
13: (PGQueueable::RunVis::operator()(std::shared_ptr<OpRequest>&)+0x6d) [0x7f83b5900cdd]
14: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0x869) [0x7f83b5905809]
15: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x887) [0x7f83b5f7b557]
16: (ShardedThreadPool::WorkThreadSharded::entry()+0x10) [0x7f83b5f7d4c0]
17: (()+0x7dc5) [0x7f83b3eb9dc5]
18: (clone()+0x6d) [0x7f83b2544ced]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- logging levels ---
0/ 0 none
0/ 0 lockdep
0/ 0 context
0/ 0 crush
0/ 0 mds
0/ 0 mds_balancer
0/ 0 mds_locker
0/ 0 mds_log
0/ 0 mds_log_expire
0/ 0 mds_migrator
0/ 0 buffer
0/ 0 timer
0/ 0 filer
0/ 0 striper
20/20 objecter
0/ 0 rados
0/ 0 rbd
0/ 5 rbd_mirror
0/ 0 rbd_replay
0/ 0 journaler
0/ 0 objectcacher
0/ 0 client
20/20 osd
0/ 0 optracker
0/ 0 objclass
0/ 0 filestore
0/ 0 journal
5/ 5 ms
0/ 0 mon
0/ 0 monc
0/ 0 paxos
0/ 0 tp
0/ 0 auth
0/ 0 crypto
0/ 0 finisher
0/ 0 heartbeatmap
0/ 0 perfcounter
0/ 0 rgw
0/ 0 civetweb
0/ 0 javaclient
0/ 0 asok
1/ 1 throttle
0/ 0 refs
0/ 0 xio
1/ 5 compressor
1/ 5 newstore
1/ 5 bluestore
1/ 5 bluefs
1/ 3 bdev
1/ 5 kstore
4/ 5 rocksdb
4/ 5 leveldb
1/ 5 kinetic
1/ 5 fuse
-2/-2 (syslog threshold)
-1/-1 (stderr threshold)
max_recent 10000
max_new 1000
log_file /var/log/ceph/ceph-osd.24.log
--- end dump of recent events ---
2020-07-06 18:40:14.439056 7f83ab2c2700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.211:6813/2669148 conn(0x7f83d0df3800 sd=1587 :6805 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=479 cs=1 l=0). == rx == osd.96 seq 5 0x7f83d151cac0 osd_map(45014..45014 src has 38101..45014) v3
2020-07-06 18:40:14.439199 7f83ab2c2700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.211:6813/2669148 conn(0x7f83d0df3800 sd=1587 :6805 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=479 cs=1 l=0). == rx == osd.96 seq 6 0x7f83d1a6b4a0 pg_notify(1.54c(15) epoch 45014) v5
2020-07-06 18:40:14.439233 7f83ab2c2700 10 osd.24 45014 do_waiters -- start
2020-07-06 18:40:14.439239 7f83ab2c2700 10 osd.24 45014 do_waiters -- finish
2020-07-06 18:40:14.439240 7f83ab2c2700 20 osd.24 45014 _dispatch 0x7f83d151cac0 osd_map(45014..45014 src has 38101..45014) v3
2020-07-06 18:40:14.439975 7f83ac2c4700 1 -- 172.26.216.197:0/2876125 >> 172.26.216.232:6800/2612269 conn(0x7f83d1abb000 sd=1637 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=24277 cs=1 l=1). == rx == osd.60 seq 1 0x7f83d15ade40 osd_op_reply(1 rbd_data.17fdbcbcf6f7e5be5.00000000000005c4 [assert-version v2117975801,copy-get max 8388608] v0'0 uv2117975801 ondisk = 0) v7
2020-07-06 18:40:14.440004 7f83ac2c4700 10 osd.24.objecter ms_dispatch 0x7f83c009e140 osd_op_reply(1 rbd_data.17fdbcbcf6f7e5be5.00000000000005c4 [assert-version v2117975801,copy-get max 8388608] v0'0 uv2117975801 ondisk = 0) v7
2020-07-06 18:40:14.440012 7f83ac2c4700 10 osd.24.objecter in handle_osd_op_reply
2020-07-06 18:40:14.446397 7f83acac5700 1 -- 172.26.224.197:6806/2876125 >> 172.26.224.165:0/500874 conn(0x7f83d0798000 sd=1393 :6806 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=12559 cs=1 l=1). == rx == osd.14 seq 1 0x7f83cf980a00 osd_ping(ping e45014 stamp 2020-07-06 18:40:14.448379) v2
2020-07-06 18:40:14.446452 7f83acac5700 1 -- 172.26.224.197:6806/2876125 >> 172.26.224.165:0/500874 conn(0x7f83d0798000 sd=1393 :6806 s=STATE_OPEN pgs=12559 cs=1 l=1). == tx == 0x7f83cf667c00 osd_ping(ping_reply e45014 stamp 2020-07-06 18:40:14.448379) v2
2020-07-06 18:40:14.446495 7f83acac5700 10 osd.24 45014 note_peer_epoch osd.14 has 45014
2020-07-06 18:40:14.446504 7f83acac5700 20 osd.24 45014 share_map_peer 0x7f83d07b0800 already has epoch 45014
2020-07-06 18:40:14.483186 7f8385487700 -1 *** Caught signal (Aborted) **
in thread 7f8385487700 thread_name:tp_osd_tp

ceph version 10.2.2 (45107e21c568dd033c2f0a3107dec8f0b0e58374)
1: (()+0x91341a) [0x7f83b5e8b41a]
2: (()+0xf100) [0x7f83b3ec1100]
3: (gsignal()+0x37) [0x7f83b24835f7]
4: (abort()+0x148) [0x7f83b2484ce8]
5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x267) [0x7f83b5f8b797]
6: (Throttle::take(long)+0x2fc) [0x7f83b5f6f73c]
7: (Objecter::_op_submit_with_budget(Objecter::Op*, ceph::shunique_lock<boost::shared_mutex>&, unsigned long*, int*)+0x2d2) [0x7f83b5b48652]
8: (Objecter::op_submit(Objecter::Op*, unsigned long*, int*)+0xed) [0x7f83b5b488dd]
9: (ReplicatedPG::_copy_some(std::shared_ptr<ObjectContext>, std::shared_ptr<ReplicatedPG::CopyOp>)+0xfb0) [0x7f83b5a42420]
10: (ReplicatedPG::start_copy(ReplicatedPG::CopyCallback*, std::shared_ptr<ObjectContext>, hobject_t, object_locator_t, unsigned long, unsigned int, bool, unsigned int, unsigned int)+0x682) [0x7f83b5a433c2]
11: (ReplicatedPG::do_osd_ops(ReplicatedPG::OpContext*, std::vector<OSDOp, std::allocator<OSDOp> >&)+0xa34a) [0x7f83b5a7ccca]
12: (ReplicatedPG::prepare_transaction(ReplicatedPG::OpContext*)+0xbf) [0x7f83b5a8a83f]
13: (ReplicatedPG::execute_ctx(ReplicatedPG::OpContext*)+0x8f0) [0x7f83b5a8b6f0]
14: (ReplicatedPG::do_op(std::shared_ptr<OpRequest>&)+0x3740) [0x7f83b5a90560]
15: (ReplicatedPG::do_request(std::shared_ptr<OpRequest>&, ThreadPool::TPHandle&)+0x747) [0x7f83b5a4be57]
16: (OSD::dequeue_op(boost::intrusive_ptr<PG>, std::shared_ptr<OpRequest>, ThreadPool::TPHandle&)+0x41d) [0x7f83b5900a8d]
17: (PGQueueable::RunVis::operator()(std::shared_ptr<OpRequest>&)+0x6d) [0x7f83b5900cdd]
18: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0x869) [0x7f83b5905809]
19: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x887) [0x7f83b5f7b557]
20: (ShardedThreadPool::WorkThreadSharded::entry()+0x10) [0x7f83b5f7d4c0]
21: (()+0x7dc5) [0x7f83b3eb9dc5]
22: (clone()+0x6d) [0x7f83b2544ced]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
-12> 2020-07-06 18:40:14.439056 7f83ab2c2700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.211:6813/2669148 conn(0x7f83d0df3800 sd=1587 :6805 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=479 cs=1 l=0). == rx == osd.96 seq 5 0x7f83d151cac0 osd_map(45014..45014 src has 38101..45014) v3
-11> 2020-07-06 18:40:14.439199 7f83ab2c2700 1 -- 172.26.224.197:6805/2876125 >> 172.26.224.211:6813/2669148 conn(0x7f83d0df3800 sd=1587 :6805 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=479 cs=1 l=0). == rx == osd.96 seq 6 0x7f83d1a6b4a0 pg_notify(1.54c(15) epoch 45014) v5
-10> 2020-07-06 18:40:14.439233 7f83ab2c2700 10 osd.24 45014 do_waiters -- start
-9> 2020-07-06 18:40:14.439239 7f83ab2c2700 10 osd.24 45014 do_waiters -- finish
-8> 2020-07-06 18:40:14.439240 7f83ab2c2700 20 osd.24 45014 _dispatch 0x7f83d151cac0 osd_map(45014..45014 src has 38101..45014) v3
-7> 2020-07-06 18:40:14.439975 7f83ac2c4700 1 -- 172.26.216.197:0/2876125 >> 172.26.216.232:6800/2612269 conn(0x7f83d1abb000 sd=1637 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=24277 cs=1 l=1). == rx == osd.60 seq 1 0x7f83d15ade40 osd_op_reply(1 rbd_data.17fdbcbcf6f7e5be5.00000000000005c4 [assert-version v2117975801,copy-get max 8388608] v0'0 uv2117975801 ondisk = 0) v7
-6> 2020-07-06 18:40:14.440004 7f83ac2c4700 10 osd.24.objecter ms_dispatch 0x7f83c009e140 osd_op_reply(1 rbd_data.17fdbcbcf6f7e5be5.00000000000005c4 [assert-version v2117975801,copy-get max 8388608] v0'0 uv2117975801 ondisk = 0) v7
-5> 2020-07-06 18:40:14.440012 7f83ac2c4700 10 osd.24.objecter in handle_osd_op_reply
-4> 2020-07-06 18:40:14.446397 7f83acac5700 1 -- 172.26.224.197:6806/2876125 >> 172.26.224.165:0/500874 conn(0x7f83d0798000 sd=1393 :6806 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=12559 cs=1 l=1). == rx == osd.14 seq 1 0x7f83cf980a00 osd_ping(ping e45014 stamp 2020-07-06 18:40:14.448379) v2
-3> 2020-07-06 18:40:14.446452 7f83acac5700 1 -- 172.26.224.197:6806/2876125 >> 172.26.224.165:0/500874 conn(0x7f83d0798000 sd=1393 :6806 s=STATE_OPEN pgs=12559 cs=1 l=1). == tx == 0x7f83cf667c00 osd_ping(ping_reply e45014 stamp 2020-07-06 18:40:14.448379) v2
-2> 2020-07-06 18:40:14.446495 7f83acac5700 10 osd.24 45014 note_peer_epoch osd.14 has 45014
-1> 2020-07-06 18:40:14.446504 7f83acac5700 20 osd.24 45014 share_map_peer 0x7f83d07b0800 already has epoch 45014
0> 2020-07-06 18:40:14.483186 7f8385487700 -1 *** Caught signal (Aborted) **
in thread 7f8385487700 thread_name:tp_osd_tp

ceph version 10.2.2 (45107e21c568dd033c2f0a3107dec8f0b0e58374)
1: (()+0x91341a) [0x7f83b5e8b41a]
2: (()+0xf100) [0x7f83b3ec1100]
3: (gsignal()+0x37) [0x7f83b24835f7]
4: (abort()+0x148) [0x7f83b2484ce8]
5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x267) [0x7f83b5f8b797]
6: (Throttle::take(long)+0x2fc) [0x7f83b5f6f73c]
7: (Objecter::_op_submit_with_budget(Objecter::Op*, ceph::shunique_lock<boost::shared_mutex>&, unsigned long*, int*)+0x2d2) [0x7f83b5b48652]
8: (Objecter::op_submit(Objecter::Op*, unsigned long*, int*)+0xed) [0x7f83b5b488dd]
9: (ReplicatedPG::_copy_some(std::shared_ptr<ObjectContext>, std::shared_ptr<ReplicatedPG::CopyOp>)+0xfb0) [0x7f83b5a42420]
10: (ReplicatedPG::start_copy(ReplicatedPG::CopyCallback*, std::shared_ptr<ObjectContext>, hobject_t, object_locator_t, unsigned long, unsigned int, bool, unsigned int, unsigned int)+0x682) [0x7f83b5a433c2]
11: (ReplicatedPG::do_osd_ops(ReplicatedPG::OpContext*, std::vector<OSDOp, std::allocator<OSDOp> >&)+0xa34a) [0x7f83b5a7ccca]
12: (ReplicatedPG::prepare_transaction(ReplicatedPG::OpContext*)+0xbf) [0x7f83b5a8a83f]
13: (ReplicatedPG::execute_ctx(ReplicatedPG::OpContext*)+0x8f0) [0x7f83b5a8b6f0]
14: (ReplicatedPG::do_op(std::shared_ptr<OpRequest>&)+0x3740) [0x7f83b5a90560]
15: (ReplicatedPG::do_request(std::shared_ptr<OpRequest>&, ThreadPool::TPHandle&)+0x747) [0x7f83b5a4be57]
16: (OSD::dequeue_op(boost::intrusive_ptr<PG>, std::shared_ptr<OpRequest>, ThreadPool::TPHandle&)+0x41d) [0x7f83b5900a8d]
17: (PGQueueable::RunVis::operator()(std::shared_ptr<OpRequest>&)+0x6d) [0x7f83b5900cdd]
18: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0x869) [0x7f83b5905809]
19: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x887) [0x7f83b5f7b557]
20: (ShardedThreadPool::WorkThreadSharded::entry()+0x10) [0x7f83b5f7d4c0]
21: (()+0x7dc5) [0x7f83b3eb9dc5]
22: (clone()+0x6d) [0x7f83b2544ced]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- logging levels ---
0/ 0 none
0/ 0 lockdep
0/ 0 context
0/ 0 crush
0/ 0 mds
0/ 0 mds_balancer
0/ 0 mds_locker
0/ 0 mds_log
0/ 0 mds_log_expire
0/ 0 mds_migrator
0/ 0 buffer
0/ 0 timer
0/ 0 filer
0/ 0 striper
20/20 objecter
0/ 0 rados
0/ 0 rbd
0/ 5 rbd_mirror
0/ 0 rbd_replay
0/ 0 journaler
0/ 0 objectcacher
0/ 0 client
20/20 osd
0/ 0 optracker
0/ 0 objclass
0/ 0 filestore
0/ 0 journal
5/ 5 ms
0/ 0 mon
0/ 0 monc
0/ 0 paxos
0/ 0 tp
0/ 0 auth
0/ 0 crypto
0/ 0 finisher
0/ 0 heartbeatmap
0/ 0 perfcounter
0/ 0 rgw
0/ 0 civetweb
0/ 0 javaclient
0/ 0 asok
1/ 1 throttle
0/ 0 refs
0/ 0 xio
1/ 5 compressor
1/ 5 newstore
1/ 5 bluestore
1/ 5 bluefs
1/ 3 bdev
1/ 5 kstore
4/ 5 rocksdb
4/ 5 leveldb
1/ 5 kinetic
1/ 5 fuse
-2/-2 (syslog threshold)
-1/-1 (stderr threshold)
max_recent 10000
max_new 1000
log_file /var/log/ceph/ceph-osd.24.log
--- end dump of recent events ---
(1-1/2)