Project

General

Profile

Bug #22660 » rbd_rename_consistencyIssue_console_log.txt

Debashis Mondal, 01/11/2018 08:25 AM

 
[root@ceph-server ~]#
[root@ceph-server ~]# rbd rename mypool/Myimage4 mypool/Myimage1
2017-12-27 12:09:09.453296 7fdb9b161d80 1 -- :/0 messenger.start
2017-12-27 12:09:09.453643 7fdb9b161d80 1 -- :/3063323630 --> 10.0.1.140:6789/0 -- auth(proto 0 30 bytes epoch 0) v1 -- ?+0 0x5596cec4d930 con 0x5596cec47ce0
2017-12-27 12:09:09.461132 7fdb9b159700 1 -- 10.0.1.140:0/3063323630 learned my addr 10.0.1.140:0/3063323630
2017-12-27 12:09:09.461883 7fdb7f4c3700 1 -- 10.0.1.140:0/3063323630 <== mon.0 10.0.1.140:6789/0 1 ==== mon_map magic: 0 v1 ==== 201+0+0 (3122463574 0 0) 0x7fdb74000be0 con 0x5596cec47ce0
2017-12-27 12:09:09.461924 7fdb7f4c3700 1 -- 10.0.1.140:0/3063323630 <== mon.0 10.0.1.140:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (196555554 0 0) 0x7fdb740010a0 con 0x5596cec47ce0
2017-12-27 12:09:09.462004 7fdb7f4c3700 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- ?+0 0x7fdb70001390 con 0x5596cec47ce0
2017-12-27 12:09:09.462445 7fdb7f4c3700 1 -- 10.0.1.140:0/3063323630 <== mon.0 10.0.1.140:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 206+0+0 (2687841102 0 0) 0x7fdb740010a0 con 0x5596cec47ce0
2017-12-27 12:09:09.462508 7fdb7f4c3700 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6789/0 -- auth(proto 2 165 bytes epoch 0) v1 -- ?+0 0x7fdb70001810 con 0x5596cec47ce0
2017-12-27 12:09:09.462940 7fdb7f4c3700 1 -- 10.0.1.140:0/3063323630 <== mon.0 10.0.1.140:6789/0 4 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 393+0+0 (364995070 0 0) 0x7fdb740010a0 con 0x5596cec47ce0
2017-12-27 12:09:09.462997 7fdb7f4c3700 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6789/0 -- mon_subscribe({monmap=0+}) v2 -- ?+0 0x5596cec519f0 con 0x5596cec47ce0
2017-12-27 12:09:09.463058 7fdb9b161d80 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6789/0 -- mon_subscribe({osdmap=0}) v2 -- ?+0 0x5596cec50ad0 con 0x5596cec47ce0
2017-12-27 12:09:09.463982 7fdb7f4c3700 1 -- 10.0.1.140:0/3063323630 <== mon.0 10.0.1.140:6789/0 5 ==== mon_map magic: 0 v1 ==== 201+0+0 (3122463574 0 0) 0x7fdb740013c0 con 0x5596cec47ce0
2017-12-27 12:09:09.464011 7fdb7f4c3700 1 -- 10.0.1.140:0/3063323630 <== mon.0 10.0.1.140:6789/0 6 ==== osd_map(371..371 src has 1..371) v3 ==== 7454+0+0 (3865180693 0 0) 0x7fdb74003360 con 0x5596cec47ce0
2017-12-27 12:09:09.464466 7fdb9b161d80 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6804/136902 -- osd_op(client.534102.0:1 11.6e5607a5 rbd_id.Myimage4 [stat] snapc 0=[] ack+read+known_if_redirected e371) v7 -- ?+0 0x5596cec57090 con 0x5596cec55b10
2017-12-27 12:09:09.465498 7fdb7c2bb700 1 -- 10.0.1.140:0/3063323630 <== osd.0 10.0.1.140:6804/136902 1 ==== osd_op_reply(1 rbd_id.Myimage4 [stat] v0'0 uv5997 ondisk = 0) v7 ==== 135+0+16 (2542313769 0 2228027123) 0x7fdb64000b40 con 0x5596cec55b10
2017-12-27 12:09:09.465583 7fdb6ffff700 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6804/136902 -- osd_op(client.534102.0:2 11.6e5607a5 rbd_id.Myimage4 [call rbd.get_id] snapc 0=[] ack+read+known_if_redirected e371) v7 -- ?+0 0x7fdb58002030 con 0x5596cec55b10
2017-12-27 12:09:09.465974 7fdb7c2bb700 1 -- 10.0.1.140:0/3063323630 <== osd.0 10.0.1.140:6804/136902 2 ==== osd_op_reply(2 rbd_id.Myimage4 [call] v0'0 uv5997 ondisk = 0) v7 ==== 135+0+17 (443782589 0 3802630161) 0x7fdb64000b40 con 0x5596cec55b10
2017-12-27 12:09:09.466074 7fdb6ffff700 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6800/137051 -- osd_op(client.534102.0:3 11.ff1e6b23 rbd_header.7d83e74b0dc51 [call rbd.get_size,call rbd.get_object_prefix] snapc 0=[] ack+read+known_if_redirected e371) v7 -- ?+0 0x7fdb580075f0 con 0x7fdb580060e0
2017-12-27 12:09:09.474628 7fdb6effd700 1 -- 10.0.1.140:0/3063323630 <== osd.1 10.0.1.140:6800/137051 1 ==== osd_op_reply(3 rbd_header.7d83e74b0dc51 [call,call] v0'0 uv24763 ondisk = 0) v7 ==== 186+0+35 (3476160404 0 4264741077) 0x5596cec57090 con 0x7fdb580060e0
2017-12-27 12:09:09.474717 7fdb6ffff700 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6800/137051 -- osd_op(client.534102.0:4 11.ff1e6b23 rbd_header.7d83e74b0dc51 [call rbd.get_stripe_unit_count] snapc 0=[] ack+read+known_if_redirected e371) v7 -- ?+0 0x7fdb580075f0 con 0x7fdb580060e0
2017-12-27 12:09:09.475177 7fdb6effd700 1 -- 10.0.1.140:0/3063323630 <== osd.1 10.0.1.140:6800/137051 2 ==== osd_op_reply(4 rbd_header.7d83e74b0dc51 [call] v0'0 uv0 ondisk = -8 ((8) Exec format error)) v7 ==== 144+0+0 (4235233407 0 0) 0x5596cec57090 con 0x7fdb580060e0
2017-12-27 12:09:09.475249 7fdb6ffff700 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6800/137051 -- osd_op(client.534102.0:5 11.ff1e6b23 rbd_header.7d83e74b0dc51 [call rbd.metadata_list] snapc 0=[] ack+read+known_if_redirected e371) v7 -- ?+0 0x7fdb58001fb0 con 0x7fdb580060e0
2017-12-27 12:09:09.475671 7fdb6effd700 1 -- 10.0.1.140:0/3063323630 <== osd.1 10.0.1.140:6800/137051 3 ==== osd_op_reply(5 rbd_header.7d83e74b0dc51 [call] v0'0 uv24763 ondisk = 0) v7 ==== 144+0+4 (3553210548 0 0) 0x5596cec57090 con 0x7fdb580060e0
2017-12-27 12:09:09.475984 7fdb6ffff700 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6800/137051 -- osd_op(client.534102.0:6 11.ff1e6b23 rbd_header.7d83e74b0dc51 [watch watch cookie 140580050993216] snapc 0=[] ondisk+write+known_if_redirected e371) v7 -- ?+0 0x7fdb58008390 con 0x7fdb580060e0
2017-12-27 12:09:09.501485 7fdb6effd700 1 -- 10.0.1.140:0/3063323630 <== osd.1 10.0.1.140:6800/137051 4 ==== osd_op_reply(6 rbd_header.7d83e74b0dc51 [watch watch cookie 140580050993216] v371'24768 uv24763 ondisk = 0) v7 ==== 144+0+0 (41080548 0 0) 0x5596cec57090 con 0x7fdb580060e0
2017-12-27 12:09:09.501638 7fdb6ffff700 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6800/137051 -- osd_op(client.534102.0:7 11.ff1e6b23 rbd_header.7d83e74b0dc51 [call rbd.get_size,call rbd.get_features,call rbd.get_snapcontext,call rbd.get_parent,call lock.get_info] snapc 0=[] ack+read+known_if_redirected e371) v7 -- ?+0 0x7fdb58012410 con 0x7fdb580060e0
2017-12-27 12:09:09.502997 7fdb6effd700 1 -- 10.0.1.140:0/3063323630 <== osd.1 10.0.1.140:6800/137051 5 ==== osd_op_reply(7 rbd_header.7d83e74b0dc51 [call,call,call,call,call] v0'0 uv24763 ondisk = 0) v7 ==== 312+0+88 (3776724993 0 515677951) 0x5596cec57c30 con 0x7fdb580060e0
2017-12-27 12:09:09.503076 7fdb6ffff700 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6800/137051 -- osd_op(client.534102.0:8 11.ff1e6b23 rbd_header.7d83e74b0dc51 [call rbd.get_flags] snapc 0=[] ack+read+known_if_redirected e371) v7 -- ?+0 0x7fdb5800ab40 con 0x7fdb580060e0
2017-12-27 12:09:09.503446 7fdb6effd700 1 -- 10.0.1.140:0/3063323630 <== osd.1 10.0.1.140:6800/137051 6 ==== osd_op_reply(8 rbd_header.7d83e74b0dc51 [call] v0'0 uv24763 ondisk = 0) v7 ==== 144+0+8 (3009119625 0 0) 0x5596cec57c30 con 0x7fdb580060e0
2017-12-27 12:09:09.503591 7fdb9b161d80 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6804/136902 -- osd_op(client.534102.0:9 11.25928e55 Myimage1.rbd [stat] snapc 0=[] ack+read+known_if_redirected e371) v7 -- ?+0 0x5596cec582b0 con 0x5596cec55b10
2017-12-27 12:09:09.503920 7fdb7c2bb700 1 -- 10.0.1.140:0/3063323630 <== osd.0 10.0.1.140:6804/136902 3 ==== osd_op_reply(9 Myimage1.rbd [stat] v0'0 uv0 ack = -2 ((2) No such file or directory)) v7 ==== 132+0+0 (2353321716 0 0) 0x7fdb64000b40 con 0x5596cec55b10
2017-12-27 12:09:09.503994 7fdb9b161d80 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6804/136902 -- osd_op(client.534102.0:10 11.9c40436c rbd_id.Myimage1 [stat] snapc 0=[] ack+read+known_if_redirected e371) v7 -- ?+0 0x5596cec582b0 con 0x5596cec55b10
2017-12-27 12:09:09.504415 7fdb7c2bb700 1 -- 10.0.1.140:0/3063323630 <== osd.0 10.0.1.140:6804/136902 4 ==== osd_op_reply(10 rbd_id.Myimage1 [stat] v0'0 uv2700 ondisk = 0) v7 ==== 135+0+16 (1060303533 0 1192786783) 0x7fdb64000f40 con 0x5596cec55b10
2017-12-27 12:09:09.504441 7fdb9b161d80 -1 librbd::Operations: rbd image Myimage1 already exists
2017-12-27 12:09:09.504477 7fdb6f7fe700 1 -- 10.0.1.140:0/3063323630 --> 10.0.1.140:6800/137051 -- osd_op(client.534102.0:11 11.ff1e6b23 rbd_header.7d83e74b0dc51 [watch unwatch cookie 140580050993216] snapc 0=[] ondisk+write+known_if_redirected e371) v7 -- ?+0 0x7fdb680014e0 con 0x7fdb580060e0
2017-12-27 12:09:09.517725 7fdb6effd700 1 -- 10.0.1.140:0/3063323630 <== osd.1 10.0.1.140:6800/137051 7 ==== osd_op_reply(11 rbd_header.7d83e74b0dc51 [watch unwatch cookie 140580050993216] v371'24769 uv24763 ondisk = 0) v7 ==== 144+0+0 (3167274714 0 0) 0x5596cec58170 con 0x7fdb580060e0
rbd: rename error: (17) File exists
2017-12-27 12:09:09.518320 7fdb9b161d80 1 -- 10.0.1.140:0/3063323630 mark_down 0x5596cec55b10 -- 0x5596cec54800
2017-12-27 12:09:09.518351 7fdb9b161d80 1 -- 10.0.1.140:0/3063323630 mark_down 0x7fdb580060e0 -- 0x7fdb58004e20
2017-12-27 12:09:09.518380 7fdb9b161d80 1 -- 10.0.1.140:0/3063323630 mark_down 0x5596cec47ce0 -- 0x5596cec4f720
2017-12-27 12:09:09.519469 7fdb9b161d80 1 -- 10.0.1.140:0/3063323630 mark_down_all
2017-12-27 12:09:09.519677 7fdb9b161d80 1 -- 10.0.1.140:0/3063323630 shutdown complete.
[root@ceph-server ~]#


[root@ceph-server ~]#
[root@ceph-server ~]# ceph osd map mypool Myimage1
osdmap e372 pool 'mypool' (11) object 'Myimage1' -> pg 11.2b1201ee (11.2) -> up ([0], p0) acting ([0], p0)
[root@ceph-server ~]#
[root@ceph-server ~]#
[root@ceph-server ~]# cd /var/lib/ceph/osd/ceph-0/current/11.2_head/
[root@ceph-server 11.2_head]# ls
__head_00000002__b rbd\uid.Myimage19__head_6E7B3BEE__b rbd\uid.Myimage64__head_2758901E__b rbd\uid.Newimage55__head_5CCC0CCA__b
journal\udata.11.7d83e74b0dc51.3__head_83AEB0E2__b rbd\uid.Myimage3__head_048B672E__b rbd\uid.Myimage7__head_C9648E5E__b rbd\uid.Newimage64__head_E66F7E86__b
rbd\uid.Myimage10__head_1762A6E2__b rbd\uid.Myimage51__head_F7219A36__b rbd\uid.Newimage25__head_F4D87136__b
rbd\uid.Myimage17__head_00B473D6__b rbd\uid.Myimage52__head_D154FC96__b rbd\uid.Newimage4__head_4EE89DAE__b
[root@ceph-server 11.2_head]# cd ..
[root@ceph-server current]# cd /var/lib/ceph/osd/ceph-0/current/11.2_TEMP
[root@ceph-server 11.2_TEMP]# ls
[root@ceph-server 11.2_TEMP]# cd ..
[root@ceph-server current]# cd ..
[root@ceph-server ceph-0]# ls
ceph_fsid current fsid journal keyring magic ready store_version superblock type whoami
[root@ceph-server ceph-0]#
(3-3/3)