Actions
Bug #40950
closedrbd: removing snaps failed: (2) No such file or directory
Status:
Closed
Priority:
Normal
Assignee:
-
Target version:
-
% Done:
0%
Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
I have some, perhaps ancient images:
# rbd info replicated_rbd/volume-0720f58e-69cf-4728-b6f4-1fd8bce43c14.deleted rbd image 'volume-0720f58e-69cf-4728-b6f4-1fd8bce43c14.deleted': size 15GiB in 3840 objects order 22 (4MiB objects) block_name_prefix: rbd_data.2765c3226ec1b8 format: 2 features: layering, striping, exclusive-lock, object-map, fast-diff flags: stripe unit: 4MiB stripe count: 1
# rbd snap ls replicated_rbd/volume-0720f58e-69cf-4728-b6f4-1fd8bce43c14.deleted SNAPID NAME SIZE TIMESTAMP 16 volume-10e16c30-17ad-41ab-af11-6e9e5ee4fb03.clone_snap 15GiB
# rados -p replicated_rbd listomapvals rbd_header.2765c3226ec1b8 features value (8 bytes) : 00000000 1f 00 00 00 00 00 00 00 |........| 00000008 flags value (8 bytes) : 00000000 00 00 00 00 00 00 00 00 |........| 00000008 object_prefix value (27 bytes) : 00000000 17 00 00 00 72 62 64 5f 64 61 74 61 2e 32 37 36 |....rbd_data.276| 00000010 35 63 33 32 32 36 65 63 31 62 38 |5c3226ec1b8| 0000001b order value (1 bytes) : 00000000 16 |.| 00000001 size value (8 bytes) : 00000000 00 00 00 c0 03 00 00 00 |........| 00000008 snap_seq value (8 bytes) : 00000000 10 00 00 00 00 00 00 00 |........| 00000008 snapshot_0000000000000010 value (149 bytes) : 00000000 06 01 8f 00 00 00 10 00 00 00 00 00 00 00 36 00 |..............6.| 00000010 00 00 76 6f 6c 75 6d 65 2d 31 30 65 31 36 63 33 |..volume-10e16c3| 00000020 30 2d 31 37 61 64 2d 34 31 61 62 2d 61 66 31 31 |0-17ad-41ab-af11| 00000030 2d 36 65 39 65 35 65 65 34 66 62 30 33 2e 63 6c |-6e9e5ee4fb03.cl| 00000040 6f 6e 65 5f 73 6e 61 70 00 00 00 c0 03 00 00 00 |one_snap........| 00000050 03 00 00 00 00 00 00 00 01 01 1c 00 00 00 ff ff |................| 00000060 ff ff ff ff ff ff 00 00 00 00 fe ff ff ff ff ff |................| 00000070 ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| 00000080 00 00 00 01 01 04 00 00 00 ff ff ff ff 00 00 00 |................| 00000090 00 00 00 00 00 |.....| 00000095
# rbd --debug_rbd=20 --debug_ms=1 snap unprotect replicated_rbd/volume-0720f58e-69cf-4728-b6f4-1fd8bce43c14.deleted@volume-10e16c30-17ad-41ab-af11-6e9e5ee4fb03.clone_snap 2019-07-25 16:00:05.020548 7f394b49ad40 1 Processor -- start 2019-07-25 16:00:05.020715 7f394b49ad40 1 -- - start start 2019-07-25 16:00:05.020944 7f394b49ad40 1 -- - --> 172.16.16.2:6789/0 -- auth(proto 0 34 bytes epoch 0) v1 -- 0x563a7a6cb920 con 0 2019-07-25 16:00:05.020957 7f394b49ad40 1 -- - --> 172.16.16.4:6789/0 -- auth(proto 0 34 bytes epoch 0) v1 -- 0x563a7a6cbc90 con 0 2019-07-25 16:00:05.021062 7f393b37b700 1 -- 172.16.16.2:0/387414038 learned_addr learned my addr 172.16.16.2:0/387414038 2019-07-25 16:00:05.021277 7f3923fff700 1 -- 172.16.16.2:0/387414038 <== mon.0 172.16.16.2:6789/0 1 ==== mon_map magic: 0 v1 ==== 433+0+0 (1676016757 0 0) 0x7f392c0012e0 con 0x563a7a6cd740 2019-07-25 16:00:05.021319 7f3923fff700 1 -- 172.16.16.2:0/387414038 <== mon.2 172.16.16.4:6789/0 1 ==== mon_map magic: 0 v1 ==== 433+0+0 (1676016757 0 0) 0x7f39300012a0 con 0x563a7a6d0d50 2019-07-25 16:00:05.021339 7f3923fff700 1 -- 172.16.16.2:0/387414038 <== mon.0 172.16.16.2:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (2567299762 0 0) 0x7f392c001610 con 0x563a7a6cd740 2019-07-25 16:00:05.021422 7f3923fff700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.2:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- 0x7f3910001d40 con 0 2019-07-25 16:00:05.021432 7f3923fff700 1 -- 172.16.16.2:0/387414038 <== mon.2 172.16.16.4:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (4193586236 0 0) 0x7f39300014c0 con 0x563a7a6d0d50 2019-07-25 16:00:05.021453 7f3923fff700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.4:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- 0x7f39100034b0 con 0 2019-07-25 16:00:05.021583 7f3923fff700 1 -- 172.16.16.2:0/387414038 <== mon.0 172.16.16.2:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 206+0+0 (801428586 0 0) 0x7f392c000eb0 con 0x563a7a6cd740 2019-07-25 16:00:05.021626 7f3923fff700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.2:6789/0 -- auth(proto 2 165 bytes epoch 0) v1 -- 0x7f39100024a0 con 0 2019-07-25 16:00:05.021634 7f3923fff700 1 -- 172.16.16.2:0/387414038 <== mon.2 172.16.16.4:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 206+0+0 (1903611240 0 0) 0x7f3930000e00 con 0x563a7a6d0d50 2019-07-25 16:00:05.021668 7f3923fff700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.4:6789/0 -- auth(proto 2 165 bytes epoch 0) v1 -- 0x7f39100029b0 con 0 2019-07-25 16:00:05.021812 7f3923fff700 1 -- 172.16.16.2:0/387414038 <== mon.0 172.16.16.2:6789/0 4 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 580+0+0 (1130696846 0 0) 0x7f392c001430 con 0x563a7a6cd740 2019-07-25 16:00:05.021857 7f3923fff700 1 -- 172.16.16.2:0/387414038 >> 172.16.16.4:6789/0 conn(0x563a7a6d0d50 :-1 s=STATE_OPEN pgs=33039961 cs=1 l=1).mark_down 2019-07-25 16:00:05.021887 7f3923fff700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.2:6789/0 -- mon_subscribe({monmap=0+}) v2 -- 0x563a7a6d75f0 con 0 2019-07-25 16:00:05.021923 7f394b49ad40 1 -- 172.16.16.2:0/387414038 --> 172.16.16.2:6789/0 -- mon_subscribe({mgrmap=0+}) v2 -- 0x563a7a6d75f0 con 0 2019-07-25 16:00:05.021979 7f394b49ad40 1 -- 172.16.16.2:0/387414038 --> 172.16.16.2:6789/0 -- mon_subscribe({osdmap=0}) v2 -- 0x563a7a6d75f0 con 0 2019-07-25 16:00:05.021990 7f3923fff700 1 -- 172.16.16.2:0/387414038 <== mon.0 172.16.16.2:6789/0 5 ==== mon_map magic: 0 v1 ==== 433+0+0 (1676016757 0 0) 0x7f392c001640 con 0x563a7a6cd740 2019-07-25 16:00:05.022069 7f3923fff700 1 -- 172.16.16.2:0/387414038 <== mon.0 172.16.16.2:6789/0 6 ==== mgrmap(e 829) v1 ==== 336+0+0 (1003204802 0 0) 0x7f392c001430 con 0x563a7a6cd740 2019-07-25 16:00:05.022108 7f3923fff700 1 -- 172.16.16.2:0/387414038 <== mon.0 172.16.16.2:6789/0 7 ==== osd_map(57003..57003 src has 56443..57003) v3 ==== 45964+0+0 (1221712999 0 0) 0x7f392c001fd0 con 0x563a7a6cd740 2019-07-25 16:00:05.022775 7f394b49ad40 5 librbd::io::ImageRequestWQ: 0x563a7a6d7c10 ImageRequestWQ: ictx=0x563a7a6d5ea0 2019-07-25 16:00:05.022823 7f394b49ad40 20 librbd::ImageState: 0x563a7a6cb900 open 2019-07-25 16:00:05.022833 7f394b49ad40 10 librbd::ImageState: 0x563a7a6cb900 0x563a7a6cb900 send_open_unlock 2019-07-25 16:00:05.022838 7f394b49ad40 10 librbd::image::OpenRequest: 0x563a7a6d8490 send_v2_detect_header 2019-07-25 16:00:05.022934 7f394b49ad40 1 -- 172.16.16.2:0/387414038 --> 172.16.16.11:6826/21514 -- osd_op(unknown.0.0:1 1.105 1:a0a19ee8:::rbd_id.volume-0720f58e-69cf-4728-b6f4-1fd8bce43c14.deleted:head [stat] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x563a7a6ddbb0 con 0 2019-07-25 16:00:05.023698 7f393a379700 1 -- 172.16.16.2:0/387414038 <== osd.9 172.16.16.11:6826/21514 1 ==== osd_op_reply(1 rbd_id.volume-0720f58e-69cf-4728-b6f4-1fd8bce43c14.deleted [stat] v0'0 uv44829207 ondisk = 0) v8 ==== 202+0+16 (1352357860 0 1175137936) 0x7f3924002180 con 0x563a7a6d9590 2019-07-25 16:00:05.023752 7f3920ff9700 10 librbd::image::OpenRequest: handle_v2_detect_header: r=0 2019-07-25 16:00:05.023757 7f3920ff9700 10 librbd::image::OpenRequest: 0x563a7a6d8490 send_v2_get_id 2019-07-25 16:00:05.023782 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.11:6826/21514 -- osd_op(unknown.0.0:2 1.105 1:a0a19ee8:::rbd_id.volume-0720f58e-69cf-4728-b6f4-1fd8bce43c14.deleted:head [call rbd.get_id] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f3904002230 con 0 2019-07-25 16:00:05.024018 7f393a379700 1 -- 172.16.16.2:0/387414038 <== osd.9 172.16.16.11:6826/21514 2 ==== osd_op_reply(2 rbd_id.volume-0720f58e-69cf-4728-b6f4-1fd8bce43c14.deleted [call] v0'0 uv44829207 ondisk = 0) v8 ==== 202+0+18 (603017223 0 1109612034) 0x7f3924002ac0 con 0x563a7a6d9590 2019-07-25 16:00:05.024033 7f3920ff9700 10 librbd::image::OpenRequest: handle_v2_get_id: r=0 2019-07-25 16:00:05.024040 7f3920ff9700 10 librbd::image::OpenRequest: 0x563a7a6d8490 send_v2_get_immutable_metadata 2019-07-25 16:00:05.024075 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:3 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [call rbd.get_size,call rbd.get_object_prefix] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f3904009a40 con 0 2019-07-25 16:00:05.025017 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 1 ==== osd_op_reply(3 rbd_header.2765c3226ec1b8 [call,call] v0'0 uv55663080 ondisk = 0) v8 ==== 211+0+36 (1373440895 0 1054985453) 0x7f3928002290 con 0x7f3904005420 2019-07-25 16:00:05.025034 7f3920ff9700 10 librbd::image::OpenRequest: handle_v2_get_immutable_metadata: r=0 2019-07-25 16:00:05.025037 7f3920ff9700 10 librbd::image::OpenRequest: 0x563a7a6d8490 send_v2_get_stripe_unit_count 2019-07-25 16:00:05.025052 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:4 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [call rbd.get_stripe_unit_count] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f3904002d60 con 0 2019-07-25 16:00:05.025312 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 2 ==== osd_op_reply(4 rbd_header.2765c3226ec1b8 [call] v0'0 uv55663080 ondisk = 0) v8 ==== 169+0+16 (2430960890 0 74706562) 0x7f39280024a0 con 0x7f3904005420 2019-07-25 16:00:05.025324 7f3920ff9700 10 librbd::image::OpenRequest: handle_v2_get_stripe_unit_count: r=0 2019-07-25 16:00:05.025326 7f3920ff9700 10 librbd::image::OpenRequest: 0x563a7a6d8490 send_v2_get_create_timestamp 2019-07-25 16:00:05.025339 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:5 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [call rbd.get_create_timestamp] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f39040020f0 con 0 2019-07-25 16:00:05.025543 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 3 ==== osd_op_reply(5 rbd_header.2765c3226ec1b8 [call] v0'0 uv55663080 ondisk = 0) v8 ==== 169+0+8 (2214946715 0 0) 0x7f39280026f0 con 0x7f3904005420 2019-07-25 16:00:05.025554 7f3920ff9700 10 librbd::image::OpenRequest: 0x563a7a6d8490 handle_v2_get_create_timestamp: r=0 2019-07-25 16:00:05.025557 7f3920ff9700 10 librbd::image::OpenRequest: 0x563a7a6d8490 send_v2_get_data_pool 2019-07-25 16:00:05.025571 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:6 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [call rbd.get_data_pool] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f39040020f0 con 0 2019-07-25 16:00:05.025762 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 4 ==== osd_op_reply(6 rbd_header.2765c3226ec1b8 [call] v0'0 uv55663080 ondisk = 0) v8 ==== 169+0+8 (3146824961 0 3293575501) 0x7f3928002410 con 0x7f3904005420 2019-07-25 16:00:05.025774 7f3920ff9700 10 librbd::image::OpenRequest: 0x563a7a6d8490 handle_v2_get_data_pool: r=0 2019-07-25 16:00:05.025785 7f3920ff9700 10 librbd::ImageCtx: init_layout stripe_unit 4194304 stripe_count 1 object_size 4194304 prefix rbd_data.2765c3226ec1b8 format rbd_data.2765c3226ec1b8.%016llx 2019-07-25 16:00:05.025788 7f3920ff9700 10 librbd::image::OpenRequest: 0x563a7a6d8490 send_v2_apply_metadata: start_key=conf_ 2019-07-25 16:00:05.025805 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:7 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [call rbd.metadata_list] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f3904004720 con 0 2019-07-25 16:00:05.026086 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 5 ==== osd_op_reply(7 rbd_header.2765c3226ec1b8 [call] v0'0 uv55663080 ondisk = 0) v8 ==== 169+0+4 (2434945042 0 0) 0x7f3928002620 con 0x7f3904005420 2019-07-25 16:00:05.026099 7f3920ff9700 10 librbd::image::OpenRequest: 0x563a7a6d8490 handle_v2_apply_metadata: r=0 2019-07-25 16:00:05.026111 7f3920ff9700 20 librbd::ImageCtx: apply_metadata 2019-07-25 16:00:05.030140 7f3920ff9700 20 librbd::ImageCtx: enabling caching... 2019-07-25 16:00:05.030144 7f3920ff9700 20 librbd::ImageCtx: Initial cache settings: size=33554432 num_objects=10 max_dirty=25165824 target_dirty=16777216 max_dirty_age=1 2019-07-25 16:00:05.030192 7f3920ff9700 10 librbd::ImageCtx: cache bytes 33554432 -> about 1048 objects 2019-07-25 16:00:05.030209 7f3920ff9700 10 librbd::image::OpenRequest: 0x563a7a6d8490 send_register_watch 2019-07-25 16:00:05.030260 7f3920ff9700 10 librbd::Watcher: 0x7f390400cb30 register_watch: 2019-07-25 16:00:05.030302 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:8 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [watch watch cookie 139882857030704] snapc 0=[] ondisk+write+known_if_redirected+full_try e57003) v8 -- 0x7f390400efb0 con 0 2019-07-25 16:00:05.031256 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 6 ==== osd_op_reply(8 rbd_header.2765c3226ec1b8 [watch watch cookie 139882857030704] v57003'68569264 uv55663080 ondisk = 0) v8 ==== 169+0+0 (3951113310 0 0) 0x7f3928002410 con 0x7f3904005420 2019-07-25 16:00:05.031272 7f3920ff9700 10 librbd::Watcher: 0x7f390400cb30 handle_register_watch: r=0 2019-07-25 16:00:05.031276 7f3920ff9700 10 librbd::image::OpenRequest: 0x563a7a6d8490 handle_register_watch: r=0 2019-07-25 16:00:05.031277 7f3920ff9700 10 librbd::image::OpenRequest: 0x563a7a6d8490 send_refresh 2019-07-25 16:00:05.031280 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 send_v2_get_mutable_metadata 2019-07-25 16:00:05.031310 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:9 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [call rbd.get_size,call rbd.get_features,call rbd.get_snapcontext,call rbd.get_parent,call lock.get_info] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f3904019370 con 0 2019-07-25 16:00:05.031802 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 7 ==== osd_op_reply(9 rbd_header.2765c3226ec1b8 [call,call,call,call,call] v0'0 uv55663080 ondisk = 0) v8 ==== 337+0+96 (2236300000 0 3525338307) 0x7f3928002620 con 0x7f3904005420 2019-07-25 16:00:05.031818 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 handle_v2_get_mutable_metadata: r=0 2019-07-25 16:00:05.031830 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 send_v2_get_metadata: start_key= 2019-07-25 16:00:05.031846 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:10 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [call rbd.metadata_list] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f3904010a80 con 0 2019-07-25 16:00:05.032090 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 8 ==== osd_op_reply(10 rbd_header.2765c3226ec1b8 [call] v0'0 uv55663080 ondisk = 0) v8 ==== 169+0+4 (169796802 0 0) 0x7f3928002410 con 0x7f3904005420 2019-07-25 16:00:05.032103 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 handle_v2_get_metadata: r=0 2019-07-25 16:00:05.032106 7f3920ff9700 20 librbd::ImageCtx: apply_metadata 2019-07-25 16:00:05.035732 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 send_v2_get_flags 2019-07-25 16:00:05.035832 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:11 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [call rbd.get_flags,call rbd.get_flags] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f39040120a0 con 0 2019-07-25 16:00:05.036109 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 9 ==== osd_op_reply(11 rbd_header.2765c3226ec1b8 [call,call] v0'0 uv55663080 ondisk = 0) v8 ==== 211+0+16 (1467156791 0 0) 0x7f3928003520 con 0x7f3904005420 2019-07-25 16:00:05.036123 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 handle_v2_get_flags: r=0 2019-07-25 16:00:05.036128 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 send_v2_get_group 2019-07-25 16:00:05.036142 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:12 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [call rbd.image_get_group] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f390400f850 con 0 2019-07-25 16:00:05.036338 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 10 ==== osd_op_reply(12 rbd_header.2765c3226ec1b8 [call] v0'0 uv55663080 ondisk = 0) v8 ==== 169+0+18 (145133082 0 3089390191) 0x7f3928003730 con 0x7f3904005420 2019-07-25 16:00:05.036350 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 handle_v2_get_group: r=0 2019-07-25 16:00:05.036355 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 send_v2_get_snapshots 2019-07-25 16:00:05.036377 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:13 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [call rbd.get_snapshot_name,call rbd.get_size,call rbd.get_parent,call rbd.get_protection_status] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f39040122d0 con 0 2019-07-25 16:00:05.036702 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 11 ==== osd_op_reply(13 rbd_header.2765c3226ec1b8 [call,call,call,call] v0'0 uv55663080 ondisk = 0) v8 ==== 295+0+96 (2895979804 0 302450594) 0x7f3928003c90 con 0x7f3904005420 2019-07-25 16:00:05.036717 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 handle_v2_get_snapshots: r=0 2019-07-25 16:00:05.036723 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 send_v2_get_snap_timestamps 2019-07-25 16:00:05.036737 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:14 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [call rbd.get_snapshot_timestamp] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f390400fe20 con 0 2019-07-25 16:00:05.036937 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 12 ==== osd_op_reply(14 rbd_header.2765c3226ec1b8 [call] v0'0 uv55663080 ondisk = 0) v8 ==== 169+0+8 (2572060462 0 0) 0x7f39280036c0 con 0x7f3904005420 2019-07-25 16:00:05.036949 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 handle_v2_get_snap_timestamps: r=0 2019-07-25 16:00:05.036951 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 send_v2_get_snap_namespaces 2019-07-25 16:00:05.036964 7f3920ff9700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:15 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [call rbd.get_snapshot_namespace] snapc 0=[] ondisk+read+known_if_redirected+full_try e57003) v8 -- 0x7f390400fe20 con 0 2019-07-25 16:00:05.037166 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 13 ==== osd_op_reply(15 rbd_header.2765c3226ec1b8 [call] v0'0 uv55663080 ondisk = 0) v8 ==== 169+0+10 (442448273 0 2850921400) 0x7f3928003c90 con 0x7f3904005420 2019-07-25 16:00:05.037179 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 handle_v2_get_snap_namespaces: r=0 2019-07-25 16:00:05.037188 7f3920ff9700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 send_v2_init_exclusive_lock 2019-07-25 16:00:05.037196 7f3920ff9700 10 librbd::ExclusiveLock: 0x7f3904012350 init 2019-07-25 16:00:05.037200 7f3920ff9700 5 librbd::io::ImageRequestWQ: 0x563a7a6d7c10 block_writes: 0x563a7a6d5ea0, num=1 2019-07-25 16:00:05.037214 7f3917fff700 10 librbd::ExclusiveLock: 0x7f3904012350 handle_init_complete: features=31 2019-07-25 16:00:05.037218 7f3917fff700 20 librbd::io::ImageRequestWQ: 0x563a7a6d7c10 set_require_lock: 2019-07-25 16:00:05.037220 7f3917fff700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 handle_v2_init_exclusive_lock: r=0 2019-07-25 16:00:05.037220 7f3917fff700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 send_v2_apply 2019-07-25 16:00:05.037226 7f3917fff700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 handle_v2_apply 2019-07-25 16:00:05.037227 7f3917fff700 20 librbd::image::RefreshRequest: 0x7f390400ecb0 apply 2019-07-25 16:00:05.037229 7f3917fff700 20 librbd::image::RefreshRequest: new snapshot id=16 name=volume-10e16c30-17ad-41ab-af11-6e9e5ee4fb03.clone_snap size=16106127360 2019-07-25 16:00:05.037241 7f3917fff700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 send_flush_aio 2019-07-25 16:00:05.037244 7f3917fff700 10 librbd::image::RefreshRequest: 0x7f390400ecb0 handle_flush_aio: r=0 2019-07-25 16:00:05.037246 7f3917fff700 10 librbd::image::OpenRequest: handle_refresh: r=0 2019-07-25 16:00:05.037249 7f3917fff700 10 librbd::ImageState: 0x563a7a6cb900 0x563a7a6cb900 handle_open: r=0 2019-07-25 16:00:05.037260 7f394b49ad40 20 librbd: snap_is_protected 0x563a7a6d5ea0 volume-10e16c30-17ad-41ab-af11-6e9e5ee4fb03.clone_snap rbd: unprotecting snap failed: (2) No such file or directory 2019-07-25 16:00:05.037275 7f394b49ad40 20 librbd::ImageState: 0x563a7a6cb900 close 2019-07-25 16:00:05.037277 7f394b49ad40 10 librbd::ImageState: 0x563a7a6cb900 0x563a7a6cb900 send_close_unlock 2019-07-25 16:00:05.037280 7f394b49ad40 10 librbd::image::CloseRequest: 0x563a7a635280 send_block_image_watcher 2019-07-25 16:00:05.037282 7f394b49ad40 10 librbd::ImageWatcher: 0x7f390400cb30 block_notifies 2019-07-25 16:00:05.037286 7f394b49ad40 5 librbd::Watcher: 0x7f390400cb30 block_notifies: blocked_count=1 2019-07-25 16:00:05.037289 7f394b49ad40 10 librbd::image::CloseRequest: 0x563a7a635280 handle_block_image_watcher: r=0 2019-07-25 16:00:05.037290 7f394b49ad40 10 librbd::image::CloseRequest: 0x563a7a635280 send_shut_down_update_watchers 2019-07-25 16:00:05.037291 7f394b49ad40 20 librbd::ImageState: 0x563a7a6cb900 shut_down_update_watchers 2019-07-25 16:00:05.037291 7f394b49ad40 20 librbd::ImageState: 0x563a7a6d6c70 ImageUpdateWatchers::shut_down 2019-07-25 16:00:05.037292 7f394b49ad40 20 librbd::ImageState: 0x563a7a6d6c70 ImageUpdateWatchers::shut_down: completing shut down 2019-07-25 16:00:05.037297 7f3917fff700 10 librbd::image::CloseRequest: 0x563a7a635280 handle_shut_down_update_watchers: r=0 2019-07-25 16:00:05.037298 7f3917fff700 10 librbd::image::CloseRequest: 0x563a7a635280 send_shut_down_io_queue 2019-07-25 16:00:05.037299 7f3917fff700 5 librbd::io::ImageRequestWQ: 0x563a7a6d7c10 shut_down: shut_down: in_flight=0 2019-07-25 16:00:05.037300 7f3917fff700 10 librbd::image::CloseRequest: 0x563a7a635280 handle_shut_down_io_queue: r=0 2019-07-25 16:00:05.037301 7f3917fff700 10 librbd::image::CloseRequest: 0x563a7a635280 send_shut_down_exclusive_lock 2019-07-25 16:00:05.037302 7f3917fff700 10 librbd::ExclusiveLock: 0x7f3904012350 shut_down 2019-07-25 16:00:05.037303 7f3917fff700 10 librbd::ManagedLock: 0x7f3904012350 shut_down 2019-07-25 16:00:05.037309 7f3917fff700 10 librbd::ManagedLock: 0x7f3904012350 send_shutdown 2019-07-25 16:00:05.037312 7f3917fff700 10 librbd::ExclusiveLock: 0x7f3904012350 shutdown_handler 2019-07-25 16:00:05.037313 7f3917fff700 20 librbd::io::ImageRequestWQ: 0x563a7a6d7c10 set_require_lock: 2019-07-25 16:00:05.037314 7f3917fff700 5 librbd::io::ImageRequestWQ: 0x563a7a6d7c10 unblock_writes: 0x563a7a6d5ea0, num=0 2019-07-25 16:00:05.037318 7f3917fff700 10 librbd::ManagedLock: 0x7f3904012350 handle_shutdown: r=0 2019-07-25 16:00:05.037318 7f3917fff700 10 librbd::ManagedLock: 0x7f3904012350 wait_for_tracked_ops: r=0 2019-07-25 16:00:05.037319 7f3917fff700 10 librbd::ManagedLock: 0x7f3904012350 complete_shutdown: r=0 2019-07-25 16:00:05.037321 7f3917fff700 10 librbd::image::CloseRequest: 0x563a7a635280 handle_shut_down_exclusive_lock: r=0 2019-07-25 16:00:05.037326 7f3917fff700 10 librbd::image::CloseRequest: 0x563a7a635280 send_unregister_image_watcher 2019-07-25 16:00:05.037327 7f3917fff700 10 librbd::ImageWatcher: 0x7f390400cb30 unregistering image watcher 2019-07-25 16:00:05.037329 7f3917fff700 10 librbd::Watcher: 0x7f390400cb30 unregister_watch: 2019-07-25 16:00:05.037351 7f3917fff700 1 -- 172.16.16.2:0/387414038 --> 172.16.16.16:6808/8296 -- osd_op(unknown.0.0:16 1.13c 1:3cabb4b0:::rbd_header.2765c3226ec1b8:head [watch unwatch cookie 139882857030704] snapc 0=[] ondisk+write+known_if_redirected+full_try e57003) v8 -- 0x7f390c0030a0 con 0 2019-07-25 16:00:05.038136 7f3939b78700 1 -- 172.16.16.2:0/387414038 <== osd.16 172.16.16.16:6808/8296 14 ==== osd_op_reply(16 rbd_header.2765c3226ec1b8 [watch unwatch cookie 139882857030704] v57003'68569265 uv55663080 ondisk = 0) v8 ==== 169+0+0 (2070309612 0 0) 0x7f3928003ea0 con 0x7f3904005420 2019-07-25 16:00:05.038174 7f3915ffb700 10 librbd::image::CloseRequest: 0x563a7a635280 handle_unregister_image_watcher: r=0 2019-07-25 16:00:05.038177 7f3915ffb700 10 librbd::image::CloseRequest: 0x563a7a635280 send_flush_readahead 2019-07-25 16:00:05.038186 7f3917fff700 10 librbd::image::CloseRequest: 0x563a7a635280 handle_flush_readahead: r=0 2019-07-25 16:00:05.038190 7f3917fff700 10 librbd::image::CloseRequest: 0x563a7a635280 send_shut_down_cache 2019-07-25 16:00:05.038212 7f3917fff700 10 librbd::image::CloseRequest: 0x563a7a635280 handle_shut_down_cache: r=0 2019-07-25 16:00:05.038214 7f3917fff700 10 librbd::image::CloseRequest: 0x563a7a635280 send_flush_op_work_queue 2019-07-25 16:00:05.038216 7f3917fff700 10 librbd::image::CloseRequest: 0x563a7a635280 handle_flush_op_work_queue: r=0 2019-07-25 16:00:05.038217 7f3917fff700 10 librbd::image::CloseRequest: 0x563a7a635280 handle_flush_image_watcher: r=0 2019-07-25 16:00:05.038231 7f3917fff700 10 librbd::ImageState: 0x563a7a6cb900 0x563a7a6cb900 handle_close: r=0 2019-07-25 16:00:05.038328 7f394b49ad40 1 -- 172.16.16.2:0/387414038 >> 172.16.16.11:6826/21514 conn(0x563a7a6d9590 :-1 s=STATE_OPEN pgs=293523 cs=1 l=1).mark_down 2019-07-25 16:00:05.038340 7f394b49ad40 1 -- 172.16.16.2:0/387414038 >> 172.16.16.16:6808/8296 conn(0x7f3904005420 :-1 s=STATE_OPEN pgs=32708 cs=1 l=1).mark_down 2019-07-25 16:00:05.038423 7f394b49ad40 1 -- 172.16.16.2:0/387414038 >> 172.16.16.2:6800/13270 conn(0x7f391000c000 :-1 s=STATE_OPEN pgs=25400478 cs=1 l=1).mark_down 2019-07-25 16:00:05.038434 7f394b49ad40 1 -- 172.16.16.2:0/387414038 >> 172.16.16.2:6789/0 conn(0x563a7a6cd740 :-1 s=STATE_OPEN pgs=29133480 cs=1 l=1).mark_down 2019-07-25 16:00:05.038445 7f393bb7c700 1 -- 172.16.16.2:0/387414038 reap_dead start 2019-07-25 16:00:05.038528 7f394b49ad40 1 -- 172.16.16.2:0/387414038 shutdown_connections 2019-07-25 16:00:05.038731 7f394b49ad40 1 -- 172.16.16.2:0/387414038 shutdown_connections 2019-07-25 16:00:05.038749 7f394b49ad40 1 -- 172.16.16.2:0/387414038 wait complete. 2019-07-25 16:00:05.038759 7f394b49ad40 1 -- 172.16.16.2:0/387414038 >> 172.16.16.2:0/387414038 conn(0x563a7a6bd170 :-1 s=STATE_NONE pgs=0 cs=0 l=0).mark_down
May be this affected old bug "Kraken release and Jewel client"? How to delete snapshot and then image if all compat options already set to Luminous?
Actions