roel-disk-4-snapshot-create.log - bluestore - Ceph

Bug #58707 » roel-disk-4-snapshot-create.log

Debug log of rbd snap create of roel-disk-4@snapshot - Roel van Meer, 03/13/2023 01:09 PM

 -03-13T14:06:19.086+0100 7ff19c6e9340  1  Processor -- start
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --  start start
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --2-  >> v2:172.18.16.155:3300/0 conn(0x5581e58090c0 0x5581e580b4b0 unknown :-1 s=NONE pgs=0 cs=0 l=0 rev1=0 rx=0 tx=0).connect
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --2-  >> v2:172.18.16.101:3300/0 conn(0x5581e580b9a0 0x5581e580de60 unknown :-1 s=NONE pgs=0 cs=0 l=0 rev1=0 rx=0 tx=0).connect
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --  --> v1:172.18.16.153:6789/0 -- auth(proto 0 30 bytes epoch 0) v1 -- 0x5581e56e6170 con 0x5581e5804bd0
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --  --> v2:172.18.16.101:3300/0 -- mon_getmap magic: 0 v1 -- 0x5581e56edb20 con 0x5581e580b9a0
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --  --> v2:172.18.16.155:3300/0 -- mon_getmap magic: 0 v1 -- 0x5581e56b34c0 con 0x5581e58090c0
 -03-13T14:06:19.086+0100 7ff19a317700  1 --2-  >> v2:172.18.16.155:3300/0 conn(0x5581e58090c0 0x5581e580b4b0 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=0 rev1=0 rx=0 tx=0)._handle_peer_banner_payload supported=1 required=0
 -03-13T14:06:19.086+0100 7ff19a317700  1 --2-  >> v2:172.18.16.155:3300/0 conn(0x5581e58090c0 0x5581e580b4b0 unknown :-1 s=HELLO_CONNECTING pgs=0 cs=0 l=0 rev1=1 rx=0 tx=0).handle_hello peer v2:172.18.16.155:3300/0 says I am v2:172.18.16.209:50586/0 (socket says 172.18.16.209:50586)
 -03-13T14:06:19.086+0100 7ff19a317700  1 -- 172.18.16.209:0/2572290712 learned_addr learned my addr 172.18.16.209:0/2572290712 (peer_addr_for_me v2:172.18.16.209:0/0)
 -03-13T14:06:19.086+0100 7ff19b319700  1 --2- 172.18.16.209:0/2572290712 >> v2:172.18.16.101:3300/0 conn(0x5581e580b9a0 0x5581e580de60 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=0 rev1=0 rx=0 tx=0)._handle_peer_banner_payload supported=1 required=0
 -03-13T14:06:19.086+0100 7ff19a317700  1 -- 172.18.16.209:0/2572290712 >> v2:172.18.16.101:3300/0 conn(0x5581e580b9a0 msgr2=0x5581e580de60 unknown :-1 s=STATE_CONNECTION_ESTABLISHED l=0).mark_down
 -03-13T14:06:19.086+0100 7ff19a317700  1 --2- 172.18.16.209:0/2572290712 >> v2:172.18.16.101:3300/0 conn(0x5581e580b9a0 0x5581e580de60 unknown :-1 s=AUTH_CONNECTING pgs=0 cs=0 l=0 rev1=1 rx=0 tx=0).stop
 -03-13T14:06:19.086+0100 7ff19a317700  1 -- 172.18.16.209:0/2572290712 >> v1:172.18.16.153:6789/0 conn(0x5581e5804bd0 legacy=0x5581e5804ff0 unknown :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
 -03-13T14:06:19.086+0100 7ff19a317700  1 -- 172.18.16.209:0/2572290712 --> v2:172.18.16.155:3300/0 -- mon_subscribe({config=0+,monmap=0+}) v3 -- 0x5581e56e18f0 con 0x5581e58090c0
 -03-13T14:06:19.086+0100 7ff19b319700  1 --2- 172.18.16.209:0/2572290712 >> v2:172.18.16.101:3300/0 conn(0x5581e580b9a0 0x5581e580de60 unknown :-1 s=CLOSED pgs=0 cs=0 l=0 rev1=1 rx=0 tx=0).handle_auth_done state changed!
 -03-13T14:06:19.086+0100 7ff19a317700  1 --2- 172.18.16.209:0/2572290712 >> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] conn(0x5581e58090c0 0x5581e580b4b0 secure :-1 s=READY pgs=12677484 cs=0 l=1 rev1=1 rx=0x5581e5805970 tx=0x7ff184005b10).ready entity=mon.4 client_cookie=cf73ed7fca0e8c49 server_cookie=0 in_seq=0 out_seq=0
 -03-13T14:06:19.086+0100 7ff199b16700  1 -- 172.18.16.209:0/2572290712 <== mon.4 v2:172.18.16.155:3300/0 1 ==== mon_map magic: 0 v1 ==== 816+0+0 (secure 0 0 0) 0x7ff184008aa0 con 0x5581e58090c0
 -03-13T14:06:19.086+0100 7ff199b16700  1 -- 172.18.16.209:0/2572290712 <== mon.4 v2:172.18.16.155:3300/0 2 ==== config(0 keys) v1 ==== 4+0+0 (secure 0 0 0) 0x7ff184008c00 con 0x5581e58090c0
 -03-13T14:06:19.086+0100 7ff199b16700  1 -- 172.18.16.209:0/2572290712 <== mon.4 v2:172.18.16.155:3300/0 3 ==== mon_map magic: 0 v1 ==== 816+0+0 (secure 0 0 0) 0x7ff1840137e0 con 0x5581e58090c0
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 -- 172.18.16.209:0/2572290712 >> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] conn(0x5581e58090c0 msgr2=0x5581e580b4b0 secure :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/2572290712 >> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] conn(0x5581e58090c0 0x5581e580b4b0 secure :-1 s=READY pgs=12677484 cs=0 l=1 rev1=1 rx=0x5581e5805970 tx=0x7ff184005b10).stop
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 -- 172.18.16.209:0/2572290712 shutdown_connections
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/2572290712 >> v2:172.18.16.101:3300/0 conn(0x5581e580b9a0 0x5581e580de60 unknown :-1 s=CLOSED pgs=0 cs=0 l=0 rev1=1 rx=0 tx=0).stop
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/2572290712 >> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] conn(0x5581e58090c0 0x5581e580b4b0 unknown :-1 s=CLOSED pgs=12677484 cs=0 l=1 rev1=1 rx=0 tx=0).stop
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 -- 172.18.16.209:0/2572290712 >> 172.18.16.209:0/2572290712 conn(0x5581e57fffe0 msgr2=0x5581e5802440 unknown :-1 s=STATE_NONE l=0).mark_down
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 -- 172.18.16.209:0/2572290712 shutdown_connections
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 -- 172.18.16.209:0/2572290712 wait complete.
 -03-13T14:06:19.086+0100 7ff19c6e9340  1  Processor -- start
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --  start start
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --2-  >> [v2:172.18.16.153:3300/0,v1:172.18.16.153:6789/0] conn(0x5581e5804bd0 0x5581e58117d0 unknown :-1 s=NONE pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0).connect
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --2-  >> [v2:172.18.16.103:3300/0,v1:172.18.16.103:6789/0] conn(0x5581e58090c0 0x5581e5811cc0 unknown :-1 s=NONE pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0).connect
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --2-  >> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] conn(0x5581e580b9a0 0x5581e5818e20 unknown :-1 s=NONE pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0).connect
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --  --> [v2:172.18.16.103:3300/0,v1:172.18.16.103:6789/0] -- mon_getmap magic: 0 v1 -- 0x5581e56b8500 con 0x5581e58090c0
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --  --> [v2:172.18.16.153:3300/0,v1:172.18.16.153:6789/0] -- mon_getmap magic: 0 v1 -- 0x5581e58193a0 con 0x5581e5804bd0
 -03-13T14:06:19.086+0100 7ff19c6e9340  1 --  --> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] -- mon_getmap magic: 0 v1 -- 0x5581e5819510 con 0x5581e580b9a0
 -03-13T14:06:19.086+0100 7ff19b319700  1 --2-  >> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] conn(0x5581e580b9a0 0x5581e5818e20 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0)._handle_peer_banner_payload supported=1 required=0
 -03-13T14:06:19.086+0100 7ff19b319700  1 --2-  >> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] conn(0x5581e580b9a0 0x5581e5818e20 unknown :-1 s=HELLO_CONNECTING pgs=0 cs=0 l=1 rev1=1 rx=0 tx=0).handle_hello peer v2:172.18.16.155:3300/0 says I am v2:172.18.16.209:50592/0 (socket says 172.18.16.209:50592)
 -03-13T14:06:19.086+0100 7ff19b319700  1 -- 172.18.16.209:0/1425925285 learned_addr learned my addr 172.18.16.209:0/1425925285 (peer_addr_for_me v2:172.18.16.209:0/0)
 -03-13T14:06:19.086+0100 7ff19a317700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.103:3300/0,v1:172.18.16.103:6789/0] conn(0x5581e58090c0 0x5581e5811cc0 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0)._handle_peer_banner_payload supported=1 required=0
 -03-13T14:06:19.086+0100 7ff19ab18700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.153:3300/0,v1:172.18.16.153:6789/0] conn(0x5581e5804bd0 0x5581e58117d0 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0)._handle_peer_banner_payload supported=1 required=0
 -03-13T14:06:19.086+0100 7ff19b319700  1 -- 172.18.16.209:0/1425925285 >> [v2:172.18.16.153:3300/0,v1:172.18.16.153:6789/0] conn(0x5581e5804bd0 msgr2=0x5581e58117d0 unknown :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
 -03-13T14:06:19.086+0100 7ff19b319700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.153:3300/0,v1:172.18.16.153:6789/0] conn(0x5581e5804bd0 0x5581e58117d0 unknown :-1 s=AUTH_CONNECTING pgs=0 cs=0 l=1 rev1=1 rx=0 tx=0).stop
 -03-13T14:06:19.086+0100 7ff19b319700  1 -- 172.18.16.209:0/1425925285 >> [v2:172.18.16.103:3300/0,v1:172.18.16.103:6789/0] conn(0x5581e58090c0 msgr2=0x5581e5811cc0 unknown :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
 -03-13T14:06:19.086+0100 7ff19b319700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.103:3300/0,v1:172.18.16.103:6789/0] conn(0x5581e58090c0 0x5581e5811cc0 unknown :-1 s=AUTH_CONNECTING pgs=0 cs=0 l=1 rev1=1 rx=0 tx=0).stop
 -03-13T14:06:19.086+0100 7ff19b319700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] -- mon_subscribe({config=0+,monmap=0+}) v3 -- 0x7ff19400a0e0 con 0x5581e580b9a0
 -03-13T14:06:19.086+0100 7ff19b319700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] conn(0x5581e580b9a0 0x5581e5818e20 secure :-1 s=READY pgs=12677485 cs=0 l=1 rev1=1 rx=0x7ff19400d900 tx=0x7ff194007040).ready entity=mon.4 client_cookie=0 server_cookie=0 in_seq=0 out_seq=0
 -03-13T14:06:19.090+0100 7ff1937fe700  1 -- 172.18.16.209:0/1425925285 <== mon.4 v2:172.18.16.155:3300/0 1 ==== mon_map magic: 0 v1 ==== 816+0+0 (secure 0 0 0) 0x7ff1940119a0 con 0x5581e580b9a0
 -03-13T14:06:19.090+0100 7ff1937fe700  1 -- 172.18.16.209:0/1425925285 <== mon.4 v2:172.18.16.155:3300/0 2 ==== config(0 keys) v1 ==== 4+0+0 (secure 0 0 0) 0x7ff194011b00 con 0x5581e580b9a0
 -03-13T14:06:19.090+0100 7ff1937fe700  1 -- 172.18.16.209:0/1425925285 <== mon.4 v2:172.18.16.155:3300/0 3 ==== mon_map magic: 0 v1 ==== 816+0+0 (secure 0 0 0) 0x7ff19400f720 con 0x5581e580b9a0
 -03-13T14:06:19.090+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] -- mon_subscribe({mgrmap=0+}) v3 -- 0x7ff184005db0 con 0x5581e580b9a0
 -03-13T14:06:19.090+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] -- mon_subscribe({osdmap=0}) v3 -- 0x5581e56bc2f0 con 0x5581e580b9a0
 -03-13T14:06:19.094+0100 7ff1937fe700  1 -- 172.18.16.209:0/1425925285 <== mon.4 v2:172.18.16.155:3300/0 4 ==== mgrmap(e 682) v1 ==== 307866+0+0 (secure 0 0 0) 0x7ff194021070 con 0x5581e580b9a0
 -03-13T14:06:19.098+0100 7ff1937fe700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.151:6898/19419,v1:172.18.16.151:6899/19419] conn(0x7ff17c18c750 0x7ff17c18ec10 unknown :-1 s=NONE pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0).connect
 -03-13T14:06:19.098+0100 7ff1937fe700  1 -- 172.18.16.209:0/1425925285 <== mon.4 v2:172.18.16.155:3300/0 5 ==== osd_map(521433..521433 src has 520735..521433) v4 ==== 85401+0+0 (secure 0 0 0) 0x7ff1941f5bd0 con 0x5581e580b9a0
 -03-13T14:06:19.098+0100 7ff19ab18700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.151:6898/19419,v1:172.18.16.151:6899/19419] conn(0x7ff17c18c750 0x7ff17c18ec10 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0)._handle_peer_banner_payload supported=1 required=0
 -03-13T14:06:19.098+0100 7ff19ab18700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.151:6898/19419,v1:172.18.16.151:6899/19419] conn(0x7ff17c18c750 0x7ff17c18ec10 secure :-1 s=READY pgs=18504011 cs=0 l=1 rev1=1 rx=0x5581e5812d80 tx=0x7ff18c000bc0).ready entity=mgr.1959232099 client_cookie=0 server_cookie=0 in_seq=0 out_seq=0
 -03-13T14:06:19.098+0100 7ff19c6e9340 20 librbd::asio::ContextWQ: 0x5581e5861370 ContextWQ:
 -03-13T14:06:19.098+0100 7ff19c6e9340 20 librbd::AsioEngine: 0x5581e5860c00 AsioEngine:
 -03-13T14:06:19.098+0100 7ff19c6e9340 10 librbd::ImageCtx: 0x5581e5819c60 ImageCtx: image_name=roel-disk-4, image_id=
 -03-13T14:06:19.098+0100 7ff19c6e9340  5 librbd::io::Dispatcher: 0x5581e580e710 register_dispatch: dispatch_layer=10
 -03-13T14:06:19.098+0100 7ff19c6e9340  5 librbd::io::QueueImageDispatch: 0x5581e580e7d0 QueueImageDispatch: ictx=0x5581e5819c60
 -03-13T14:06:19.098+0100 7ff19c6e9340  5 librbd::io::Dispatcher: 0x5581e580e710 register_dispatch: dispatch_layer=1
 -03-13T14:06:19.098+0100 7ff19c6e9340  5 librbd::io::QosImageDispatch: 0x5581e580e870 QosImageDispatch: ictx=0x5581e5819c60
 -03-13T14:06:19.102+0100 7ff19c6e9340  5 librbd::io::Dispatcher: 0x5581e580e710 register_dispatch: dispatch_layer=2
 -03-13T14:06:19.102+0100 7ff19c6e9340  5 librbd::io::RefreshImageDispatch: 0x5581e580ed80 RefreshImageDispatch: ictx=0x5581e5819c60
 -03-13T14:06:19.102+0100 7ff19c6e9340  5 librbd::io::Dispatcher: 0x5581e580e710 register_dispatch: dispatch_layer=4
 -03-13T14:06:19.102+0100 7ff19c6e9340  5 librbd::io::WriteBlockImageDispatch: 0x5581e5766cf0 WriteBlockImageDispatch: ictx=0x5581e5819c60
 -03-13T14:06:19.102+0100 7ff19c6e9340  5 librbd::io::Dispatcher: 0x5581e580e710 register_dispatch: dispatch_layer=7
 -03-13T14:06:19.102+0100 7ff19c6e9340  5 librbd::io::Dispatcher: 0x5581e58614a0 register_dispatch: dispatch_layer=6
 -03-13T14:06:19.102+0100 7ff19c6e9340 20 librbd::ImageState: 0x5581e5861420 open
 -03-13T14:06:19.102+0100 7ff19c6e9340 10 librbd::ImageState: 0x5581e5861420 0x5581e5861420 send_open_unlock
 -03-13T14:06:19.102+0100 7ff19c6e9340 10 librbd::image::OpenRequest: 0x5581e5862930 send_v2_detect_header
 -03-13T14:06:19.102+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6819/9074,v1:172.18.16.107:6822/9074] conn(0x5581e5866690 0x5581e5868a80 unknown :-1 s=NONE pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0).connect
 -03-13T14:06:19.102+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.107:6819/9074,v1:172.18.16.107:6822/9074] -- osd_op(unknown.0.0:1 15213.189 15213:91a3bdfd:::rbd_id.roel-disk-4:head [stat] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x5581e5869010 con 0x5581e5866690
 -03-13T14:06:19.102+0100 7ff19a317700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6819/9074,v1:172.18.16.107:6822/9074] conn(0x5581e5866690 0x5581e5868a80 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0)._handle_peer_banner_payload supported=1 required=0
 -03-13T14:06:19.102+0100 7ff19a317700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6819/9074,v1:172.18.16.107:6822/9074] conn(0x5581e5866690 0x5581e5868a80 crc :-1 s=READY pgs=16172 cs=0 l=1 rev1=1 rx=0 tx=0).ready entity=osd.65 client_cookie=0 server_cookie=0 in_seq=0 out_seq=0
 -03-13T14:06:19.102+0100 7ff19a317700  1 -- 172.18.16.209:0/1425925285 <== osd.65 v2:172.18.16.107:6819/9074 1 ==== osd_op_reply(1 rbd_id.roel-disk-4 [stat out=16b] v0'0 uv114183615 ondisk = 0) v8 ==== 162+0+16 (crc 0 0 0) 0x7ff184008700 con 0x5581e5866690
 -03-13T14:06:19.102+0100 7ff198b14700 10 librbd::image::OpenRequest: handle_v2_detect_header: r=0
 -03-13T14:06:19.102+0100 7ff198b14700 10 librbd::image::OpenRequest: 0x5581e5862930 send_v2_get_id
 -03-13T14:06:19.102+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.107:6819/9074,v1:172.18.16.107:6822/9074] -- osd_op(unknown.0.0:2 15213.189 15213:91a3bdfd:::rbd_id.roel-disk-4:head [call rbd.get_id in=9b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff174003750 con 0x5581e5866690
 -03-13T14:06:19.102+0100 7ff19a317700  1 -- 172.18.16.209:0/1425925285 <== osd.65 v2:172.18.16.107:6819/9074 2 ==== osd_op_reply(2 rbd_id.roel-disk-4 [call out=18b] v0'0 uv114183615 ondisk = 0) v8 ==== 162+0+18 (crc 0 0 0) 0x7ff184008700 con 0x5581e5866690
 -03-13T14:06:19.102+0100 7ff199315700 10 librbd::image::OpenRequest: handle_v2_get_id: r=0
 -03-13T14:06:19.102+0100 7ff199315700 10 librbd::image::OpenRequest: 0x5581e5862930 send_v2_get_initial_metadata
 -03-13T14:06:19.102+0100 7ff199315700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] conn(0x7ff180008740 0x7ff18000abc0 unknown :-1 s=NONE pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0).connect
 -03-13T14:06:19.102+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:3 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call rbd.get_size in=19b,call rbd.get_object_prefix in=20b,call rbd.get_features in=24b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff18000c3d0 con 0x7ff180008740
 -03-13T14:06:19.102+0100 7ff19ab18700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] conn(0x7ff180008740 0x7ff18000abc0 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0)._handle_peer_banner_payload supported=1 required=0
 -03-13T14:06:19.102+0100 7ff19ab18700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] conn(0x7ff180008740 0x7ff18000abc0 crc :-1 s=READY pgs=17779 cs=0 l=1 rev1=1 rx=0 tx=0).ready entity=osd.70 client_cookie=0 server_cookie=0 in_seq=0 out_seq=0
 -03-13T14:06:19.102+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 1 ==== osd_op_reply(3 rbd_header.be32ac9b290c61 [call out=9b,call out=27b,call out=16b] v0'0 uv190147833 ondisk = 0) v8 ==== 253+0+52 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.102+0100 7ff198b14700 10 librbd::image::OpenRequest: handle_v2_get_initial_metadata: r=0
 -03-13T14:06:19.102+0100 7ff198b14700 10 librbd::image::OpenRequest: 0x5581e5862930 send_v2_get_create_timestamp
 -03-13T14:06:19.102+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:4 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call rbd.get_create_timestamp in=23b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff174004e50 con 0x7ff180008740
 -03-13T14:06:19.102+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 2 ==== osd_op_reply(4 rbd_header.be32ac9b290c61 [call out=8b] v0'0 uv190147833 ondisk = 0) v8 ==== 169+0+8 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.102+0100 7ff199315700 10 librbd::image::OpenRequest: 0x5581e5862930 handle_v2_get_create_timestamp: r=0
 -03-13T14:06:19.102+0100 7ff199315700 10 librbd::image::OpenRequest: 0x5581e5862930 send_v2_get_access_modify_timestamp
 -03-13T14:06:19.102+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:5 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call rbd.get_access_timestamp in=23b,call rbd.get_modify_timestamp in=23b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff180003960 con 0x7ff180008740
 -03-13T14:06:19.102+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 3 ==== osd_op_reply(5 rbd_header.be32ac9b290c61 [call out=8b,call out=8b] v0'0 uv190147833 ondisk = 0) v8 ==== 211+0+16 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.102+0100 7ff198b14700 10 librbd::image::OpenRequest: 0x5581e5862930 handle_v2_get_access_modify_timestamp: r=0
 -03-13T14:06:19.102+0100 7ff198b14700 10 librbd::image::OpenRequest: 0x5581e5862930 send_v2_get_data_pool
 -03-13T14:06:19.102+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:6 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call rbd.get_data_pool in=16b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff174005280 con 0x7ff180008740
 -03-13T14:06:19.102+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 4 ==== osd_op_reply(6 rbd_header.be32ac9b290c61 [call out=8b] v0'0 uv190147833 ondisk = 0) v8 ==== 169+0+8 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.102+0100 7ff199315700 10 librbd::image::OpenRequest: 0x5581e5862930 handle_v2_get_data_pool: r=0
 -03-13T14:06:19.102+0100 7ff199315700 10 librbd::ImageCtx: init_layout stripe_unit 4194304 stripe_count 1 object_size 4194304 prefix rbd_data.be32ac9b290c61 format rbd_data.be32ac9b290c61.%016llx
 -03-13T14:06:19.102+0100 7ff199315700 10 librbd::image::OpenRequest: 0x5581e5862930 send_refresh
 -03-13T14:06:19.102+0100 7ff199315700 10 librbd::ConfigWatcher: init:
 -03-13T14:06:19.102+0100 7ff199315700 10 librbd::image::RefreshRequest: 0x7ff180010b70 send_v2_get_mutable_metadata
 -03-13T14:06:19.102+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:7 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call rbd.get_size in=19b,call rbd.get_features in=24b,call rbd.get_flags in=20b,call rbd.get_snapcontext in=18b,call lock.get_info in=30b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff18001b470 con 0x7ff180008740
 -03-13T14:06:19.102+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 5 ==== osd_op_reply(7 rbd_header.be32ac9b290c61 [call out=9b,call out=16b,call out=8b,call out=12b,call out=120b] v0'0 uv190147833 ondisk = 0) v8 ==== 337+0+165 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.102+0100 7ff198b14700 10 librbd::image::RefreshRequest: 0x7ff180010b70 handle_v2_get_mutable_metadata: r=0
 -03-13T14:06:19.102+0100 7ff198b14700 10 librbd::image::RefreshRequest: 0x7ff180010b70 send_v2_get_parent: legacy=0
 -03-13T14:06:19.102+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:8 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call rbd.parent_get in=13b,call rbd.parent_overlap_get in=29b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff174007b90 con 0x7ff180008740
 -03-13T14:06:19.106+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 6 ==== osd_op_reply(8 rbd_header.be32ac9b290c61 [call out=30b,call out=1b] v0'0 uv190147833 ondisk = 0) v8 ==== 211+0+31 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.106+0100 7ff199315700 10 librbd::image::RefreshRequest: 0x7ff180010b70 handle_v2_get_parent: r=0
 -03-13T14:06:19.106+0100 7ff199315700 10 librbd::image::RefreshRequest: 0x7ff180010b70 send_v2_get_metadata
 -03-13T14:06:19.106+0100 7ff199315700 15 librbd::image::GetMetadataRequest: 0x7ff18001ace0 metadata_list: start_key=conf_
 -03-13T14:06:19.106+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:9 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call rbd.metadata_list in=33b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff18001ada0 con 0x7ff180008740
 -03-13T14:06:19.106+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 7 ==== osd_op_reply(9 rbd_header.be32ac9b290c61 [call out=4b] v0'0 uv190147833 ondisk = 0) v8 ==== 169+0+4 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.106+0100 7ff198b14700 15 librbd::image::GetMetadataRequest: 0x7ff18001ace0 handle_metadata_list: r=0
 -03-13T14:06:19.106+0100 7ff198b14700 15 librbd::image::GetMetadataRequest: 0x7ff18001ace0 finish: r=0
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::image::RefreshRequest: 0x7ff180010b70 handle_v2_get_metadata: r=0
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::image::RefreshRequest: 0x7ff180010b70 send_v2_get_pool_metadata
 -03-13T14:06:19.106+0100 7ff198b14700 15 librbd::image::GetMetadataRequest: 0x7ff174003350 metadata_list: start_key=conf_
 -03-13T14:06:19.106+0100 7ff198b14700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.101:6842/8695,v1:172.18.16.101:6843/8695] conn(0x7ff174007090 0x7ff1740074d0 unknown :-1 s=NONE pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0).connect
 -03-13T14:06:19.106+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.101:6842/8695,v1:172.18.16.101:6843/8695] -- osd_op(unknown.0.0:10 15213.33a 15213:5cea7035:::rbd_info:head [call rbd.metadata_list in=33b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff174009f50 con 0x7ff174007090
 -03-13T14:06:19.106+0100 7ff19a317700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.101:6842/8695,v1:172.18.16.101:6843/8695] conn(0x7ff174007090 0x7ff1740074d0 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0)._handle_peer_banner_payload supported=1 required=0
 -03-13T14:06:19.106+0100 7ff19a317700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.101:6842/8695,v1:172.18.16.101:6843/8695] conn(0x7ff174007090 0x7ff1740074d0 crc :-1 s=READY pgs=43820 cs=0 l=1 rev1=1 rx=0 tx=0).ready entity=osd.4 client_cookie=0 server_cookie=0 in_seq=0 out_seq=0
 -03-13T14:06:19.106+0100 7ff19a317700  1 -- 172.18.16.209:0/1425925285 <== osd.4 v2:172.18.16.101:6842/8695 1 ==== osd_op_reply(10 rbd_info [call out=4b] v0'0 uv2 ondisk = 0) v8 ==== 152+0+4 (crc 0 0 0) 0x7ff184008700 con 0x7ff174007090
 -03-13T14:06:19.106+0100 7ff199315700 15 librbd::image::GetMetadataRequest: 0x7ff174003350 handle_metadata_list: r=0
 -03-13T14:06:19.106+0100 7ff199315700 15 librbd::image::GetMetadataRequest: 0x7ff174003350 finish: r=0
 -03-13T14:06:19.106+0100 7ff199315700 10 librbd::image::RefreshRequest: 0x7ff180010b70 handle_v2_get_pool_metadata: r=0
 -03-13T14:06:19.106+0100 7ff199315700 20 librbd::ImageCtx: apply_metadata
 -03-13T14:06:19.106+0100 7ff199315700  5 librbd::ImageCtx: 0x5581e5819c60: disabling zero-copy writes
 -03-13T14:06:19.106+0100 7ff199315700 10 librbd::image::RefreshRequest: 0x7ff180010b70 send_v2_get_group
 -03-13T14:06:19.106+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:11 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call rbd.image_group_get in=18b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff180017730 con 0x7ff180008740
 -03-13T14:06:19.106+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 8 ==== osd_op_reply(11 rbd_header.be32ac9b290c61 [call out=18b] v0'0 uv190147833 ondisk = 0) v8 ==== 169+0+18 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::image::RefreshRequest: 0x7ff180010b70 handle_v2_get_group: r=0
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::image::RefreshRequest: 0x7ff180010b70 send_v2_init_exclusive_lock
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::ExclusiveLock: 0x7ff174001f80 init: features=61
 -03-13T14:06:19.106+0100 7ff198b14700  5 librbd::io::Dispatcher: 0x5581e580e710 register_dispatch: dispatch_layer=3
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::exclusive_lock::ImageDispatch: 0x7ff1740021d0 set_require_lock: direction=1, enabled=1
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::io::AsyncOperation: 0x7ff1740023c0 start_op
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e580e710 send: dispatch_spec=0x7ff174002420
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::io::RefreshImageDispatch: 0x5581e580ed80 flush: tid=1
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::io::WriteBlockImageDispatch: 0x5581e5766cf0 flush: tid=1
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::io::ImageDispatch: 0x5581e580e7b0 flush:
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::io::ImageRequest: 0x7ff198b0ecf0 send: aio_flush: ictx=0x5581e5819c60, completion=0x7ff1740022b0
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff1740022b0 set_request_count: pending=1
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e58614a0 send: dispatch_spec=0x7ff174002510
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff1740022b0 complete_request: cb=1, pending=0
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff1740022b0 finalize: r=0
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::image::RefreshRequest: 0x7ff180010b70 handle_v2_init_exclusive_lock: r=0
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::image::RefreshRequest: 0x7ff180010b70 send_v2_apply
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::io::AsyncOperation: 0x7ff1740023c0 finish_op
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::image::RefreshRequest: 0x7ff180010b70 handle_v2_apply
 -03-13T14:06:19.106+0100 7ff198b14700 20 librbd::image::RefreshRequest: 0x7ff180010b70 apply
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::image::OpenRequest: handle_refresh: r=0
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::image::OpenRequest: send_init_plugin_registry: plugins=
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::image::OpenRequest: handle_init_plugin_registry: r=0
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::image::OpenRequest: 0x5581e5862930 send_init_cache
 -03-13T14:06:19.106+0100 7ff198b14700  5 librbd::cache::WriteAroundObjectDispatch: 0x7ff174002730 init:
 -03-13T14:06:19.106+0100 7ff198b14700  5 librbd::io::Dispatcher: 0x5581e58614a0 register_dispatch: dispatch_layer=1
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::image::OpenRequest: 0x5581e5862930 send_register_watch
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::Watcher: 0x7ff180007790 register_watch:
 -03-13T14:06:19.106+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:12 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [watch watch cookie 140675010013520] snapc 0=[] ondisk+write+known_if_redirected e521433) v8 -- 0x7ff174005cd0 con 0x7ff180008740
 -03-13T14:06:19.106+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 9 ==== osd_op_reply(12 rbd_header.be32ac9b290c61 [watch watch cookie 140675010013520] v521433'190148196 uv190147833 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.106+0100 7ff199315700 10 librbd::Watcher: 0x7ff180007790 handle_register_watch: r=0
 -03-13T14:06:19.106+0100 7ff199315700 10 librbd::image::OpenRequest: 0x5581e5862930 handle_register_watch: r=0
 -03-13T14:06:19.106+0100 7ff199315700  5 librbd::io::SimpleSchedulerObjectDispatch: 0x7ff174003350 SimpleSchedulerObjectDispatch: ictx=0x5581e5819c60
 -03-13T14:06:19.106+0100 7ff199315700  5 librbd::io::SimpleSchedulerObjectDispatch: 0x7ff174003350 init:
 -03-13T14:06:19.106+0100 7ff199315700  5 librbd::io::Dispatcher: 0x5581e58614a0 register_dispatch: dispatch_layer=5
 -03-13T14:06:19.106+0100 7ff199315700 10 librbd::ImageState: 0x5581e5861420 0x5581e5861420 handle_open: r=0
 -03-13T14:06:19.106+0100 7ff19c6e9340 20 librbd::api::Snapshot: create: snap_create 0x5581e5819c60 snapshot flags: 0
 -03-13T14:06:19.106+0100 7ff19c6e9340  5 librbd::Operations: 0x5581e5860fe0 snap_create: snap_name=snapshot
 -03-13T14:06:19.106+0100 7ff19c6e9340 20 librbd::ManagedLock: 0x7ff174001f98 is_lock_owner: =0
 -03-13T14:06:19.106+0100 7ff19c6e9340 20 librbd::Operations: send_acquire_exclusive_lock
 -03-13T14:06:19.106+0100 7ff19c6e9340 10 librbd::ManagedLock: 0x7ff174001f98 try_acquire_lock:
 -03-13T14:06:19.106+0100 7ff19c6e9340 10 librbd::ManagedLock: 0x7ff174001f98 send_acquire_lock:
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::ExclusiveLock: 0x7ff174001f80 pre_acquire_lock_handler
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::exclusive_lock::PreAcquireRequest: 0x7ff18c01a000 send_prepare_lock:
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::ImageState: 0x5581e5861420 prepare_lock
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::ImageState: 0x5581e5861420 0x5581e5861420 send_prepare_lock_unlock
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::exclusive_lock::PreAcquireRequest: 0x7ff18c01a000 handle_prepare_lock: r=0
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::exclusive_lock::PreAcquireRequest: 0x7ff18c01a000 send_flush_notifies:
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::exclusive_lock::PreAcquireRequest: 0x7ff18c01a000 handle_flush_notifies:
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::ManagedLock: 0x7ff174001f98 handle_pre_acquire_lock: r=0
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002420 send_get_locker:
 -03-13T14:06:19.106+0100 7ff198b14700 10 librbd::managed_lock::GetLockerRequest: 0x7ff174002240 send_get_lockers:
 -03-13T14:06:19.106+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:13 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call lock.get_info in=30b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff174005cd0 con 0x7ff180008740
 -03-13T14:06:19.106+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 10 ==== osd_op_reply(13 rbd_header.be32ac9b290c61 [call out=120b] v0'0 uv190147833 ondisk = 0) v8 ==== 169+0+120 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.106+0100 7ff199315700 10 librbd::managed_lock::GetLockerRequest: 0x7ff174002240 handle_get_lockers: r=0
 -03-13T14:06:19.106+0100 7ff199315700 10 librbd::managed_lock::GetLockerRequest: 0x7ff174002240 handle_get_lockers: retrieved exclusive locker: client.1959673577@172.18.16.209:0/1869670625
 -03-13T14:06:19.106+0100 7ff199315700 10 librbd::managed_lock::GetLockerRequest: 0x7ff174002240 finish: r=0
 -03-13T14:06:19.106+0100 7ff199315700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002420 handle_get_locker: r=0
 -03-13T14:06:19.106+0100 7ff199315700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002420 send_lock: entity=client.2059286549, cookie=auto 140675010013520
 -03-13T14:06:19.106+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:14 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call lock.lock in=76b] snapc 0=[] ondisk+write+known_if_redirected e521433) v8 -- 0x7ff180018740 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 11 ==== osd_op_reply(14 rbd_header.be32ac9b290c61 [call] v521433'190148197 uv190147833 ondisk = -16 ((16) Device or resource busy)) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002420 handle_lock: r=-16
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002420 send_break_lock:
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::managed_lock::BreakRequest: 0x7ff174005cd0 send_get_watchers:
 -03-13T14:06:19.110+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:15 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [list-watchers] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff174005f30 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 12 ==== osd_op_reply(15 rbd_header.be32ac9b290c61 [list-watchers out=134b] v0'0 uv190147833 ondisk = 0) v8 ==== 169+0+134 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::BreakRequest: 0x7ff174005cd0 handle_get_watchers: r=0
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::managed_lock::BreakRequest: 0x7ff174005cd0 handle_get_watchers: watcher=[addr=172.18.16.209:0/1425925285, entity=client.2059286549]
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::managed_lock::BreakRequest: 0x7ff174005cd0 handle_get_watchers: watcher=[addr=172.18.16.209:0/1869670625, entity=client.1959673577]
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::BreakRequest: 0x7ff174005cd0 handle_get_watchers: lock owner is still alive
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::BreakRequest: 0x7ff174005cd0 finish: r=-11
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002420 handle_break_lock: r=-11
 -03-13T14:06:19.110+0100 7ff199315700  5 librbd::managed_lock::AcquireRequest: 0x7ff174002420 handle_break_lock: lock owner is still alive
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::ManagedLock: 0x7ff174001f98 handle_acquire_lock: r=-11
 -03-13T14:06:19.110+0100 7ff199315700  5 librbd::ManagedLock: 0x7ff174001f98 handle_acquire_lock: unable to acquire exclusive lock
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::ExclusiveLock: 0x7ff174001f80 post_acquire_lock_handler: r=-11
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::ImageState: 0x5581e5861420 handle_prepare_lock_complete
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::ManagedLock: 0x7ff174001f98 handle_post_acquire_lock: r=0
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::Operations: handle_acquire_exclusive_lock: r=0
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::ManagedLock: 0x7ff174001f98 is_lock_owner: =0
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::Operations: send_remote_request
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::ManagedLock: 0x7ff174001f98 is_lock_owner: =0
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::ImageWatcher: 0x7ff180007790 async request: [2059286549,140675010013520,1]
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::ImageWatcher: scheduling async request time out: [2059286549,140675010013520,1]
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::image_watcher::NotifyLockOwner: 0x7ff18c024000 send_notify
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 notify: pending=1
 -03-13T14:06:19.110+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:16 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify cookie 140675211422816 in=76b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff180018740 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 13 ==== watch-notify(notify (1) cookie 140675010013520 notify 2239537682055423 ret 0) v3 ==== 106+0+0 (crc 0 0 0) 0x7ff18c00a040 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff198b14700  5 librbd::Watcher: 0x7ff180007790 notifications_blocked: blocked=0
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x7ff1800192a0 C_NotifyAck: id=2239537682055423, handle=140675010013520
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff180007790 remote snap_create request: [2059286549,140675010013520,1] [user] snapshot 0
 -03-13T14:06:19.110+0100 7ff198b14700 20 librbd::ExclusiveLock: 0x7ff174001f80 accept_request=0 (request_type=0)
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x7ff1800192a0 finish: r=0
 -03-13T14:06:19.110+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:17 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify-ack in=20b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff174006360 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 14 ==== osd_op_reply(16 rbd_header.be32ac9b290c61 [notify cookie 140675211422816 out=8b] v0'0 uv190147833 ondisk = 0) v8 ==== 169+0+8 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 15 ==== osd_op_reply(17 rbd_header.be32ac9b290c61 [notify-ack] v0'0 uv190147833 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 16 ==== watch-notify(notify_complete (2) cookie 140675211422816 notify 2239537682055423 ret 0) v3 ==== 42+0+58 (crc 0 0 0) 0x5581e56e6170 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff198b14700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: r=0
 -03-13T14:06:19.110+0100 7ff198b14700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: pending=0
 -03-13T14:06:19.110+0100 7ff198b14700 20 librbd::image_watcher::NotifyLockOwner: 0x7ff18c024000 handle_notify: r=0
 -03-13T14:06:19.110+0100 7ff198b14700 20 librbd::Operations: handle_remote_request: r=-95
 -03-13T14:06:19.110+0100 7ff198b14700  5 librbd::Operations: snap create not supported by current lock owner
 -03-13T14:06:19.110+0100 7ff198b14700 20 librbd::ManagedLock: 0x7ff174001f98 is_lock_owner: =0
 -03-13T14:06:19.110+0100 7ff198b14700 20 librbd::Operations: send_acquire_exclusive_lock
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::ManagedLock: 0x7ff174001f98 acquire_lock:
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::ManagedLock: 0x7ff174001f98 send_acquire_lock:
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::ExclusiveLock: 0x7ff174001f80 pre_acquire_lock_handler
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::exclusive_lock::PreAcquireRequest: 0x7ff174007b00 send_prepare_lock:
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::ImageState: 0x5581e5861420 prepare_lock
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::ImageState: 0x5581e5861420 0x5581e5861420 send_prepare_lock_unlock
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::exclusive_lock::PreAcquireRequest: 0x7ff174007b00 handle_prepare_lock: r=0
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::exclusive_lock::PreAcquireRequest: 0x7ff174007b00 send_flush_notifies:
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::exclusive_lock::PreAcquireRequest: 0x7ff174007b00 handle_flush_notifies:
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::ManagedLock: 0x7ff174001f98 handle_pre_acquire_lock: r=0
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002510 send_get_locker:
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::managed_lock::GetLockerRequest: 0x7ff174006230 send_get_lockers:
 -03-13T14:06:19.110+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:18 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call lock.get_info in=30b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff174006360 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 17 ==== osd_op_reply(18 rbd_header.be32ac9b290c61 [call out=120b] v0'0 uv190147833 ondisk = 0) v8 ==== 169+0+120 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::GetLockerRequest: 0x7ff174006230 handle_get_lockers: r=0
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::GetLockerRequest: 0x7ff174006230 handle_get_lockers: retrieved exclusive locker: client.1959673577@172.18.16.209:0/1869670625
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::GetLockerRequest: 0x7ff174006230 finish: r=0
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002510 handle_get_locker: r=0
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002510 send_lock: entity=client.2059286549, cookie=auto 140675010013520
 -03-13T14:06:19.110+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:19 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call lock.lock in=76b] snapc 0=[] ondisk+write+known_if_redirected e521433) v8 -- 0x7ff180018740 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 18 ==== osd_op_reply(19 rbd_header.be32ac9b290c61 [call] v521433'190148198 uv190147833 ondisk = -16 ((16) Device or resource busy)) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002510 handle_lock: r=-16
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002510 send_break_lock:
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::managed_lock::BreakRequest: 0x7ff174006360 send_get_watchers:
 -03-13T14:06:19.110+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:20 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [list-watchers] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff174006730 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 19 ==== osd_op_reply(20 rbd_header.be32ac9b290c61 [list-watchers out=134b] v0'0 uv190147833 ondisk = 0) v8 ==== 169+0+134 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::BreakRequest: 0x7ff174006360 handle_get_watchers: r=0
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::managed_lock::BreakRequest: 0x7ff174006360 handle_get_watchers: watcher=[addr=172.18.16.209:0/1425925285, entity=client.2059286549]
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::managed_lock::BreakRequest: 0x7ff174006360 handle_get_watchers: watcher=[addr=172.18.16.209:0/1869670625, entity=client.1959673577]
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::BreakRequest: 0x7ff174006360 handle_get_watchers: lock owner is still alive
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::BreakRequest: 0x7ff174006360 finish: r=-11
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002510 handle_break_lock: r=-11
 -03-13T14:06:19.110+0100 7ff199315700  5 librbd::managed_lock::AcquireRequest: 0x7ff174002510 handle_break_lock: lock owner is still alive
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::ManagedLock: 0x7ff174001f98 handle_acquire_lock: r=-11
 -03-13T14:06:19.110+0100 7ff199315700  5 librbd::ManagedLock: 0x7ff174001f98 handle_acquire_lock: unable to acquire exclusive lock
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::ExclusiveLock: 0x7ff174001f80 post_acquire_lock_handler: r=-11
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::ImageState: 0x5581e5861420 handle_prepare_lock_complete
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::ManagedLock: 0x7ff174001f98 is_lock_owner: =0
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::ImageWatcher: 0x7ff180007790 notify request lock
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::image_watcher::NotifyLockOwner: 0x7ff18c033000 send_notify
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 notify: pending=1
 -03-13T14:06:19.110+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:21 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify cookie 140675211422816 in=39b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff180018740 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff199315700 10 librbd::ManagedLock: 0x7ff174001f98 handle_post_acquire_lock: r=-125
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 20 ==== watch-notify(notify (1) cookie 140675010013520 notify 2239537682055424 ret 0) v3 ==== 69+0+0 (crc 0 0 0) 0x5581e56e6170 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff198b14700  5 librbd::Watcher: 0x7ff180007790 notifications_blocked: blocked=0
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x7ff180018b50 C_NotifyAck: id=2239537682055424, handle=140675010013520
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff180007790 exclusive lock requested
 -03-13T14:06:19.110+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x7ff180018b50 finish: r=0
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 21 ==== osd_op_reply(21 rbd_header.be32ac9b290c61 [notify cookie 140675211422816 out=8b] v0'0 uv190147833 ondisk = 0) v8 ==== 169+0+8 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:22 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify-ack in=20b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff174006730 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 22 ==== osd_op_reply(22 rbd_header.be32ac9b290c61 [notify-ack] v0'0 uv190147833 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 23 ==== watch-notify(notify_complete (2) cookie 140675211422816 notify 2239537682055424 ret 0) v3 ==== 42+0+58 (crc 0 0 0) 0x7ff18c011450 con 0x7ff180008740
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: r=0
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: pending=0
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::image_watcher::NotifyLockOwner: 0x7ff18c033000 handle_notify: r=0
 -03-13T14:06:19.110+0100 7ff199315700 15 librbd::ImageWatcher: 0x7ff180007790 will retry in 10 seconds
 -03-13T14:06:19.110+0100 7ff199315700 20 librbd::ManagedLock: 0x7ff174001f98 is_lock_owner: =0
 -03-13T14:06:19.110+0100 7ff199315700 15 librbd::ImageWatcher: 0x7ff180007790 requesting exclusive lock
 -03-13T14:06:19.114+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 24 ==== watch-notify(notify (1) cookie 140675010013520 notify 2239537682055425 ret 0) v3 ==== 68+0+0 (crc 0 0 0) 0x7ff18c011450 con 0x7ff180008740
 -03-13T14:06:19.114+0100 7ff198b14700  5 librbd::Watcher: 0x7ff180007790 notifications_blocked: blocked=0
 -03-13T14:06:19.114+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x5581e58629f0 C_NotifyAck: id=2239537682055425, handle=140675010013520
 -03-13T14:06:19.114+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff180007790 exclusive lock released
 -03-13T14:06:19.114+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff180007790 unexpected owner: [1959673577,18446462598732841868] != [0,0]
 -03-13T14:06:19.114+0100 7ff198b14700 20 librbd::ManagedLock: 0x7ff174001f98 is_lock_owner: =0
 -03-13T14:06:19.114+0100 7ff198b14700 10 librbd::ExclusiveLock: 0x7ff174001f80 handle_peer_notification
 -03-13T14:06:19.114+0100 7ff198b14700 10 librbd::ManagedLock: 0x7ff174001f98 send_acquire_lock:
 -03-13T14:06:19.114+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x5581e58629f0 finish: r=0
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::ExclusiveLock: 0x7ff174001f80 pre_acquire_lock_handler
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::exclusive_lock::PreAcquireRequest: 0x7ff1800041f0 send_prepare_lock:
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::ImageState: 0x5581e5861420 prepare_lock
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::ImageState: 0x5581e5861420 0x5581e5861420 send_prepare_lock_unlock
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::exclusive_lock::PreAcquireRequest: 0x7ff1800041f0 handle_prepare_lock: r=0
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::exclusive_lock::PreAcquireRequest: 0x7ff1800041f0 send_flush_notifies:
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::exclusive_lock::PreAcquireRequest: 0x7ff1800041f0 handle_flush_notifies:
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::ManagedLock: 0x7ff174001f98 handle_pre_acquire_lock: r=0
 -03-13T14:06:19.114+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:23 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify-ack in=20b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff174006730 con 0x7ff180008740
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002510 send_get_locker:
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::managed_lock::GetLockerRequest: 0x7ff180016640 send_get_lockers:
 -03-13T14:06:19.114+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:24 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call lock.get_info in=30b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff180018740 con 0x7ff180008740
 -03-13T14:06:19.114+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 25 ==== osd_op_reply(23 rbd_header.be32ac9b290c61 [notify-ack] v0'0 uv190148199 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.114+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 26 ==== osd_op_reply(24 rbd_header.be32ac9b290c61 [call out=23b] v0'0 uv190148199 ondisk = 0) v8 ==== 169+0+23 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.114+0100 7ff198b14700 10 librbd::managed_lock::GetLockerRequest: 0x7ff180016640 handle_get_lockers: r=0
 -03-13T14:06:19.114+0100 7ff198b14700 20 librbd::managed_lock::GetLockerRequest: 0x7ff180016640 handle_get_lockers: no lockers detected
 -03-13T14:06:19.114+0100 7ff198b14700 10 librbd::managed_lock::GetLockerRequest: 0x7ff180016640 finish: r=-2
 -03-13T14:06:19.114+0100 7ff198b14700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002510 handle_get_locker: r=-2
 -03-13T14:06:19.114+0100 7ff198b14700 20 librbd::managed_lock::AcquireRequest: 0x7ff174002510 handle_get_locker: no lockers detected
 -03-13T14:06:19.114+0100 7ff198b14700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002510 send_lock: entity=client.2059286549, cookie=auto 140675010013520
 -03-13T14:06:19.114+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:25 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call lock.lock in=76b] snapc 0=[] ondisk+write+known_if_redirected e521433) v8 -- 0x7ff174006730 con 0x7ff180008740
 -03-13T14:06:19.114+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 27 ==== osd_op_reply(25 rbd_header.be32ac9b290c61 [call] v521433'190148200 uv190148200 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::managed_lock::AcquireRequest: 0x7ff174002510 handle_lock: r=0
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::ManagedLock: 0x7ff174001f98 handle_acquire_lock: r=0
 -03-13T14:06:19.114+0100 7ff199315700  5 librbd::ManagedLock: 0x7ff174001f98 handle_acquire_lock: successfully acquired exclusive lock
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::ExclusiveLock: 0x7ff174001f80 post_acquire_lock_handler: r=0
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::exclusive_lock::PostAcquireRequest: 0x7ff18c03e000 send_open_object_map:
 -03-13T14:06:19.114+0100 7ff199315700 20 librbd::object_map::RefreshRequest: 0x7ff18001b1d0 send: object_count=50
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::object_map::RefreshRequest: 0x7ff18001b1d0 send_lock: oid=rbd_object_map.be32ac9b290c61
 -03-13T14:06:19.114+0100 7ff199315700 10 librbd::object_map::LockRequest: 0x7ff1800168b0 send_lock: oid=rbd_object_map.be32ac9b290c61
 -03-13T14:06:19.114+0100 7ff199315700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6810/9088,v1:172.18.16.107:6811/9088] conn(0x7ff180011570 0x7ff1800139d0 unknown :-1 s=NONE pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0).connect
 -03-13T14:06:19.114+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.107:6810/9088,v1:172.18.16.107:6811/9088] -- osd_op(unknown.0.0:26 15213.3d5 15213:abc89829:::rbd_object_map.be32ac9b290c61:head [call lock.lock in=48b] snapc 0=[] ondisk+write+known_if_redirected e521433) v8 -- 0x7ff180013ec0 con 0x7ff180011570
 -03-13T14:06:19.114+0100 7ff19b319700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6810/9088,v1:172.18.16.107:6811/9088] conn(0x7ff180011570 0x7ff1800139d0 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0)._handle_peer_banner_payload supported=1 required=0
 -03-13T14:06:19.114+0100 7ff19b319700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6810/9088,v1:172.18.16.107:6811/9088] conn(0x7ff180011570 0x7ff1800139d0 crc :-1 s=READY pgs=18915 cs=0 l=1 rev1=1 rx=0 tx=0).ready entity=osd.69 client_cookie=0 server_cookie=0 in_seq=0 out_seq=0
 -03-13T14:06:19.118+0100 7ff19b319700  1 -- 172.18.16.209:0/1425925285 <== osd.69 v2:172.18.16.107:6810/9088 1 ==== osd_op_reply(26 rbd_object_map.be32ac9b290c61 [call] v521433'104363831 uv104363831 ondisk = 0) v8 ==== 173+0+0 (crc 0 0 0) 0x7ff194017070 con 0x7ff180011570
 -03-13T14:06:19.118+0100 7ff198b14700 10 librbd::object_map::LockRequest: 0x7ff1800168b0 handle_lock: r=0
 -03-13T14:06:19.118+0100 7ff198b14700 10 librbd::object_map::RefreshRequest: 0x7ff18001b1d0 handle_lock
 -03-13T14:06:19.118+0100 7ff198b14700 10 librbd::object_map::RefreshRequest: 0x7ff18001b1d0 send_load: oid=rbd_object_map.be32ac9b290c61
 -03-13T14:06:19.118+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.107:6810/9088,v1:172.18.16.107:6811/9088] -- osd_op(unknown.0.0:27 15213.3d5 15213:abc89829:::rbd_object_map.be32ac9b290c61:head [call rbd.object_map_load in=18b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff1740064b0 con 0x7ff180011570
 -03-13T14:06:19.118+0100 7ff19b319700  1 -- 172.18.16.209:0/1425925285 <== osd.69 v2:172.18.16.107:6810/9088 2 ==== osd_op_reply(27 rbd_object_map.be32ac9b290c61 [call out=35b] v0'0 uv104363831 ondisk = 0) v8 ==== 173+0+35 (crc 0 0 0) 0x7ff194017070 con 0x7ff180011570
 -03-13T14:06:19.118+0100 7ff199315700 10 librbd::object_map::RefreshRequest: 0x7ff18001b1d0 handle_load: r=0
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::object_map::RefreshRequest: refreshed object map: num_objs=50
 -03-13T14:06:19.118+0100 7ff199315700 10 librbd::exclusive_lock::PostAcquireRequest: 0x7ff18c03e000 handle_open_object_map: r=0
 -03-13T14:06:19.118+0100 7ff199315700 10 librbd::ExclusiveLock: 0x7ff174001f80 handle_post_acquiring_lock
 -03-13T14:06:19.118+0100 7ff199315700 10 librbd::ImageState: 0x5581e5861420 handle_prepare_lock_complete
 -03-13T14:06:19.118+0100 7ff199315700 10 librbd::exclusive_lock::PostAcquireRequest: 0x7ff18c03e000 send_process_plugin_acquire_lock:
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::PluginRegistry: 0x5581e5860d40 acquired_exclusive_lock:
 -03-13T14:06:19.118+0100 7ff199315700 10 librbd::exclusive_lock::PostAcquireRequest: 0x7ff18c03e000 handle_process_plugin_acquire_lock: r=0
 -03-13T14:06:19.118+0100 7ff199315700 10 librbd::ExclusiveLock: 0x7ff174001f80 handle_post_acquired_lock: r=0
 -03-13T14:06:19.118+0100 7ff199315700 10 librbd::ImageWatcher: 0x7ff180007790 notify acquired lock
 -03-13T14:06:19.118+0100 7ff199315700 10 librbd::ImageWatcher: 0x7ff180007790 current lock owner: [2059286549,140675010013520]
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 notify: pending=1
 -03-13T14:06:19.118+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:28 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify cookie 140675211423264 in=38b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff180014780 con 0x7ff180008740
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::exclusive_lock::ImageDispatch: 0x7ff1740021d0 set_require_lock: direction=2, enabled=0
 -03-13T14:06:19.118+0100 7ff199315700 10 librbd::ManagedLock: 0x7ff174001f98 handle_post_acquire_lock: r=0
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::Operations: handle_acquire_exclusive_lock: r=0
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::ManagedLock: 0x7ff174001f98 is_lock_owner: =1
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::Operations: start_op: snap create 0x7ff180010b50
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::Operations: start snap create 0x7ff180010b50
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::Operations: execute_local_request
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::ManagedLock: 0x7ff174001f98 is_lock_owner: =1
 -03-13T14:06:19.118+0100 7ff199315700  5 librbd::Operations: 0x5581e5860fe0 execute_snap_create: snap_name=snapshot
 -03-13T14:06:19.118+0100 7ff199315700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 send_notify_quiesce
 -03-13T14:06:19.118+0100 7ff199315700 10 librbd::ImageWatcher: 0x7ff180007790 notify_quiesce: request_id=0x7ff180014d00
 -03-13T14:06:19.118+0100 7ff199315700 10 librbd::ImageWatcher: 0x7ff180007790 notify_quiesce: async_request_id=[2059286549,140675010013520,2] attempts=10
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 notify: pending=2
 -03-13T14:06:19.118+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:29 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify cookie 140675211443248 in=46b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff180015d90 con 0x7ff180008740
 -03-13T14:06:19.118+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 28 ==== watch-notify(notify (1) cookie 140675010013520 notify 2239537682055426 ret 0) v3 ==== 68+0+0 (crc 0 0 0) 0x7ff18c011690 con 0x7ff180008740
 -03-13T14:06:19.118+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 29 ==== osd_op_reply(28 rbd_header.be32ac9b290c61 [notify cookie 140675211423264 out=8b] v0'0 uv190148200 ondisk = 0) v8 ==== 169+0+8 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.118+0100 7ff198b14700  5 librbd::Watcher: 0x7ff180007790 notifications_blocked: blocked=0
 -03-13T14:06:19.118+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 30 ==== watch-notify(notify (1) cookie 140675010013520 notify 2239537682055427 ret 0) v3 ==== 76+0+0 (crc 0 0 0) 0x7ff18c011820 con 0x7ff180008740
 -03-13T14:06:19.118+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x7ff180014940 C_NotifyAck: id=2239537682055426, handle=140675010013520
 -03-13T14:06:19.118+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff180007790 image exclusively locked announcement
 -03-13T14:06:19.118+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff180007790 current lock owner: [2059286549,140675010013520]
 -03-13T14:06:19.118+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x7ff180014940 finish: r=0
 -03-13T14:06:19.118+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 31 ==== osd_op_reply(29 rbd_header.be32ac9b290c61 [notify cookie 140675211443248 out=8b] v0'0 uv190148200 ondisk = 0) v8 ==== 169+0+8 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.118+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:30 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify-ack in=20b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff17400b310 con 0x7ff180008740
 -03-13T14:06:19.118+0100 7ff198b14700  5 librbd::Watcher: 0x7ff180007790 notifications_blocked: blocked=0
 -03-13T14:06:19.118+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x7ff180018b50 C_NotifyAck: id=2239537682055427, handle=140675010013520
 -03-13T14:06:19.118+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff180007790 quiesce request: [2059286549,140675010013520,2]
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::ImageState: 0x5581e5861420 notify_quiesce
 -03-13T14:06:19.118+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff18c000b60 C_ResponseMessage: r=0
 -03-13T14:06:19.118+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x7ff180018b50 finish: r=0
 -03-13T14:06:19.118+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:31 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify-ack in=30b] snapc 0=[] ondisk+read+known_if_redirected e521433) v8 -- 0x7ff17400b310 con 0x7ff180008740
 -03-13T14:06:19.118+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 32 ==== watch-notify(notify_complete (2) cookie 140675211423264 notify 2239537682055426 ret 0) v3 ==== 42+0+48 (crc 0 0 0) 0x7ff18c011a50 con 0x7ff180008740
 -03-13T14:06:19.118+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 33 ==== osd_op_reply(30 rbd_header.be32ac9b290c61 [notify-ack] v0'0 uv190148200 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: r=0
 -03-13T14:06:19.118+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: pending=1
 -03-13T14:06:19.118+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 34 ==== osd_op_reply(31 rbd_header.be32ac9b290c61 [notify-ack] v0'0 uv190148200 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.118+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 35 ==== watch-notify(notify_complete (2) cookie 140675211443248 notify 2239537682055427 ret 0) v3 ==== 42+0+58 (crc 0 0 0) 0x7ff18c011a50 con 0x7ff180008740
       Creating snap: 2023-03-13T14:06:19.118+0100 7ff198b14700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: r=0
 % complete...2023-03-13T14:06:19.118+0100 7ff198b14700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: pending=0
 -03-13T14:06:19.118+0100 7ff198b14700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 handle_notify_quiesce: r=0
 -03-13T14:06:19.118+0100 7ff198b14700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 send_suspend_requests
 -03-13T14:06:19.118+0100 7ff198b14700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 send_suspend_aio
 -03-13T14:06:19.118+0100 7ff198b14700  5 librbd::io::WriteBlockImageDispatch: 0x5581e5766cf0 block_writes: 0x5581e5819c60, num=1
 -03-13T14:06:19.118+0100 7ff198b14700 10 librbd::io::WriteBlockImageDispatch: 0x5581e5766cf0 flush_io:
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::io::AsyncOperation: 0x7ff180011000 start_op
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e580e710 send: dispatch_spec=0x7ff174005f30
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::io::ImageDispatch: 0x5581e580e7b0 flush:
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::io::ImageRequest: 0x7ff198b0ed70 send: aio_flush: ictx=0x5581e5819c60, completion=0x7ff180010ef0
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff180010ef0 set_request_count: pending=1
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e58614a0 send: dispatch_spec=0x7ff174006230
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::cache::WriteAroundObjectDispatch: 0x7ff174002730 flush:
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::io::SimpleSchedulerObjectDispatch: 0x7ff174003350 flush:
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::io::SimpleSchedulerObjectDispatch: 0x7ff174003350 dispatch_all_delayed_requests:
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e58614a0 send: dispatch_spec=0x7ff174006230
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff180010ef0 complete_request: cb=1, pending=0
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff180010ef0 finalize: r=0
 -03-13T14:06:19.118+0100 7ff198b14700 20 librbd::io::AsyncOperation: 0x7ff180011000 finish_op
 -03-13T14:06:19.118+0100 7ff198b14700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 handle_suspend_aio: r=0
 -03-13T14:06:19.118+0100 7ff198b14700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 send_allocate_snap_id
 -03-13T14:06:19.118+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] -- pool_op(create unmanaged snap pool 15213 tid 32 name  v0) v4 -- 0x7ff1740068b0 con 0x5581e580b9a0
 -03-13T14:06:19.478+0100 7ff1937fe700  1 -- 172.18.16.209:0/1425925285 <== mon.4 v2:172.18.16.155:3300/0 6 ==== pool_op_reply(tid 32 (0) Success v521434) v1 ==== 55+0+0 (secure 0 0 0) 0x7ff194015040 con 0x5581e580b9a0
 -03-13T14:06:19.478+0100 7ff1937fe700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] -- mon_subscribe({osdmap=521434}) v3 -- 0x7ff17c202650 con 0x5581e580b9a0
 -03-13T14:06:19.478+0100 7ff1937fe700  1 -- 172.18.16.209:0/1425925285 <== mon.4 v2:172.18.16.155:3300/0 7 ==== osd_map(521434..521434 src has 520735..521434) v4 ==== 618+0+0 (secure 0 0 0) 0x7ff1941c4da0 con 0x5581e580b9a0
 -03-13T14:06:19.478+0100 7ff199315700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 handle_allocate_snap_id: r=0, snap_id=182
 -03-13T14:06:19.478+0100 7ff199315700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 send_create_snap
 -03-13T14:06:19.478+0100 7ff199315700 20 librbd::ManagedLock: 0x7ff174001f98 is_lock_owner: =1
 -03-13T14:06:19.478+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:33 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call rbd.snapshot_add in=45b] snapc 0=[] ondisk+write+known_if_redirected e521434) v8 -- 0x7ff180016e20 con 0x7ff180008740
 -03-13T14:06:19.486+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 36 ==== osd_op_reply(33 rbd_header.be32ac9b290c61 [call] v521434'190148209 uv190148209 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.486+0100 7ff198b14700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 handle_create_snap: r=0
 -03-13T14:06:19.486+0100 7ff198b14700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 send_create_object_map
 -03-13T14:06:19.486+0100 7ff198b14700  5 librbd::object_map::SnapshotCreateRequest: 0x7ff18c0119b0 send_read_map: oid=rbd_object_map.be32ac9b290c61
 -03-13T14:06:19.486+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.107:6810/9088,v1:172.18.16.107:6811/9088] -- osd_op(unknown.0.0:34 15213.3d5 15213:abc89829:::rbd_object_map.be32ac9b290c61:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected e521434) v8 -- 0x7ff17400b7b0 con 0x7ff180011570
 -03-13T14:06:19.494+0100 7ff19b319700  1 -- 172.18.16.209:0/1425925285 <== osd.69 v2:172.18.16.107:6810/9088 3 ==== osd_op_reply(34 rbd_object_map.be32ac9b290c61 [read 0~47 out=47b] v0'0 uv104363831 ondisk = 0) v8 ==== 173+0+47 (crc 0 0 0) 0x7ff194017070 con 0x7ff180011570
 -03-13T14:06:19.494+0100 7ff199315700  5 librbd::object_map::SnapshotCreateRequest: 0x7ff18c0119b0 should_complete: state=READ_MAP, r=0
 -03-13T14:06:19.494+0100 7ff199315700  5 librbd::object_map::SnapshotCreateRequest: 0x7ff18c0119b0 send_write_map: snap_oid=rbd_object_map.be32ac9b290c61.00000000000000b6
 -03-13T14:06:19.494+0100 7ff199315700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6852/9082,v1:172.18.16.107:6854/9082] conn(0x7ff180016e20 0x7ff180017c40 unknown :-1 s=NONE pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0).connect
 -03-13T14:06:19.494+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.107:6852/9082,v1:172.18.16.107:6854/9082] -- osd_op(unknown.0.0:35 15213.372 15213:4ecadfe2:::rbd_object_map.be32ac9b290c61.00000000000000b6:head [writefull 0~47 in=47b] snapc 0=[] ondisk+write+known_if_redirected e521434) v8 -- 0x7ff180018130 con 0x7ff180016e20
 -03-13T14:06:19.494+0100 7ff19ab18700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6852/9082,v1:172.18.16.107:6854/9082] conn(0x7ff180016e20 0x7ff180017c40 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=1 rev1=0 rx=0 tx=0)._handle_peer_banner_payload supported=1 required=0
 -03-13T14:06:19.494+0100 7ff19ab18700  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6852/9082,v1:172.18.16.107:6854/9082] conn(0x7ff180016e20 0x7ff180017c40 crc :-1 s=READY pgs=18015 cs=0 l=1 rev1=1 rx=0 tx=0).ready entity=osd.67 client_cookie=0 server_cookie=0 in_seq=0 out_seq=0
 -03-13T14:06:19.502+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.67 v2:172.18.16.107:6852/9082 1 ==== osd_op_reply(35 rbd_object_map.be32ac9b290c61.00000000000000b6 [writefull 0~47] v521434'99682870 uv99682870 ondisk = 0) v8 ==== 190+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180016e20
 -03-13T14:06:19.502+0100 7ff198b14700  5 librbd::object_map::SnapshotCreateRequest: 0x7ff18c0119b0 should_complete: state=WRITE_MAP, r=0
 -03-13T14:06:19.502+0100 7ff198b14700  5 librbd::object_map::SnapshotCreateRequest: 0x7ff18c0119b0 send_add_snapshot: oid=rbd_object_map.be32ac9b290c61
 -03-13T14:06:19.502+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.107:6810/9088,v1:172.18.16.107:6811/9088] -- osd_op(unknown.0.0:36 15213.3d5 15213:abc89829:::rbd_object_map.be32ac9b290c61:head [call lock.assert_locked in=44b,call rbd.object_map_snap_add in=22b] snapc 0=[] ondisk+write+known_if_redirected e521434) v8 -- 0x7ff17400b310 con 0x7ff180011570
 -03-13T14:06:19.502+0100 7ff19b319700  1 -- 172.18.16.209:0/1425925285 <== osd.69 v2:172.18.16.107:6810/9088 4 ==== osd_op_reply(36 rbd_object_map.be32ac9b290c61 [call,call] v521434'104363833 uv104363833 ondisk = 0) v8 ==== 215+0+0 (crc 0 0 0) 0x7ff194017070 con 0x7ff180011570
 -03-13T14:06:19.502+0100 7ff199315700  5 librbd::object_map::SnapshotCreateRequest: 0x7ff18c0119b0 should_complete: state=ADD_SNAPSHOT, r=0
 -03-13T14:06:19.502+0100 7ff199315700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 handle_create_object_map: r=0
 -03-13T14:06:19.502+0100 7ff199315700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 update_snap_context
 -03-13T14:06:19.502+0100 7ff199315700 20 librbd::ManagedLock: 0x7ff174001f98 is_lock_owner: =1
 -03-13T14:06:19.502+0100 7ff199315700  5 librbd::io::WriteBlockImageDispatch: 0x5581e5766cf0 unblock_writes: 0x5581e5819c60, num=0
 -03-13T14:06:19.502+0100 7ff199315700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 send_notify_unquiesce
 -03-13T14:06:19.502+0100 7ff199315700 10 librbd::ImageWatcher: 0x7ff180007790 notify_unquiesce: request_id=2
 -03-13T14:06:19.502+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 notify: pending=1
 -03-13T14:06:19.502+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:37 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify cookie 140675211412112 in=46b] snapc 0=[] ondisk+read+known_if_redirected e521434) v8 -- 0x7ff180018130 con 0x7ff180008740
 -03-13T14:06:19.506+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 37 ==== watch-notify(notify (1) cookie 140675010013520 notify 2239541977022724 ret 0) v3 ==== 76+0+0 (crc 0 0 0) 0x7ff18c011a50 con 0x7ff180008740
 -03-13T14:06:19.506+0100 7ff198b14700  5 librbd::Watcher: 0x7ff180007790 notifications_blocked: blocked=0
 -03-13T14:06:19.506+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 38 ==== osd_op_reply(37 rbd_header.be32ac9b290c61 [notify cookie 140675211412112 out=8b] v0'0 uv190148209 ondisk = 0) v8 ==== 169+0+8 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.506+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x7ff18001bbe0 C_NotifyAck: id=2239541977022724, handle=140675010013520
 -03-13T14:06:19.506+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff180007790 unquiesce request: [2059286549,140675010013520,2]
 -03-13T14:06:19.506+0100 7ff198b14700 20 librbd::ImageState: 0x5581e5861420 notify_unquiesce
 -03-13T14:06:19.506+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x7ff18001bbe0 finish: r=0
 -03-13T14:06:19.506+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:38 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify-ack in=20b] snapc 0=[] ondisk+read+known_if_redirected e521434) v8 -- 0x7ff17400bb60 con 0x7ff180008740
 -03-13T14:06:19.506+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 39 ==== osd_op_reply(38 rbd_header.be32ac9b290c61 [notify-ack] v0'0 uv190148209 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.506+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 40 ==== watch-notify(notify_complete (2) cookie 140675211412112 notify 2239541977022724 ret 0) v3 ==== 42+0+48 (crc 0 0 0) 0x7ff18c023790 con 0x7ff180008740
 -03-13T14:06:19.506+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: r=0
 -03-13T14:06:19.506+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: pending=0
 -03-13T14:06:19.506+0100 7ff199315700  5 librbd::SnapshotCreateRequest: 0x7ff180014be0 handle_notify_unquiesce: r=0
 -03-13T14:06:19.506+0100 7ff199315700 10 librbd::Request: 0x7ff180014be0 create_context_finisher
 -03-13T14:06:19.506+0100 7ff199315700 10 librbd::Request: 0x7ff180014be0 finish: r=0
 -03-13T14:06:19.506+0100 7ff199315700 20 librbd::ImageState: 0x5581e5861420 handle_update_notification: refresh_seq = 1, last_refresh = 0
 -03-13T14:06:19.506+0100 7ff199315700 20 librbd::ImageState: 0x5581e56d1350 ImageUpdateWatchers::notify
 -03-13T14:06:19.506+0100 7ff199315700 10 librbd::ImageWatcher: 0x7ff180007790: notify_header_update
 -03-13T14:06:19.506+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 notify: pending=1
 -03-13T14:06:19.506+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:39 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify cookie 140675211412112 in=22b] snapc 0=[] ondisk+read+known_if_redirected e521434) v8 -- 0x7ff180018130 con 0x7ff180008740
 -03-13T14:06:19.506+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 41 ==== watch-notify(notify (1) cookie 140675010013520 notify 2239541977022725 ret 0) v3 ==== 52+0+0 (crc 0 0 0) 0x7ff18c023790 con 0x7ff180008740
 -03-13T14:06:19.506+0100 7ff198b14700  5 librbd::Watcher: 0x7ff180007790 notifications_blocked: blocked=0
 -03-13T14:06:19.506+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x7ff18001bbe0 C_NotifyAck: id=2239541977022725, handle=140675010013520
 -03-13T14:06:19.506+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff180007790 image header updated
 -03-13T14:06:19.506+0100 7ff198b14700 20 librbd::ImageState: 0x5581e5861420 handle_update_notification: refresh_seq = 2, last_refresh = 0
 -03-13T14:06:19.506+0100 7ff198b14700 20 librbd::ImageState: 0x5581e56d1350 ImageUpdateWatchers::notify
 -03-13T14:06:19.506+0100 7ff198b14700 20 librbd::ImageState: 0x5581e5861420 flush_update_watchers
 -03-13T14:06:19.506+0100 7ff198b14700 20 librbd::ImageState: 0x5581e56d1350 ImageUpdateWatchers::flush
 -03-13T14:06:19.506+0100 7ff198b14700 20 librbd::ImageState: 0x5581e56d1350 ImageUpdateWatchers::flush: completing flush
 -03-13T14:06:19.506+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff18c011ca0 C_ResponseMessage: r=0
 -03-13T14:06:19.506+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 42 ==== osd_op_reply(39 rbd_header.be32ac9b290c61 [notify cookie 140675211412112 out=8b] v0'0 uv190148209 ondisk = 0) v8 ==== 169+0+8 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.506+0100 7ff198b14700 10 librbd::Watcher::C_NotifyAck 0x7ff18001bbe0 finish: r=0
 -03-13T14:06:19.506+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:40 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify-ack in=30b] snapc 0=[] ondisk+read+known_if_redirected e521434) v8 -- 0x7ff17400bb60 con 0x7ff180008740
 -03-13T14:06:19.506+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 43 ==== osd_op_reply(40 rbd_header.be32ac9b290c61 [notify-ack] v0'0 uv190148209 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.506+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 44 ==== watch-notify(notify_complete (2) cookie 140675211412112 notify 2239541977022725 ret 0) v3 ==== 42+0+58 (crc 0 0 0) 0x7ff18c0239c0 con 0x7ff180008740
 -03-13T14:06:19.506+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: r=0
 -03-13T14:06:19.506+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: pending=0
 -03-13T14:06:19.506+0100 7ff199315700 20 librbd::Operations: handle_local_request: r=0
 -03-13T14:06:19.506+0100 7ff199315700 20 librbd::Operations: finish_op: snap create r=0
       Creating snap: 100% complete...done.
 -03-13T14:06:19.510+0100 7ff19c6e9340 20 librbd::ImageState: 0x5581e5861420 close
 -03-13T14:06:19.510+0100 7ff19c6e9340 10 librbd::ImageState: 0x5581e5861420 0x5581e5861420 send_close_unlock
 -03-13T14:06:19.510+0100 7ff19c6e9340 10 librbd::ConfigWatcher: shut_down:
 -03-13T14:06:19.510+0100 7ff19c6e9340 10 librbd::image::CloseRequest: 0x5581e5863550 send_block_image_watcher
 -03-13T14:06:19.510+0100 7ff19c6e9340 10 librbd::ImageWatcher: 0x7ff180007790 block_notifies
 -03-13T14:06:19.510+0100 7ff19c6e9340  5 librbd::Watcher: 0x7ff180007790 block_notifies: blocked_count=1
 -03-13T14:06:19.510+0100 7ff19c6e9340 10 librbd::image::CloseRequest: 0x5581e5863550 handle_block_image_watcher: r=0
 -03-13T14:06:19.510+0100 7ff19c6e9340 10 librbd::image::CloseRequest: 0x5581e5863550 send_shut_down_update_watchers
 -03-13T14:06:19.510+0100 7ff19c6e9340 20 librbd::ImageState: 0x5581e5861420 shut_down_update_watchers
 -03-13T14:06:19.510+0100 7ff19c6e9340 20 librbd::ImageState: 0x5581e56d1350 ImageUpdateWatchers::shut_down
 -03-13T14:06:19.510+0100 7ff19c6e9340 20 librbd::ImageState: 0x5581e56d1350 ImageUpdateWatchers::shut_down: completing shut down
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 handle_shut_down_update_watchers: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 send_flush
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AsyncOperation: 0x7ff180011000 start_op
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e580e710 send: dispatch_spec=0x7ff174005f30
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::QueueImageDispatch: 0x5581e580e7d0 flush: tid=3
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e580e710 send: dispatch_spec=0x7ff174005f30
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::QosImageDispatch: 0x5581e580e870 flush: tid=3
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e580e710 send: dispatch_spec=0x7ff174005f30
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::exclusive_lock::ImageDispatch: 0x7ff1740021d0 flush: tid=3
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::RefreshImageDispatch: 0x5581e580ed80 flush: tid=3
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::WriteBlockImageDispatch: 0x5581e5766cf0 flush: tid=3
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::ImageDispatch: 0x5581e580e7b0 flush:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::ImageRequest: 0x7ff198b0e870 send: aio_flush: ictx=0x5581e5819c60, completion=0x7ff180010ef0
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff180010ef0 set_request_count: pending=1
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e58614a0 send: dispatch_spec=0x7ff174006230
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::cache::WriteAroundObjectDispatch: 0x7ff174002730 flush:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::SimpleSchedulerObjectDispatch: 0x7ff174003350 flush:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::SimpleSchedulerObjectDispatch: 0x7ff174003350 dispatch_all_delayed_requests:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e58614a0 send: dispatch_spec=0x7ff174006230
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff180010ef0 complete_request: cb=1, pending=0
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff180010ef0 finalize: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 handle_flush: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 send_shut_down_exclusive_lock
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::ExclusiveLock: 0x7ff174001f80 shut_down
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::ManagedLock: 0x7ff174001f98 shut_down:
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::ManagedLock: 0x7ff174001f98 send_shutdown:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AsyncOperation: 0x7ff180011000 finish_op
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::ManagedLock: 0x7ff174001f98 send_shutdown_release:
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::ExclusiveLock: 0x7ff174001f80 pre_release_lock_handler
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 send_cancel_op_requests:
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 handle_cancel_op_requests: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 send_set_require_lock:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::exclusive_lock::ImageDispatch: 0x7ff1740021d0 set_require_lock: direction=1, enabled=1
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AsyncOperation: 0x7ff180011000 start_op
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e580e710 send: dispatch_spec=0x7ff174005f30
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::RefreshImageDispatch: 0x5581e580ed80 flush: tid=4
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::WriteBlockImageDispatch: 0x5581e5766cf0 flush: tid=4
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::ImageDispatch: 0x5581e580e7b0 flush:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::ImageRequest: 0x7ff198b0ee20 send: aio_flush: ictx=0x5581e5819c60, completion=0x7ff180010ef0
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff180010ef0 set_request_count: pending=1
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e58614a0 send: dispatch_spec=0x7ff174006230
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::cache::WriteAroundObjectDispatch: 0x7ff174002730 flush:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::SimpleSchedulerObjectDispatch: 0x7ff174003350 flush:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::SimpleSchedulerObjectDispatch: 0x7ff174003350 dispatch_all_delayed_requests:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e58614a0 send: dispatch_spec=0x7ff174006230
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff180010ef0 complete_request: cb=1, pending=0
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff180010ef0 finalize: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 handle_set_require_lock: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 send_wait_for_ops:
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 handle_wait_for_ops:
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 send_process_plugin_release_lock:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::PluginRegistry: 0x5581e5860d40 prerelease_exclusive_lock:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AsyncOperation: 0x7ff180011000 finish_op
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 handle_process_plugin_release_lock: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 send_invalidate_cache:
 -03-13T14:06:19.510+0100 7ff198b14700  5 librbd::io::ImageDispatcher: 0x5581e580e710 invalidate_cache:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::ImageDispatch: 0x5581e580e7b0 invalidate_cache:
 -03-13T14:06:19.510+0100 7ff198b14700  5 librbd::io::ObjectDispatcher: 0x5581e58614a0 invalidate_cache:
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 handle_invalidate_cache: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 send_flush_io:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AsyncOperation: 0x7ff180011000 start_op
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e580e710 send: dispatch_spec=0x7ff174005f30
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::RefreshImageDispatch: 0x5581e580ed80 flush: tid=5
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::WriteBlockImageDispatch: 0x5581e5766cf0 flush: tid=5
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::ImageDispatch: 0x5581e580e7b0 flush:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::ImageRequest: 0x7ff198b0ee00 send: aio_flush: ictx=0x5581e5819c60, completion=0x7ff180010ef0
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff180010ef0 set_request_count: pending=1
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e58614a0 send: dispatch_spec=0x7ff174006230
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::cache::WriteAroundObjectDispatch: 0x7ff174002730 flush:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::SimpleSchedulerObjectDispatch: 0x7ff174003350 flush:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::SimpleSchedulerObjectDispatch: 0x7ff174003350 dispatch_all_delayed_requests:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::Dispatcher: 0x5581e58614a0 send: dispatch_spec=0x7ff174006230
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff180010ef0 complete_request: cb=1, pending=0
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AioCompletion: 0x7ff180010ef0 finalize: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 handle_flush_io: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 send_flush_notifies:
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::io::AsyncOperation: 0x7ff180011000 finish_op
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 handle_flush_notifies:
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 send_close_object_map:
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::object_map::UnlockRequest: 0x7ff174006a60 send_unlock: oid=rbd_object_map.be32ac9b290c61
 -03-13T14:06:19.510+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.107:6810/9088,v1:172.18.16.107:6811/9088] -- osd_op(unknown.0.0:41 15213.3d5 15213:abc89829:::rbd_object_map.be32ac9b290c61:head [call lock.unlock in=32b] snapc 0=[] ondisk+write+known_if_redirected e521434) v8 -- 0x7ff17400cbd0 con 0x7ff180011570
 -03-13T14:06:19.510+0100 7ff19b319700  1 -- 172.18.16.209:0/1425925285 <== osd.69 v2:172.18.16.107:6810/9088 5 ==== osd_op_reply(41 rbd_object_map.be32ac9b290c61 [call] v521434'104363834 uv104363834 ondisk = 0) v8 ==== 173+0+0 (crc 0 0 0) 0x7ff194017070 con 0x7ff180011570
 -03-13T14:06:19.510+0100 7ff199315700 10 librbd::object_map::UnlockRequest: 0x7ff174006a60 handle_unlock: r=0
 -03-13T14:06:19.510+0100 7ff199315700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 handle_close_object_map: r=0
 -03-13T14:06:19.510+0100 7ff199315700 10 librbd::exclusive_lock::PreReleaseRequest: 0x7ff180008000 send_unlock:
 -03-13T14:06:19.510+0100 7ff199315700 10 librbd::ManagedLock: 0x7ff174001f98 handle_shutdown_pre_release: r=0
 -03-13T14:06:19.510+0100 7ff199315700 10 librbd::managed_lock::ReleaseRequest: 0x7ff1941e0b90 send_unlock: entity=client.2059286549, cookie=auto 140675010013520
 -03-13T14:06:19.510+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:42 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [call lock.unlock in=52b] snapc 0=[] ondisk+write+known_if_redirected e521434) v8 -- 0x7ff180018130 con 0x7ff180008740
 -03-13T14:06:19.510+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 45 ==== osd_op_reply(42 rbd_header.be32ac9b290c61 [call] v521434'190148210 uv190148210 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::managed_lock::ReleaseRequest: 0x7ff1941e0b90 handle_unlock: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::ExclusiveLock: 0x7ff174001f80 post_release_lock_handler: r=0 shutting_down=1
 -03-13T14:06:19.510+0100 7ff198b14700  5 librbd::io::Dispatcher: 0x5581e580e710 shut_down_dispatch: dispatch_layer=3
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff180007790 notify released lock
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff180007790 current lock owner: [0,0]
 -03-13T14:06:19.510+0100 7ff198b14700 20 librbd::watcher::Notifier: 0x7ff180007810 notify: pending=1
 -03-13T14:06:19.510+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:43 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify cookie 140675010025008 in=38b] snapc 0=[] ondisk+read+known_if_redirected e521434) v8 -- 0x7ff17400d4f0 con 0x7ff180008740
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::ManagedLock: 0x7ff174001f98 handle_shutdown_post_release: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::ManagedLock: 0x7ff174001f98 wait_for_tracked_ops: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::ManagedLock: 0x7ff174001f98 complete_shutdown: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 handle_shut_down_exclusive_lock: r=0
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 send_unregister_image_watcher
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::ImageWatcher: 0x7ff180007790 unregistering image watcher
 -03-13T14:06:19.510+0100 7ff198b14700 10 librbd::Watcher: 0x7ff180007790 unregister_watch:
 -03-13T14:06:19.510+0100 7ff198b14700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:44 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [watch unwatch cookie 140675010013520] snapc 0=[] ondisk+write+known_if_redirected e521434) v8 -- 0x7ff17400dfd0 con 0x7ff180008740
 -03-13T14:06:19.510+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 46 ==== watch-notify(notify (1) cookie 140675010013520 notify 2239541977022726 ret 0) v3 ==== 68+0+0 (crc 0 0 0) 0x7ff18c0239c0 con 0x7ff180008740
 -03-13T14:06:19.510+0100 7ff199315700  5 librbd::Watcher: 0x7ff180007790 notifications_blocked: blocked=1
 -03-13T14:06:19.510+0100 7ff199315700  1 -- 172.18.16.209:0/1425925285 --> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] -- osd_op(unknown.0.0:45 15213.1b3 15213:cdb776eb:::rbd_header.be32ac9b290c61:head [notify-ack in=20b] snapc 0=[] ondisk+read+known_if_redirected e521434) v8 -- 0x7ff180018130 con 0x7ff180008740
 -03-13T14:06:19.510+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 47 ==== osd_op_reply(43 rbd_header.be32ac9b290c61 [notify cookie 140675010025008 out=8b] v0'0 uv190148210 ondisk = 0) v8 ==== 169+0+8 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.514+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 48 ==== osd_op_reply(44 rbd_header.be32ac9b290c61 [watch unwatch cookie 140675010013520] v521434'190148211 uv190148210 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.514+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 49 ==== osd_op_reply(45 rbd_header.be32ac9b290c61 [notify-ack] v0'0 uv190148210 ondisk = 0) v8 ==== 169+0+0 (crc 0 0 0) 0x7ff18c0031b0 con 0x7ff180008740
 -03-13T14:06:19.514+0100 7ff17bfff700 10 librbd::image::CloseRequest: 0x5581e5863550 handle_unregister_image_watcher: r=0
 -03-13T14:06:19.514+0100 7ff17bfff700 10 librbd::image::CloseRequest: 0x5581e5863550 send_flush_readahead
 -03-13T14:06:19.514+0100 7ff19ab18700  1 -- 172.18.16.209:0/1425925285 <== osd.70 v2:172.18.16.108:6821/8603 50 ==== watch-notify(notify_complete (2) cookie 140675010025008 notify 2239541977022726 ret 0) v3 ==== 42+0+28 (crc 0 0 0) 0x7ff18c023bf0 con 0x7ff180008740
 -03-13T14:06:19.514+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 handle_flush_readahead: r=0
 -03-13T14:06:19.514+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 send_shut_down_image_dispatcher
 -03-13T14:06:19.514+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: r=0
 -03-13T14:06:19.514+0100 7ff198b14700 20 librbd::io::AsyncOperation: 0x7ff174002180 start_op
 -03-13T14:06:19.514+0100 7ff198b14700  5 librbd::io::Dispatcher: 0x5581e580e710 shut_down:
 -03-13T14:06:19.514+0100 7ff199315700 20 librbd::watcher::Notifier: 0x7ff180007810 handle_notify: pending=0
 -03-13T14:06:19.514+0100 7ff198b14700 20 librbd::io::FlushTracker: 0x5581e56eb1d0 shut_down:
 -03-13T14:06:19.514+0100 7ff198b14700 20 librbd::io::FlushTracker: 0x5581e56ec2c0 shut_down:
 -03-13T14:06:19.514+0100 7ff198b14700 20 librbd::io::AsyncOperation: 0x7ff174002180 finish_op
 -03-13T14:06:19.514+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 handle_shut_down_image_dispatcher: r=0
 -03-13T14:06:19.514+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 send_shut_down_object_dispatcher
 -03-13T14:06:19.514+0100 7ff198b14700  5 librbd::io::Dispatcher: 0x5581e58614a0 shut_down:
 -03-13T14:06:19.514+0100 7ff198b14700  5 librbd::io::ObjectDispatch: 0x5581e580ee20 shut_down:
 -03-13T14:06:19.514+0100 7ff198b14700  5 librbd::io::SimpleSchedulerObjectDispatch: 0x7ff174003350 shut_down:
 -03-13T14:06:19.514+0100 7ff198b14700 20 librbd::io::FlushTracker: 0x7ff18001b2e0 shut_down:
 -03-13T14:06:19.514+0100 7ff198b14700  5 librbd::cache::WriteAroundObjectDispatch: 0x7ff174002730 shut_down:
 -03-13T14:06:19.514+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 handle_shut_down_object_dispatcher: r=0
 -03-13T14:06:19.514+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 send_flush_op_work_queue
 -03-13T14:06:19.514+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 handle_flush_op_work_queue: r=0
 -03-13T14:06:19.514+0100 7ff198b14700 10 librbd::image::CloseRequest: 0x5581e5863550 handle_flush_image_watcher: r=0
 -03-13T14:06:19.514+0100 7ff198b14700 10 librbd::ImageState: 0x5581e5861420 0x5581e5861420 handle_close: r=0
 -03-13T14:06:19.514+0100 7ff17bfff700 10 librbd::ImageCtx: 0x5581e5819c60 ~ImageCtx
 -03-13T14:06:19.514+0100 7ff17bfff700 20 librbd::AsioEngine: 0x5581e5860c00 ~AsioEngine:
 -03-13T14:06:19.514+0100 7ff17bfff700 20 librbd::asio::ContextWQ: 0x5581e5861370 ~ContextWQ:
 -03-13T14:06:19.514+0100 7ff17bfff700 20 librbd::asio::ContextWQ: 0x5581e5861370 drain:
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 >> [v2:172.18.16.101:6842/8695,v1:172.18.16.101:6843/8695] conn(0x7ff174007090 msgr2=0x7ff1740074d0 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.101:6842/8695,v1:172.18.16.101:6843/8695] conn(0x7ff174007090 0x7ff1740074d0 crc :-1 s=READY pgs=43820 cs=0 l=1 rev1=1 rx=0 tx=0).stop
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6819/9074,v1:172.18.16.107:6822/9074] conn(0x5581e5866690 msgr2=0x5581e5868a80 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6819/9074,v1:172.18.16.107:6822/9074] conn(0x5581e5866690 0x5581e5868a80 crc :-1 s=READY pgs=16172 cs=0 l=1 rev1=1 rx=0 tx=0).stop
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6852/9082,v1:172.18.16.107:6854/9082] conn(0x7ff180016e20 msgr2=0x7ff180017c40 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6852/9082,v1:172.18.16.107:6854/9082] conn(0x7ff180016e20 0x7ff180017c40 crc :-1 s=READY pgs=18015 cs=0 l=1 rev1=1 rx=0 tx=0).stop
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6810/9088,v1:172.18.16.107:6811/9088] conn(0x7ff180011570 msgr2=0x7ff1800139d0 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.107:6810/9088,v1:172.18.16.107:6811/9088] conn(0x7ff180011570 0x7ff1800139d0 crc :-1 s=READY pgs=18915 cs=0 l=1 rev1=1 rx=0 tx=0).stop
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 >> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] conn(0x7ff180008740 msgr2=0x7ff18000abc0 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
 -03-13T14:06:19.514+0100 7ff19b319700  1 -- 172.18.16.209:0/1425925285 reap_dead start
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.108:6821/8603,v1:172.18.16.108:6825/8603] conn(0x7ff180008740 0x7ff18000abc0 crc :-1 s=READY pgs=17779 cs=0 l=1 rev1=1 rx=0 tx=0).stop
 -03-13T14:06:19.514+0100 7ff19b319700  1 -- 172.18.16.209:0/1425925285 reap_dead start
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 >> [v2:172.18.16.151:6898/19419,v1:172.18.16.151:6899/19419] conn(0x7ff17c18c750 msgr2=0x7ff17c18ec10 secure :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.151:6898/19419,v1:172.18.16.151:6899/19419] conn(0x7ff17c18c750 0x7ff17c18ec10 secure :-1 s=READY pgs=18504011 cs=0 l=1 rev1=1 rx=0x5581e5812d80 tx=0x7ff18c000bc0).stop
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 >> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] conn(0x5581e580b9a0 msgr2=0x5581e5818e20 secure :-1 s=STATE_CONNECTION_ESTABLISHED l=1).mark_down
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] conn(0x5581e580b9a0 0x5581e5818e20 secure :-1 s=READY pgs=12677485 cs=0 l=1 rev1=1 rx=0x7ff19400d900 tx=0x7ff194007040).stop
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 shutdown_connections
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.155:3300/0,v1:172.18.16.155:6789/0] conn(0x5581e580b9a0 0x5581e5818e20 unknown :-1 s=CLOSED pgs=12677485 cs=0 l=1 rev1=1 rx=0 tx=0).stop
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 --2- 172.18.16.209:0/1425925285 >> [v2:172.18.16.151:6898/19419,v1:172.18.16.151:6899/19419] conn(0x7ff17c18c750 0x7ff17c18ec10 unknown :-1 s=CLOSED pgs=18504011 cs=0 l=1 rev1=1 rx=0 tx=0).stop
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 >> 172.18.16.209:0/1425925285 conn(0x5581e57fffe0 msgr2=0x5581e580be50 unknown :-1 s=STATE_NONE l=0).mark_down
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 shutdown_connections
 -03-13T14:06:19.514+0100 7ff19c6e9340  1 -- 172.18.16.209:0/1425925285 wait complete.

« Previous
1
…
8
9
10
11
12
…
17
Next »

(10-10/17)

Project

General

Profile

Ceph » bluestore

Bug #58707 » roel-disk-4-snapshot-create.log