Snapshots in conjunction with VM move broken

[mhoffmann75]

Thanks for all the fixes but on stress testing RBDSR with XenServer 7 i think i found just another misbeaviour. There seems to be a bug when creating/deleting snapshots close after moving a VM from one host to another (XenServer pool with RBDSR Shared Storage)

This way you can reproduce the problem (latest commit 31):

1. Move VM from host1 to host2
2. Wait till move finished and VM is on host2
3. Create Snapshot => VDI Snapshot failed

Logs from host1 (The VM is already running on host2 !!!)

Aug 5 12:13:38 host1 SM: [24229] vdi_snapshot {'sr_uuid': 'ff12160f-ff09-40bb-a874-1366ad907f44', 'subtask_of': 'DummyRef:|054ee25b-87c4-28a2-da15-109a675c3d30|VDI.snapshot', 'vdi_ref': 'OpaqueRef:e4d27111-6f88-da9f-2eb7-0d7f31b59a2b', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': '9599b3e2-8b65-4c6a-9d52-2183701dad4b', 'host_ref': 'OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df', 'session_ref': 'OpaqueRef:6828020c-c41f-90c6-ece3-26cb7a99a150', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_snapshot', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:eab55273-a6e8-6963-3264-7f2df1efd9f5', 'driver_params': {'epochhint': '973a1296-876a-3c6c-6292-f9475ce88265'}, 'vdi_uuid': '9599b3e2-8b65-4c6a-9d52-2183701dad4b'} Aug 5 12:13:38 host1 SM: [24229] RBDVDI.snapshot for 9599b3e2-8b65-4c6a-9d52-2183701dad4b Aug 5 12:13:38 host1 SM: [24229] ['uuidgen', '-r'] Aug 5 12:13:38 host1 SM: [24229] preit SUCCESS Aug 5 12:13:38 host1 SM: [24229] ['rbd', 'image-meta', 'list', 'VHD-9599b3e2-8b65-4c6a-9d52-2183701dad4b', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44', '--format', 'json', '--name', 'client.admin'] Aug 5 12:13:38 host1 SM: [24229] preit SUCCESS Aug 5 12:13:38 host1 SM: [24229] Pause request for 9599b3e2-8b65-4c6a-9d52-2183701dad4b Aug 5 12:13:38 host1 SM: [24229] Calling tap-pause on host OpaqueRef:3d55d0be-ab56-8ed8-10ad-bc00ea96ecc9 Aug 5 12:13:38 host1 SM: [24229] ['realpath', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-9599b3e2-8b65-4c6a-9d52-2183701dad4b'] Aug 5 12:13:38 host1 SM: [24229] preit SUCCESS Aug 5 12:13:38 host1 SM: [24229] ['unlink', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-9599b3e2-8b65-4c6a-9d52-2183701dad4b'] Aug 5 12:13:38 host1 SM: [24229] FAILED in util.pread: (rc 1) stdout: '', stderr: 'unlink: cannot unlink '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-9599b3e2-8b65-4c6a-9d52-2183701dad4b': No such file or directory Aug 5 12:13:38 host1 SM: [24229] ' Aug 5 12:13:38 host1 SM: [24229] * vdi_snapshot: EXCEPTION <class 'util.CommandException'>, Operation not permitted Aug 5 12:13:38 host1 SM: [24229] File "/opt/xensource/sm/SRCommand.py", line 110, in run Aug 5 12:13:38 host1 SM: [24229] return self._run_locked(sr) Aug 5 12:13:38 host1 SM: [24229] File "/opt/xensource/sm/SRCommand.py", line 159, in _run_locked Aug 5 12:13:38 host1 SM: [24229] rv = self._run(sr, target) Aug 5 12:13:38 host1 SM: [24229] File "/opt/xensource/sm/SRCommand.py", line 249, in _run Aug 5 12:13:38 host1 SM: [24229] return target.snapshot(self.params['sr_uuid'], self.vdi_uuid) Aug 5 12:13:38 host1 SM: [24229] File "/opt/xensource/sm/RBDSR", line 452, in snapshot Aug 5 12:13:38 host1 SM: [24229] return self._snapshot(sr_uuid, vdi_uuid).get_params() Aug 5 12:13:38 host1 SM: [24229] File "/opt/xensource/sm/RBDSR", line 475, in _snapshot Aug 5 12:13:38 host1 SM: [24229] self._do_snapshot(base_uuid, snap_uuid) Aug 5 12:13:38 host1 SM: [24229] File "/opt/xensource/sm/cephutils.py", line 314, in _do_snapshot Aug 5 12:13:38 host1 SM: [24229] self._unmap_VHD(vdi_uuid) Aug 5 12:13:38 host1 SM: [24229] File "/opt/xensource/sm/cephutils.py", line 367, in _unmap_VHD Aug 5 12:13:38 host1 SM: [24229] util.pread2(["unlink", dev_name]) Aug 5 12:13:38 host1 SM: [24229] File "/opt/xensource/sm/util.py", line 189, in pread2 Aug 5 12:13:38 host1 SM: [24229] return pread(cmdlist, quiet = quiet) Aug 5 12:13:38 host1 SM: [24229] File "/opt/xensource/sm/util.py", line 182, in preit Aug 5 12:13:38 host1 SM: [24229] raise CommandException(rc, str(cmdlist), stderr.strip()) Aug 5 12:13:38 host1 SM: [24229] Aug 5 12:13:39 host1 SM: [24229] Raising exception [82, Failed to snapshot VDI [opterr=Command ['unlink', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-9599b3e2-8b65-4c6a-9d52-2183701dad4b'] failed (unlink: cannot unlink '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-9599b3e2-8b65-4c6a-9d52-2183701dad4b': No such file or directory): Operation not permitted]] Aug 5 12:13:39 host1 SM: [24229] * RBD: EXCEPTION <class 'SR.SROSError'>, Failed to snapshot VDI [opterr=Command ['unlink', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-9599b3e2-8b65-4c6a-9d52-2183701dad4b'] failed (unlink: cannot unlink '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-9599b3e2-8b65-4c6a-9d52-2183701dad4b': No such file or directory): Operation not permitted] Aug 5 12:13:39 host1 SM: [24229] File "/opt/xensource/sm/SRCommand.py", line 352, in run Aug 5 12:13:39 host1 SM: [24229] ret = cmd.run(sr) Aug 5 12:13:39 host1 SM: [24229] File "/opt/xensource/sm/SRCommand.py", line 120, in run Aug 5 12:13:39 host1 SM: [24229] raise xs_errors.XenError(excType, opterr=msg) Aug 5 12:13:39 host1 SM: [24229] File "/opt/xensource/sm/xs_errors.py", line 52, in init Aug 5 12:13:39 host1 SM: [24229] raise SR.SROSError(errorcode, error message Aug 5 12:13:39 host1 SM: [24229])

After that VM hangs and cannot be shutdown - host2 endlessly repeating:

Aug 5 12:17:10 host2 SM: [20333] lock: released /var/lock/sm/9599b3e2-8b65-4c6a-9d52-2183701dad4b/vdi Aug 5 12:17:11 host2 SM: [20333] lock: acquired /var/lock/sm/9599b3e2-8b65-4c6a-9d52-2183701dad4b/vdi Aug 5 12:17:11 host2 SM: [20333] Paused key found [{'vdi_type': 'aio', 'attached': 'true', 'paused': 'true', 'read-caching-enabled-on-0e08baee-c66b-4cd7-ab3a-0446cb40a2a0': 'false', 'read-caching-reason-0e08baee-c66b-4cd7-ab3a-0446cb40a2a0': 'LICENSE_RESTRICTION', 'host_OpaqueRef:3d55d0be-ab56-8ed8-10ad-bc00ea96ecc9': 'RW'}]

Similar problem seem to occur on snapshot removal:

1. create snapshot of VM on host1
2. wait till snapshot creation is done
3. move VM from host1 to host2
4. wait till move is done
5. try to delete snapshot => according to /var/log/SMlog XenServer tries to delete snapshot on host1 resulting in RBDSR errors.

Most of the time VM hangs and also host must be rebooted in order to fix this situation.

If you need i will be able to provide logs while problem occurs.

So whats going on here? Why does the old host try to do SR stuff and what can be done in RBDSR to fix this?

[Emmenemoi]

Yes, this is the issue I was talking about and it puts VM in bad state. Thanks for documenting. I'll create a xenserver7 branch because (my first impression from yesterday) it seems SR+RBDSR are both adding the paused state which crash the snapshot process. I'm not going to test on xenserver<7 and let other people check if the xs7 branch will be compatible with xs<7.

[rposudnevskiy]

Hi, This error occurs because we unmap image before making snapshot due to problem, described in issue #4. If we have only one host it works fine. But if we have more then one host the error occurs as the image mapped on host2 but snapshot operation is executed by pool master i.e. host1 and try to unmap image that already unmapped on host1. We could do not unmap the image before making snapshot but if we use nbd and try to make a snapshot the nbd device hang. So we should find a means how to unmap the image on the right host.

As workaround you can use FUSE mode as it doesn't use map/unmap

[mhoffmann75]

Hi, I was not aware that pool master is actually taking the snapshots - but sounds logical. Do you know if it's necessary to map/unmap on host2 (VM running on host2) when host1 is pool master and creating the snapshot? If not necessary then it would be enough for RDBSR to check for existence of the /dev/nbd/xxx device before unmapping. If it's also hanging the nbd driver on host2 then we need a mechanism for RBDSR on pool master to contact RBDSR on the pool member(s). Makes it quite complex i guess.

Same situation for VDI cloning?

[mhoffmann75]

BTW: fuse mode is broken in latest build, too:

['rbd-fuse', '-p', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44', '/run/sr-mount/ff12160f-ff09-40bb-a874-1366ad907f44', '--name', 'client.admin'] FAILED in util.pread: (rc 1) stdout: '', stderr: 'fuse: invalid argument `client.admin'

Seems as if rdb-fuse doesn't like: --name client.admin

Pull in from my fork to fix.

[Emmenemoi]

I added the fallback to kernel mode if fuse mode and cephx is used (commit 6e5ed2d7da5a470a1aea8dad7f33596eb00c9408)

[Emmenemoi]

By the way: why unmap + remap if blktap is paused + unpaused? Isn't it double "paused" of the FS ?

[rposudnevskiy]

because mapped nbd device hangs if you try to make snapshot of the image i don't know why it hangs but if you unmap before snapshot it doesn't hang

[mhoffmann75]

Has anyone actually tested if nbd does hang too on a mapped volume if snapshot is done on another host where the volume ist NOT mapped?

[rposudnevskiy]

Issue has been fixed. copy ceph_plugin.py to /etc/xapi.d/plugins on each host in pool rename to ceph_plugin and make it executable It now calls rbd-nbd map/unmap on the right host

Please test it

[mhoffmann75]

Just tested it - look very promising. VM Snapshot and snapshot deletion always worked. Regardless of host running on or moving to another host. So i guess you really fixed this. Well done!

[rposudnevskiy]

Ok. Thank you Martin. I'm going to close the issue.