rposudnevskiy / rbdsr Goto Github PK

Thank you for creating RBDSR. I was missing this solution since we are running XenServer and Ceph.
It seems to use cephs native functions as much as possible.

I tested RBDSR on our XenServer 7 with ceph jewel lab environment and without fixing some small things it did not work.
First of all, PROVISIONING_DEFAULT was not defined so looked in some of the original Citrix scripts and copied it from there.
I also had to remove all refrences to self.dconf['monitors'] because cephutils do not use them and do not expect them as paramter which causes errors.
I imported some VMs and copied other VMs from Local Storage to the RBD SR.
At this point most things worked, except for two tasks.

If a VM is already on the RBD SR and has no snapshots, I can not copy or clone it, because snap_sm_config["snapshot-of"] is not defined, but the clone function requires it.
Same error occurs if you convert the VM to an template and try to create new VMs from this template.
This part of my patch is not fix it is currently more a hack to make it work. There maybe a better way to handle this.

For another issue I did not find a solution: If you upgrade to ceph jewel, you get a permanent

 health HEALTH_WARN
        crush map has legacy tunables (require bobtail, min is firefly)

So you have to run at least:
ceph osd crush tunables firefly
or better:
ceph osd crush tunables optimal

Because the kernel of XenServer 7 is too old and the kernel module does not support all features, RBD mapping does not work anymore.
So you have to go back to
ceph osd crush tunables bobtail

Which works stable, but you have the permanent HEALTH_WARN again.

--- a/RBDSR.py  2016-06-30 13:26:46.000000000 +0200
+++ b/RBDSR.py  2016-07-19 23:58:28.000000000 +0200
@@ -27,7 +27,8 @@
 import xml.dom.minidom
 import blktap2

-CAPABILITIES = ["VDI_CREATE","VDI_DELETE","VDI_ATTACH","VDI_DETACH","VDI_CLONE","VDI_SNAPSHOT", "VDI_RESIZE", "VDI_RESIZE_ONLINE", "ATOMIC_PAUSE", "VDI_UPDATE"
+CAPABILITIES = ["VDI_CREATE","VDI_DELETE","VDI_ATTACH","VDI_DETACH",
+                "VDI_CLONE","VDI_SNAPSHOT", "VDI_RESIZE", "VDI_RESIZE_ONLINE", "ATOMIC_PAUSE", "VDI_UPDATE",
                 "SR_SCAN","SR_UPDATE","SR_ATTACH","SR_DETACH","SR_PROBE"]
 CONFIGURATION = []
 DRIVER_INFO = {
@@ -45,7 +46,10 @@

 class RBDSR(SR.SR):
     """Shared memory storage repository"""
-    
+
+    PROVISIONING_TYPES = ["thin", "thick"]
+    PROVISIONING_DEFAULT = "thick"
+ 
     def _loadvdis(self):
         """Scan the location directory."""
         if self.vdis:
@@ -160,7 +164,7 @@

     def probe(self):
         util.SMlog("RBDSR.probe for %s" % self.uuid)
-        return cephutils.srlist_toxml(cephutils.scan_srlist(self.dconf['monitors']))
+        return cephutils.srlist_toxml(cephutils.scan_srlist())

     def load(self, sr_uuid):
         """Initialises the SR"""
@@ -168,7 +172,7 @@
             raise xs_errors.XenError('ConfigDeviceMissing',)

         self.sr_vditype = 'rbd'
-        self.provision = PROVISIONING_DEFAULT
+        self.provision = self.PROVISIONING_DEFAULT
         self.uuid = sr_uuid


@@ -190,8 +194,8 @@
     def scan(self, sr_uuid):
         """Scan"""
         self.sr_vditype = 'rbd'
-        self.provision = PROVISIONING_DEFAULT
-        RBDPOOLs = cephutils.scan_srlist(self.dconf['monitors'])
+        self.provision = self.PROVISIONING_DEFAULT
+        RBDPOOLs = cephutils.scan_srlist()
         self.physical_size = cephutils._get_pool_info(RBDPOOLs[sr_uuid],'size')
         self.physical_utilisation = cephutils._get_pool_info(RBDPOOLs[sr_uuid],'used')
         RBDVDIs = cephutils.scan_vdilist(RBDPOOLs[self.uuid])
@@ -213,11 +217,11 @@
         valloc = int(self.session.xenapi.SR.get_virtual_allocation(self.sr_ref))
         self.virtual_allocation = valloc + int(virtAllocDelta)
         self.session.xenapi.SR.set_virtual_allocation(self.sr_ref, str(self.virtual_allocation))
-        RBDPOOLs = cephutils.scan_srlist(self.dconf['monitors'])
+        RBDPOOLs = cephutils.scan_srlist()
         self.session.xenapi.SR.set_physical_utilisation(self.sr_ref, str(cephutils._get_pool_info(RBDPOOLs[sr_uuid],'used')))

     def _isSpaceAvailable(self, sr_uuid, size):
-        RBDPOOLs = cephutils.scan_srlist(self.dconf['monitors'])
+        RBDPOOLs = cephutils.scan_srlist()
         sr_free_space = cephutils._get_pool_info(RBDPOOLs[sr_uuid],'size') - cephutils._get_pool_info(RBDPOOLs[sr_uuid],'used')
         if size > sr_free_space:
             return False
@@ -398,7 +402,12 @@

         snap_vdi_ref = self.session.xenapi.VDI.get_by_uuid(snap_uuid)
         snap_sm_config = self.session.xenapi.VDI.get_sm_config(snap_vdi_ref)
-        old_base_uuid = snap_sm_config["snapshot-of"]
+        if snap_sm_config.has_key("snapshot-of"):
+            old_base_uuid = snap_sm_config["snapshot-of"]
+        else:
+            snapVDI = self._snapshot(sr_uuid, snap_uuid)
+            return self.clone(sr_uuid, snapVDI.uuid)
+
         base_uuid = None

         vdis = self.session.xenapi.SR.get_VDIs(self.sr.sr_ref)
@@ -454,6 +463,9 @@
             return cloneVDI.get_params()

     def snapshot(self, sr_uuid, vdi_uuid):
+        return self._snapshot(self, sr_uuid, vdi_uuid).get_params()
+
+    def _snapshot(self, sr_uuid, vdi_uuid):
         util.SMlog("RBDVDI.snapshot for %s" % (vdi_uuid))

         secondary = None
@@ -494,7 +506,7 @@

         blktap2.VDI.tap_unpause(self.session, sr_uuid, vdi_uuid, secondary)

-        return snapVDI.get_params()
+        return snapVDI

     def resize(self, sr_uuid, vdi_uuid, size):
         """Resize the given VDI to size <size> MB. Size can

New version of XenServer 7.1 is just here.
I don't think is a good idea to have 1 plugin for all version.
Probably is better to have 3 plugins to have a best specific support for every platform.
I don't know really but maybe features can be differents across different XenServers.

What do you think?

Tests are required for pool metadata replication and Disaster Recovery support

While I'm trying to copy a VM from a Xen Pool to another I get this error: "the attempt to snapshot the VDI failed".

OLD XEN POOL
-> connect to Ceph CephRBDStorage1

NEW XEN POOL
-> connect to Ceph CephRBDStorage2

Some minuts later I can see that there are more than 1 copy of the same VDI on the CephRBDStorage1.
Except for the one attached to the VM all others miss the "Size" attribute which seems empty.

I'm using non xenserver tools to backup RBD images to a disaster recovery site using snap+export.
Unfortunately sr-scan tries to import those not protected snaps (1 per image).

This should not fail but just ignore them (everything that is not XS origins, using snap prefix):

Error code: SR_BACKEND_FAILURE_40
Error parameters: , The SR scan failed [opterr=['UUID_INVALID', 'VDI', 'backup2016-08-23T10.16.08']],

Delete a VM with snapshot:

 vdi_delete {'sr_uuid': '2C740292-44FC-40F6-9949-XXX', 'subtask_of': 'DummyRef:|0e2fd846-9404-2214-59a1-XXX|VDI.destroy', 'vdi_ref': 'OpaqueRef:de7f938d-55f4-d634-c669-XXX', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': '33dd263e-934f-4094-8794-XXX', 'host_ref': 'OpaqueRef:a3894b6e-409a-3cc3-0132-XXX', 'session_ref': 'OpaqueRef:8d28593e-933b-d7a4-7363-XXX', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_delete', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:f63541e3-eb71-1619-100d-XXX', 'vdi_uuid': '33dd263e-934f-4094-8794-XXX'}
Aug  8 10:52:14 xenserver-test SM: [14343] RBDVDI.delete for 33dd263e-934f-4094-8794-XXX
Aug  8 10:52:14 xenserver-test SM: [14343] Pause request for 9b0ccb0b-faa7-4b40-9409-XXX
Aug  8 10:52:14 xenserver-test SM: [14343] Calling _unmap_VHD
Aug  8 10:52:14 xenserver-test SM: [14343] Calling ceph_plugin
Aug  8 10:52:14 xenserver-test SM: [14343] ***** generic exception: vdi_delete: EXCEPTION <type 'exceptions.NameError'>, global name 'session' is not defined

vdi_delete {'sr_uuid': '2C740292-44FC-40F6-9949-XXX', 'subtask_of': 'DummyRef:|22c664dd-5e79-6741-de40-XXX|VDI.destroy', 'vdi_ref': 'OpaqueRef:7a12072b-c57a-e7a1-3d43-XXX', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': '9b0ccb0b-faa7-4b40-9409-XXX', 'host_ref': 'OpaqueRef:a3894b6e-409a-3cc3-0132-XXX', 'session_ref': 'OpaqueRef:97e967c8-5e88-3d8c-72af-XXX', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_delete', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:f63541e3-eb71-1619-100d-XXX', 'vdi_uuid': '9b0ccb0b-faa7-4b40-9409-XXX'}
Aug  8 10:54:12 xenserver-test SM: [14999] RBDVDI.delete for 9b0ccb0b-faa7-4b40-9409-XXX
Aug  8 10:54:12 xenserver-test SM: [14999] ['uuidgen', '-r']
Aug  8 10:54:12 xenserver-test SM: [14999]   pread SUCCESS
Aug  8 10:54:12 xenserver-test SM: [14999] ['rbd', 'mv', 'RBD_XenStorage-2C740292-44FC-40F6-9949-XXX/VHD-9b0ccb0b-faa7-4b40-9409-XXX', 'RBD_XenStorage-2C740292-44FC-40F6-9949-XXX/VHD-52ce7013-fb9f-4e87-af3a-XXX', '--name', 'client.xenserver']
Aug  8 10:54:13 xenserver-test SM: [14999]   pread SUCCESS
Aug  8 10:54:13 xenserver-test SM: [14999] RBDVDI.delete set snapshot_of = 9b0ccb0b-faa7-4b40-9409-XXX for 33dd263e-934f-4094-8794-XXX

Then SM scan fails:
sr_scan: EXCEPTION <class 'XenAPI.Failure'>, ['UUID_INVALID', 'VDI', '52ce7013-fb9f-4e87-af3a-XXX']

Because the RBD image is a snap (meta: SNAP-33dd263e-934f-4094-8794-XXX) of a deleted VDI.

Hy!

I just used your script and found 2 bug in the install.sh...

The first one is the if statement, cause it's stopped the running.
I put 3 ";" after the closing "]" tags, and the script goes forward...

The second one is the sparse_dd saving/copying.
First you mv the original, with -orig ending, and it's fine.
After that, you run this "cp bins/sparse_dd /usr/libexec/xapi/sparse_dd-orig"

After the script finished, you loose the orig file, and the toolstack will not start, since the sparse_dd binary will missing.

Sorry, that I not push codes, but I'am not familiar with proper developing methods... :(

Regards,
Peter

In the repo there some files that are included but there is no explanation about how and where to install them.

What are these files:

• tap-ctl
• vhd-tool

used for?

Do I need to install theme?
Where?

On XenServer 7 with Ceph Jewel we get the following error on xe pbd-plug attempt:

# xe pbd-plug uuid=xxxx
Error code: SR_BACKEND_FAILURE_90
Error parameters: , The request is missing the device parameter,

Any idea where to look at?
The patch mentioned here #1 does not seem to change anything....

Hi
My English is not good,Part of the use of google translation

I'm use CEPH RBD Storage_skip(The Xenserver's SR name) in a lot of xenserver

But i'm create and delete VDI in xenserverA , at the same time , in xenserverB will always show the VDI and xencenter not be del the VDI.

create VDI use xapi form template to CEPH RBD Storage_skip , template save as xen local‘s SR
delete VDI use xencenter , remove the VM by deleting the VDI

At last use "xe vdi-forget uuid=" can removed VDI in CEPH RBD Storage_skip(The Xenserver's SR name)

BUT!!!!!!!!!!!!!
Check CEPH use "ceph -s" Will not take up CEPH storage space

picture from xenserverB in xencenter

picture from xenserverB in xencenter

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?

I'm currently evaluating options for using Ceph with XenServer and apart from iSCSI bridges it seems RBDSR is the best option right now, but I couldn't find any information on how "production ready" this is or if anyone uses RBDSR in production.

Is there any experience on how stable RBDSR is when applying XS patches/hotfixes? Also, would there be any possibility to get someone who'd (commercially) support this in case of problems with updates? I'd really like to use it for our company cluster but I won't get any permission to do so unless I can find someone who'd be able to fix problems with it.

If I create a new VDI the physical-utilisation size shown when running xe vdi-param-list uuid= is incorrect.
I'm running XenServer7, ceph version 10.2.3 and the latest rbdsr code.

This is the values of a 10GB image.

virtual-size ( RO): 10737418240
physical-utilisation ( RO): 11258999068426240

This affects for instance if i try to run a move on it, then this value is checked when XenServer decides where there is space enough to place it.

This is not a very big issue since there is a work-around and that is to run xe sr-scan uuid=, after the values are correct.

virtual-size ( RO): 10737418240
physical-utilisation ( RO): 10737418240

[root@13 ~]# xe sr-scan uuid=a8726545-cc41-4ff3-b603-XXX
Error code: SR_BACKEND_FAILURE_40
Error parameters: , The SR scan failed [opterr=['INTERNAL_ERROR', 'Storage_interface.Vdi_does_not_exist("98bd94aa-2108-41fa-b92a-XXX")']],

But 98bd94aa-2108-41fa-b92a-XXX exists in both XS (xe vdi-list) and in ceph.

98bd94aa-2108-41fa-b92a-XXX is attached to a running VM.

I have an issue with one VDI.
Suddenly stop and show:

"Failed","Starting VM '
Internal error: xenopsd internal error: Memory_interface.Internal_error("VM = 980788af-7864-4a96-b5c3-8fbde2961fa9; domid = 42; Bootloader.Bad_error Traceback (most recent call last):\n  File \"/usr/bin/pygrub\", line 984, in <module>\n    part_offs = get_partition_offsets(file)\n  File \"/usr/bin/pygrub\", line 116, in get_partition_offsets\n    image_type = identify_disk_image(file)\n  File \"/usr/bin/pygrub\", line 60, in identify_disk_image\n    buf = os.read(fd, read_size_roundup(fd, 0x8006))\nOSError: [Errno 5] Input/output error\n")

The Readme states that migration is supported. Trying to do that in XenServer 7.1 with Ceph jewel is not working.
XenCenter reports: You attempted to migrate a VDI to or from an SR that doesn't support migration
I don't see any errors in SMlog or xensource.log
Tracking that issue down to the xapi script that handles migration its about the capabilities listed in RBDSR.py
Missing capabilities compared to NFS: SR_CACHING, VDI_GENERATE_CONFIG, VDI_MIRROR and VDI_RESET_ON_BOOT/2 but because it is not missing any capabilities compared to ISCSISR that can not be the reason.
Hopefully you can resolve that issue,

Thank you in advance

Daniel

Hi there,

Found a problem with rebooting VMs and tracked it down to a key error in the unmap call:

Dec 1 15:41:14 nyx3 SM: [10012] ***** BLKTAP2:<function _deactivate_locked at 0x2294938>: EXCEPTION <class 'XenAPI.Failure'>, ['XENAPI_PLUGIN_FAILURE', 'unmap', 'KeyError', "'sharable'"]
Dec 1 15:41:14 nyx3 SM: [10012] File "/opt/xensource/sm/blktap2.py", line 86, in wrapper
Dec 1 15:41:14 nyx3 SM: [10012] ret = op(self, *args)
Dec 1 15:41:14 nyx3 SM: [10012] File "/opt/xensource/sm/blktap2.py", line 1687, in _deactivate_locked
Dec 1 15:41:14 nyx3 SM: [10012] self._detach(sr_uuid, vdi_uuid)
Dec 1 15:41:14 nyx3 SM: [10012] File "/opt/xensource/sm/blktap2.py", line 1744, in _detach
Dec 1 15:41:14 nyx3 SM: [10012] self.target.detach(sr_uuid, vdi_uuid)
Dec 1 15:41:14 nyx3 SM: [10012] File "/opt/xensource/sm/blktap2.py", line 1119, in detach
Dec 1 15:41:14 nyx3 SM: [10012] self.vdi.detach(sr_uuid, vdi_uuid)
Dec 1 15:41:14 nyx3 SM: [10012] File "/opt/xensource/sm/RBDSR.py", line 424, in detach
Dec 1 15:41:14 nyx3 SM: [10012] self._unmap_VHD(vdi_uuid)
Dec 1 15:41:14 nyx3 SM: [10012] File "/opt/xensource/sm/cephutils.py", line 423, in _unmap_VHD
Dec 1 15:41:14 nyx3 SM: [10012] self._call_plugin('unmap',args)
Dec 1 15:41:14 nyx3 SM: [10012] File "/opt/xensource/sm/cephutils.py", line 377, in _call_plugin
Dec 1 15:41:14 nyx3 SM: [10012] if not self.session.xenapi.host.call_plugin(host_ref, "ceph_plugin", op, args):
Dec 1 15:41:14 nyx3 SM: [10012] File "/usr/lib/python2.7/site-packages/XenAPI.py", line 248, in call
Dec 1 15:41:14 nyx3 SM: [10012] return self.__send(self.__name, args)
Dec 1 15:41:14 nyx3 SM: [10012] File "/usr/lib/python2.7/site-packages/XenAPI.py", line 150, in xenapi_request
Dec 1 15:41:14 nyx3 SM: [10012] result = _parse_result(getattr(self, methodname)(*full_params))
Dec 1 15:41:14 nyx3 SM: [10012] File "/usr/lib/python2.7/site-packages/XenAPI.py", line 222, in _parse_result
Dec 1 15:41:14 nyx3 SM: [10012] raise Failure(result['ErrorDescription'])
Dec 1 15:41:14 nyx3 SM: [10012]
Dec 1 15:41:14 nyx3 SM: [10012] Raising exception [46, The VDI is not available [opterr=['XENAPI_PLUGIN_FAILURE', 'unmap', 'KeyError', "'sharable'"]]]
Dec 1 15:41:14 nyx3 SM: [10012] lock: released /var/lock/sm/784d503b-5a4e-45ef-8e1d-28c88bbdb6ae/vdi
Dec 1 15:41:14 nyx3 SM: [10012] ***** generic exception: vdi_deactivate: EXCEPTION <class 'SR.SROSError'>, The VDI is not available [opterr=['XENAPI_PLUGIN_FAILURE', 'unmap', 'KeyError', "'sharable'"]]

It seems that attribute isn't being passed in:

Dec 1 15:41:14 nyx3 xapi: [debug|nyx3|1082 UNIX /var/lib/xcp/xapi|host.call_plugin R:0eaa9abb212c|audit] Host.call_plugin host = '07ecd211-7e63-44e9-95ea-2fd3da5b5eee (nyx3)'; plugin = 'ceph_plugin'; fn = 'unmap'; args = [ CEPH_USER: client.admin; dev_name: /dev/nbd/RBD_XenStorage-3e115378-9791-4cf4-b973-0c228d1c1f64/VHD-784d503b-5a4e-45ef-8e1d-28c88bbdb6ae; vdi_name: VHD-784d503b-5a4e-45ef-8e1d-28c88bbdb6ae; mode: nbd; NBDS_MAX: 64; vdi_uuid: 784d503b-5a4e-45ef-8e1d-28c88bbdb6ae; CEPH_POOL_NAME: RBD_XenStorage-3e115378-9791-4cf4-b973-0c228d1c1f64 ]
Dec 1 15:41:14 nyx3 xapi: [error|nyx3|1082 UNIX /var/lib/xcp/xapi|dispatch:host.call_plugin D:e31d770f82e7|backtrace] host.call_plugin R:0eaa9abb212c failed with exception Server_error(XENAPI_PLUGIN_FAILURE, [ unmap; KeyError; 'sharable' ])
Dec 1 15:41:14 nyx3 xapi: [error|nyx3|1082 UNIX /var/lib/xcp/xapi|dispatch:host.call_plugin D:e31d770f82e7|backtrace] Raised Server_error(XENAPI_PLUGIN_FAILURE, [ unmap; KeyError; 'sharable' ])

I'm able to work around it for now by simply removing the assignment in the unmap function.

Cheers,
Brian

When several rbd-nbd images are mapped on a host, commands like "vgs" or "fdisk -l" hangs on this host, and impossible to kill those commands.

It seems VDI export (e.g. via XenCenter: Create Snapshot, Chose export to file or via API) is broken:

Aug 9 14:31:45 pns-xen07 SM: [29979] vdi_activate {'sr_uuid': 'ff12160f-ff09-40bb-a874-1366ad907f44', 'subtask_of': 'DummyRef:|257d0fe7-815c-b642-d3fe-2933c542939f|VDI.activate', 'vdi_ref': 'OpaqueRef:b33e90a3-6bed-cb06-52af-5dde1f8a5b0f', 'vdi_on_boot': 'persist', 'args': ['false'], 'vdi_location': '4ad1754e-701f-4403-8e03-a04ce33f83c3', 'host_ref': 'OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df', 'session_ref': 'OpaqueRef:90500cdf-1117-dafc-2520-8ecc4af1a7f5', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_activate', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:eab55273-a6e8-6963-3264-7f2df1efd9f5', 'vdi_uuid': '4ad1754e-701f-4403-8e03-a04ce33f83c3'}
Aug 9 14:31:45 pns-xen07 SM: [29979] lock: opening lock file /var/lock/sm/4ad1754e-701f-4403-8e03-a04ce33f83c3/vdi
Aug 9 14:31:45 pns-xen07 SM: [29979] blktap2.activate
Aug 9 14:31:45 pns-xen07 SM: [29979] lock: acquired /var/lock/sm/4ad1754e-701f-4403-8e03-a04ce33f83c3/vdi
Aug 9 14:31:45 pns-xen07 SM: [29979] Adding tag to: 4ad1754e-701f-4403-8e03-a04ce33f83c3
Aug 9 14:31:45 pns-xen07 SM: [29979] Activate lock succeeded
Aug 9 14:31:45 pns-xen07 SM: [29979] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Aug 9 14:31:45 pns-xen07 SM: [29979] preit SUCCESS
Aug 9 14:31:45 pns-xen07 SM: [29979] RBDVDI.attach for 4ad1754e-701f-4403-8e03-a04ce33f83c3
Aug 9 14:31:45 pns-xen07 SM: [29979] Calling _map_VHD
Aug 9 14:31:45 pns-xen07 SM: [29979] Calling ceph_plugin
Aug 9 14:31:45 pns-xen07 SM: [29979] Calling rbd/nbd map on host OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df
Aug 9 14:31:45 pns-xen07 SM: [29979] Raising exception [46, The VDI is not available [opterr=Could not find: /run/sr-mount/ff12160f-ff09-40bb-a874-1366ad907f44/VHD-4ad1754e-701f-4403-8e03-a04ce33f83c3]]
Aug 9 14:31:45 pns-xen07 SM: [29979] Exception in activate/attach
Aug 9 14:31:45 pns-xen07 SM: [29979] Removed host key host_OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df for 4ad1754e-701f-4403-8e03-a04ce33f83c3
Aug 9 14:31:45 pns-xen07 SM: [29979] ***** BLKTAP2:<function _activate_locked at 0x14b6668>: EXCEPTION <class 'SR.SROSError'>, The VDI is not available [opterr=Could not find: /run/sr-mount/ff12160f-ff09-40bb-a874-1366ad907f44/VHD-4ad1754e-701f-4403-8e03-a04ce33f83c3]
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 86, in wrapper
Aug 9 14:31:45 pns-xen07 SM: [29979] ret = op(self, *args)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 1593, in _activate_locked
Aug 9 14:31:45 pns-xen07 SM: [29979] self._attach(sr_uuid, vdi_uuid)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 1658, in _attach
Aug 9 14:31:45 pns-xen07 SM: [29979] attach_info = xmlrpclib.loads(self.target.attach(sr_uuid, vdi_uuid))[0][0]
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 1115, in attach
Aug 9 14:31:45 pns-xen07 SM: [29979] return self.vdi.attach(sr_uuid, vdi_uuid)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/RBDSR.py", line 388, in attach
Aug 9 14:31:45 pns-xen07 SM: [29979] raise xs_errors.XenError('VDIUnavailable', opterr='Could not find: %s' % self.path)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/xs_errors.py", line 52, in init
Aug 9 14:31:45 pns-xen07 SM: [29979] raise SR.SROSError(errorcode, errormessage)
Aug 9 14:31:45 pns-xen07 SM: [29979]
Aug 9 14:31:45 pns-xen07 SM: [29979] lock: released /var/lock/sm/4ad1754e-701f-4403-8e03-a04ce33f83c3/vdi
Aug 9 14:31:45 pns-xen07 SM: [29979] ***** generic exception: vdi_activate: EXCEPTION <class 'SR.SROSError'>, The VDI is not available [opterr=Could not find: /run/sr-mount/ff12160f-ff09-40bb-a874-1366ad907f44/VHD-4ad1754e-701f-4403-8e03-a04ce33f83c3]
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/SRCommand.py", line 110, in run
Aug 9 14:31:45 pns-xen07 SM: [29979] return self._run_locked(sr)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/SRCommand.py", line 159, in _run_locked
Aug 9 14:31:45 pns-xen07 SM: [29979] rv = self._run(sr, target)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/SRCommand.py", line 264, in _run
Aug 9 14:31:45 pns-xen07 SM: [29979] writable, caching_params)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 1560, in activate
Aug 9 14:31:45 pns-xen07 SM: [29979] if self._activate_locked(sr_uuid, vdi_uuid, options):
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 86, in wrapper
Aug 9 14:31:45 pns-xen07 SM: [29979] ret = op(self, *args)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 1593, in _activate_locked
Aug 9 14:31:45 pns-xen07 SM: [29979] self._attach(sr_uuid, vdi_uuid)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 1658, in _attach
Aug 9 14:31:45 pns-xen07 SM: [29979] attach_info = xmlrpclib.loads(self.target.attach(sr_uuid, vdi_uuid))[0][0]
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 1115, in attach
Aug 9 14:31:45 pns-xen07 SM: [29979] return self.vdi.attach(sr_uuid, vdi_uuid)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/RBDSR.py", line 388, in attach
Aug 9 14:31:45 pns-xen07 SM: [29979] raise xs_errors.XenError('VDIUnavailable', opterr='Could not find: %s' % self.path)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/xs_errors.py", line 52, in init
Aug 9 14:31:45 pns-xen07 SM: [29979] raise SR.SROSError(errorcode, errormessage)
Aug 9 14:31:45 pns-xen07 SM: [29979]
Aug 9 14:31:45 pns-xen07 SM: [29979] ***** RBD: EXCEPTION <class 'SR.SROSError'>, The VDI is not available [opterr=Could not find: /run/sr-mount/ff12160f-ff09-40bb-a874-1366ad907f44/VHD-4ad1754e-701f-4403-8e03-a04ce33f83c3]
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/SRCommand.py", line 352, in run
Aug 9 14:31:45 pns-xen07 SM: [29979] ret = cmd.run(sr)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/SRCommand.py", line 110, in run
Aug 9 14:31:45 pns-xen07 SM: [29979] return self._run_locked(sr)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/SRCommand.py", line 159, in _run_locked
Aug 9 14:31:45 pns-xen07 SM: [29979] rv = self._run(sr, target)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/SRCommand.py", line 264, in _run
Aug 9 14:31:45 pns-xen07 SM: [29979] writable, caching_params)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 1560, in activate
Aug 9 14:31:45 pns-xen07 SM: [29979] if self._activate_locked(sr_uuid, vdi_uuid, options):
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 86, in wrapper
Aug 9 14:31:45 pns-xen07 SM: [29979] ret = op(self, *args)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 1593, in _activate_locked
Aug 9 14:31:45 pns-xen07 SM: [29979] self._attach(sr_uuid, vdi_uuid)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 1658, in _attach
Aug 9 14:31:45 pns-xen07 SM: [29979] attach_info = xmlrpclib.loads(self.target.attach(sr_uuid, vdi_uuid))[0][0]
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/blktap2.py", line 1115, in attach
Aug 9 14:31:45 pns-xen07 SM: [29979] return self.vdi.attach(sr_uuid, vdi_uuid)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/RBDSR.py", line 388, in attach
Aug 9 14:31:45 pns-xen07 SM: [29979] raise xs_errors.XenError('VDIUnavailable', opterr='Could not find: %s' % self.path)
Aug 9 14:31:45 pns-xen07 SM: [29979] File "/opt/xensource/sm/xs_errors.py", line 52, in init
Aug 9 14:31:45 pns-xen07 SM: [29979] raise SR.SROSError(errorcode, errormessage)
Aug 9 14:31:45 pns-xen07 SM: [29979]

Unfortunately this renders backup solutions relying on any kind of export (e.g. XenOrchestra) useless

edit: the problem does not exist with v2.0

xen server 7.2 / ceph luminous

creating a pdb with
xe pbd-create sr-uuid=f9c45630a162 host-uuid=0174e10d-f6a9-4d2a-8cd8-d3118b40d375 device-config:rbd-mode=kernel

everything looks good until the VM is started - then i get:

tapdisk experienced an error

this is only happening with v1.0 - is it supposed to be working with kernel mode rbd?

I tried disabling rbd features for the image
rbd feature disable RBD_XenStorage-f9c45630a162/VHD-a45fdf50-8d3d-4e5a-b310-eaa2385be4bb exclusive-lock object-map fast-diff deep-flatten
but that didn't seem to have any effect. (it is necessary to do that if i want to map the image via rbd command)

Hi

The project might not consist of much code but the code must be reliable and stable as much as possible. To get reliability we need some more documentation on the core of rdbsr.
We should also have a list about things that need to be done.

Sincerely
Daniel

Hello guys.

Followed the install guide. Went well without any issues. However, upon staring vm got an error:

tapdisk: experienced an error.

from what I can see, the disk on the ceph pool got created fine with the right size.

Any idea what is wrong or where to find more info?

thanks

I don't know if it is related but:
Even if the VDI is not marked "read only", it is attached RO to a VM:

sm-config (MRO): attached: true; host_OpaqueRef:2dacdcbe-d559-2bd0-1815-809e88072bcb: RO

Can't find a reason.

Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|5 ||xenstore_watch] xenstore watch path=/vm/53514d1a-d2ff-dc80-9bc8-61bb2d31e57e/rtc/timeoffset token=xenopsd-xc:domain-12
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|3 |events|xenops_server] Received an event on managed VM 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|3 |queue|xenops_server] Queue.push ["VM_check_state", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"] onto redirected 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e:[ ["Atomic", ["VM_unpause", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"]], ["VM_check_state", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"] ]
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|3 |events|xenops_server] Received an event on managed VM 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|3 |queue|xenops_server] Queue.push ["VM_check_state", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"] onto redirected 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e:[ ["Atomic", ["VM_unpause", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"]], ["VM_check_state", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e"] ]
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] TASK.signal 262 = ["Pending", 0.250000]
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] Performing: ["VBD_set_active", ["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], true]
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] VBD.set_active 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e.xvda true
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] VBD_DB.signal 53514d1a-d2ff-dc80-9bc8-61bb2d31e57e.xvda
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] TASK.signal 262 = ["Pending", 0.333333]
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] Performing: ["Parallel", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "VBD.epoch_begin RW vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", []]
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] begin_Parallel:task=262.atoms=0.(VBD.epoch_begin RW vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e)
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] end_Parallel:task=262.atoms=0.(VBD.epoch_begin RW vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e)
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] TASK.signal 262 = ["Pending", 0.416667]
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] Performing: ["Parallel", "53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", [["VBD_epoch_begin", [["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"], true]]]]
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] begin_Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e)
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |VM.start R:210891658b2c|xenops_server] queue_atomics_and_wait: Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e): chunk of 1 atoms
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|39 |queue|xenops_server] Queue.push ["Atomic", ["VBD_epoch_begin", [["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"], true]]] onto Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e).chunk=0.atom=0:[ ]
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|30 ||xenops_server] Queue.pop returned ["Atomic", ["VBD_epoch_begin", [["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"], true]]]
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|30 |Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e)|xenops_server] Task 267 reference Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e): ["Atomic", ["VBD_epoch_begin", [["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"], ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"], true]]]
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|30 |Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e)|xenops_server] VBD.epoch_begin ["VDI", "2C740292-44FC-40F6-9949-1F68E59B9024/afba13c0-9906-459f-9b5d-3d9d9f3acf2a"]
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [ info|xenserver-test2|30 |Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e)|xenops] Processing disk SR=2C740292-44FC-40F6-9949-1F68E59B9024 VDI=afba13c0-9906-459f-9b5d-3d9d9f3acf2a
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|8 ||scheduler] Scheduler sleep until 1470762704 (another 24 seconds)
Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|178 |org.xen.xapi.xenops.classic events D:0d65cc36f692|xenops] Processing event: ["Task", "262"]
Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|178 |org.xen.xapi.xenops.classic events D:0d65cc36f692|xenops] xenops event on Task 262
Aug 9 19:11:19 xenserver-test2 xapi: [ info|xenserver-test2|2574 ||storage_impl] VDI.epoch_begin dbg:Parallel:task=262.atoms=1.(VBD.epoch_begin RO vm=53514d1a-d2ff-dc80-9bc8-61bb2d31e57e) sr:2C740292-44FC-40F6-9949-1F68E59B9024 vdi:afba13c0-9906-459f-9b5d-3d9d9f3acf2a persistent:true
Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|2575 ||dummytaskhelper] task VDI.epoch_begin D:f24d88170fde created by task R:ask=262.toms
Aug 9 19:11:19 xenserver-test2 xenopsd-xc: [debug|xenserver-test2|8 ||scheduler] Scheduler sleep until 1470762704 (another 24 seconds)
Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|2575 |VDI.epoch_begin D:f24d88170fde|sm] SM rbd vdi_epoch_begin sr=OpaqueRef:717833f2-b3c8-a0da-b5a3-abbe26981e47 vdi=OpaqueRef:82153e6e-58e1-ee6f-4926-b69391a33650
Aug 9 19:11:19 xenserver-test2 xapi: [ info|xenserver-test2|2575 |sm_exec D:b9d89462526d|xapi] Session.create trackid=e5d14fd9bbe0f238d304c130c60bfb73 pool=false uname= originator=xapi is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|2575 |sm_exec D:b9d89462526d|mscgen] xapi=>xapi [label="pool.get_all"];
Aug 9 19:11:19 xenserver-test2 xapi: [debug|xenserver-test2|178 |org.xen.xapi.xenops.classic events D:0d65cc36f692|xenops] Processing event: ["Vbd", ["53514d1a-d2ff-dc80-9bc8-61bb2d31e57e", "xvda"]]

Just another bug with commit 30:

Aug 5 09:09:36 pns-xen06 SM: [12284] ***** RBD: EXCEPTION <type 'exceptions.AttributeError'>, 'RBDSR' object has no attribute 'CEPH_USER'
Aug 5 09:09:36 pns-xen06 SM: [12284] File "/opt/xensource/sm/SRCommand.py", line 350, in run
Aug 5 09:09:36 pns-xen06 SM: [12284] sr = driver(cmd, cmd.sr_uuid)
Aug 5 09:09:36 pns-xen06 SM: [12284] File "/opt/xensource/sm/SR.py", line 147, in init
Aug 5 09:09:36 pns-xen06 SM: [12284] self.load(sr_uuid)
Aug 5 09:09:36 pns-xen06 SM: [12284] File "/opt/xensource/sm/RBDSR", line 178, in load
Aug 5 09:09:36 pns-xen06 SM: [12284] cephutils.SR.load(self,sr_uuid, ceph_user)
Aug 5 09:09:36 pns-xen06 SM: [12284] File "/opt/xensource/sm/cephutils.py", line 168, in load
Aug 5 09:09:36 pns-xen06 SM: [12284] self.RBDPOOLs = self._get_srlist()
Aug 5 09:09:36 pns-xen06 SM: [12284] File "/opt/xensource/sm/cephutils.py", line 155, in _get_srlist
Aug 5 09:09:36 pns-xen06 SM: [12284] cmdout = util.pread2(["ceph", "df", "--format", "json", "--name", self.CEPH_USER])
Aug 5 09:09:36 pns-xen06 SM: [12284]

I wonder if this has been tested?

Hi,

We've been working through testing the RBDSR code for deployment into our environment over the past few weeks, so far everything is looking good except the following bug that we've found.

When attempting to move a VM's to or from an LVM repository to an RBD repository, I've uploaded a section of the servers SMLog, also below is what I believe to be the relevant section.

Further information on the environment
XenServer 7 with XS70E17 installed
Ceph Jewel
RBDSR UUID = c3278df0-c7f5-4658-aa27-b61bccd7662a
Local SR UUID = f5aa74b2-3a98-860c-5b7a-7301ec8ba1b4

If there is any additional information that might help with this please let me know.

Nov  8 12:14:48 xenserver-testlab2 SM: [7028] Activate lock succeeded
Nov  8 12:14:48 xenserver-testlab2 SM: [7028] RBDSR.handles type rbd
Nov  8 12:14:48 xenserver-testlab2 SM: [7028] RBDSR.load using cephx id xenserver
Nov  8 12:14:48 xenserver-testlab2 SM: [7028] ['ceph', 'df', '--format', 'json', '--name', 'client.xenserver']
Nov  8 12:14:48 xenserver-testlab2 SM: [7028]   pread SUCCESS
Nov  8 12:14:48 xenserver-testlab2 SM: [7028] ['rbd', 'ls', '-l', '--format', 'json', '--pool', 'RBD_XenStorage-c3278df0-c7f5-4658-aa27-b61bccd7662a', '--name', 'client.xenserver']
Nov  8 12:14:48 xenserver-testlab2 SM: [7028]   pread SUCCESS
Nov  8 12:14:48 xenserver-testlab2 SM: [7028] RBDVDI.attach for c40b64c6-32b2-4299-9e08-a31024b2ea3d
Nov  8 12:14:48 xenserver-testlab2 SM: [7028] Calling _map_VHD
Nov  8 12:14:48 xenserver-testlab2 SM: [7028] Calling ceph_plugin
Nov  8 12:14:48 xenserver-testlab2 SM: [7028] Calling rbd/nbd map on host OpaqueRef:1941be1c-04a5-70fc-d7d6-bc2580811da8
Nov  8 12:14:49 xenserver-testlab2 SM: [7189] ['rbd-nbd', '--nbds_max', '64', 'map', 'RBD_XenStorage-c3278df0-c7f5-4658-aa27-b61bccd7662a/VHD-c40b64c6-32b2-4299-9e08-a31024b2ea3d', '--name', 'client.xenserver']
Nov  8 12:14:49 xenserver-testlab2 SM: [7189] FAILED in util.pread: (rc 1) stdout: '', stderr: 'rbd-nbd: failed to map, status: (2) No such file or directory
Nov  8 12:14:49 xenserver-testlab2 SM: [7189] 2016-11-08 12:14:49.147847 7f298627ce00 -1 asok(0x7f29910e1770) AdminSocketConfigObs::init: failed: AdminSocket::bind_and_listen: failed to bind the UNIX domain socket to '/var/run/ceph/ceph-client.xenserver.asok': (17) File exists
Nov  8 12:14:49 xenserver-testlab2 SM: [7189] '
Nov  8 12:14:49 xenserver-testlab2 SM: [7028] Exception in activate/attach
Nov  8 12:14:49 xenserver-testlab2 SM: [7028] Removed host key host_OpaqueRef:1941be1c-04a5-70fc-d7d6-bc2580811da8 for c40b64c6-32b2-4299-9e08-a31024b2ea3d
Nov  8 12:14:49 xenserver-testlab2 SM: [7028] ***** BLKTAP2:<function _activate_locked at 0x211c6e0>: EXCEPTION <class 'XenAPI.Failure'>, ['XENAPI_PLUGIN_FAILURE', 'map', 'CommandException', 'Operation not permitted']
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/blktap2.py", line 86, in wrapper
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     ret = op(self, *args)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/blktap2.py", line 1593, in _activate_locked
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     self._attach(sr_uuid, vdi_uuid)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/blktap2.py", line 1658, in _attach
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     attach_info = xmlrpclib.loads(self.target.attach(sr_uuid, vdi_uuid))[0][0]
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/blktap2.py", line 1115, in attach
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     return self.vdi.attach(sr_uuid, vdi_uuid)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/RBDSR.py", line 401, in attach
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     self._map_VHD(vdi_uuid)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/cephutils.py", line 372, in _call_plugin
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     if not self.session.xenapi.host.call_plugin(host_ref, "ceph_plugin", op, args):
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/usr/lib/python2.7/site-packages/XenAPI.py", line 248, in __call__
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     return self.__send(self.__name, args)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/usr/lib/python2.7/site-packages/XenAPI.py", line 150, in xenapi_request
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     result = _parse_result(getattr(self, methodname)(*full_params))
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/usr/lib/python2.7/site-packages/XenAPI.py", line 222, in _parse_result
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     raise Failure(result['ErrorDescription'])
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]
Nov  8 12:14:49 xenserver-testlab2 SM: [7028] Raising exception [46, The VDI is not available [opterr=['XENAPI_PLUGIN_FAILURE', 'map', 'CommandException', 'Operation not permitted']]]
Nov  8 12:14:49 xenserver-testlab2 SM: [7028] lock: released /var/lock/sm/c40b64c6-32b2-4299-9e08-a31024b2ea3d/vdi
Nov  8 12:14:49 xenserver-testlab2 SM: [7028] ***** generic exception: vdi_activate: EXCEPTION <class 'SR.SROSError'>, The VDI is not available [opterr=['XENAPI_PLUGIN_FAILURE', 'map', 'CommandException', 'Operation not permitted']]
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/SRCommand.py", line 110, in run
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     return self._run_locked(sr)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/SRCommand.py", line 159, in _run_locked
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     rv = self._run(sr, target)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/SRCommand.py", line 264, in _run
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     writable, caching_params)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/blktap2.py", line 1560, in activate
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     if self._activate_locked(sr_uuid, vdi_uuid, options):
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/blktap2.py", line 94, in wrapper
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     raise xs_errors.XenError(excType, opterr=msg)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/xs_errors.py", line 52, in __init__
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     raise SR.SROSError(errorcode, errormessage)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]
Nov  8 12:14:49 xenserver-testlab2 SM: [7028] ***** RBD: EXCEPTION <class 'SR.SROSError'>, The VDI is not available [opterr=['XENAPI_PLUGIN_FAILURE', 'map', 'CommandException', 'Operation not permitted']]
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/SRCommand.py", line 352, in run
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     ret = cmd.run(sr)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/SRCommand.py", line 110, in run
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     return self._run_locked(sr)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/SRCommand.py", line 159, in _run_locked
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     rv = self._run(sr, target)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/SRCommand.py", line 264, in _run
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     writable, caching_params)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/blktap2.py", line 1560, in activate
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     if self._activate_locked(sr_uuid, vdi_uuid, options):
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/blktap2.py", line 94, in wrapper
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     raise xs_errors.XenError(excType, opterr=msg)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]   File "/opt/xensource/sm/xs_errors.py", line 52, in __init__
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]     raise SR.SROSError(errorcode, errormessage)
Nov  8 12:14:49 xenserver-testlab2 SM: [7028]
Nov  8 12:14:49 xenserver-testlab2 SM: [7028] lock: closed /var/lock/sm/c40b64c6-32b2-4299-9e08-a31024b2ea3d/vdi
Nov  8 12:14:49 xenserver-testlab2 SM: [7224] lock: opening lock file /var/lock/sm/f5aa74b2-3a98-860c-5b7a-7301ec8ba1b4/sr
Nov  8 12:14:49 xenserver-testlab2 SM: [7224] LVMCache created for VG_XenStorage-f5aa74b2-3a98-860c-5b7a-7301ec8ba1b4
Nov  8 12:14:49 xenserver-testlab2 SM: [7224] ['/sbin/vgs', 'VG_XenStorage-f5aa74b2-3a98-860c-5b7a-7301ec8ba1b4']
Nov  8 12:14:53 xenserver-testlab2 SM: [7224]   pread SUCCESS
Nov  8 12:14:53 xenserver-testlab2 SM: [7224] Entering _checkMetadataVolume
Nov  8 12:14:53 xenserver-testlab2 SM: [7224] LVMCache: will initialize now
Nov  8 12:14:53 xenserver-testlab2 SM: [7224] LVMCache: refreshing
Nov  8 12:14:53 xenserver-testlab2 SM: [7224] ['/sbin/lvs', '--noheadings', '--units', 'b', '-o', '+lv_tags', '/dev/VG_XenStorage-f5aa74b2-3a98-860c-5b7a-7301ec8ba1b4']
Nov  8 12:14:56 xenserver-testlab2 SM: [7224]   pread SUCCESS
Nov  8 12:14:56 xenserver-testlab2 SM: [7224] vdi_deactivate {'sr_uuid': 'f5aa74b2-3a98-860c-5b7a-7301ec8ba1b4', 'subtask_of': 'DummyRef:|5ac4b40e-398b-90c9-f3fd-253c92e2875c|VDI.deactivate', 'vdi_ref': 'OpaqueRef:dc8fa82e-275b-03a6-a41f-297bc687cf2c', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': 'e711cd11-e3fe-456c-b42d-2e8c933354c6', 'host_ref': 'OpaqueRef:1941be1c-04a5-70fc-d7d6-bc2580811da8', 'session_ref': 'OpaqueRef:6d4ee445-d0d5-f456-32eb-7092a779ff78', 'device_config': {'device': '/dev/disk/by-id/ata-ST500DM002-1BD142_Z6EHZG38-part3', 'SRmaster': 'true'}, 'command': 'vdi_deactivate', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:5672509e-4c88-178d-d6a0-8f103b614caf', 'vdi_uuid': 'e711cd11-e3fe-456c-b42d-2e8c933354c6'}
Nov  8 12:14:56 xenserver-testlab2 SM: [7224] lock: opening lock file /var/lock/sm/e711cd11-e3fe-456c-b42d-2e8c933354c6/vdi
Nov  8 12:14:56 xenserver-testlab2 SM: [7224] blktap2.deactivate
Nov  8 12:14:56 xenserver-testlab2 SM: [7224] lock: acquired /var/lock/sm/e711cd11-e3fe-456c-b42d-2e8c933354c6/vdi
Nov  8 12:14:56 xenserver-testlab2 SM: [7224] ['/usr/sbin/tap-ctl', 'close', '-p', '6939', '-m', '21']
Nov  8 12:14:56 xenserver-testlab2 SM: [7224]  = 0
Nov  8 12:14:56 xenserver-testlab2 SM: [7224] Attempt to deregister tapdisk with RRDD.
Nov  8 12:14:56 xenserver-testlab2 SM: [7224] ERROR: Failed to deregister tapdisk with RRDD due to UnixStreamHTTP instance has no attribute 'getresponse'
Nov  8 12:14:56 xenserver-testlab2 SM: [7224] ['/usr/sbin/tap-ctl', 'detach', '-p', '6939', '-m', '21']
Nov  8 12:14:56 xenserver-testlab2 SM: [7224]  = 0
Nov  8 12:14:56 xenserver-testlab2 SM: [7224] ['/usr/sbin/tap-ctl', 'free', '-m', '21']
Nov  8 12:14:56 xenserver-testlab2 SM: [7224]  = 0

ceph-SXM-error.txt

It seems RBDSR is not compatible with XenOrchestra's DeltaBackup - backups simply "fail". Unfortunately no further information from XO and no obvious errors in Xen's SMlog:

Aug 11 21:03:59 pns-xen07 SM: [17729] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Aug 11 21:04:00 pns-xen07 SM: [17729] preit SUCCESS
Aug 11 21:04:00 pns-xen07 SM: [17729] vdi_snapshot {'sr_uuid': 'ff12160f-ff09-40bb-a874-1366ad907f44', 'subtask_of': 'DummyRef:|6680d904-5370-bad4-38c0-8f0d3c7249d9|VDI.snapshot', 'vdi_ref': 'OpaqueRef:c7b74e33-c24e-e757-9dda-89a68b638c12', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': '2851fb05-59fd-4159-ad0b-9a3b6219047e', 'host_ref': 'OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df', 'session_ref': 'OpaqueRef:6623272a-04bf-77bb-6650-d29f143b74c6', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_snapshot', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:5a051e6e-4e23-beff-e3c7-7f7c926575fc', 'driver_params': {'epochhint': '91d22328-25ca-b5a4-ef34-9e1f46213ffa'}, 'vdi_uuid': '2851fb05-59fd-4159-ad0b-9a3b6219047e'}
Aug 11 21:04:00 pns-xen07 SM: [17729] RBDVDI.snapshot for 2851fb05-59fd-4159-ad0b-9a3b6219047e
Aug 11 21:04:00 pns-xen07 SM: [17729] ['uuidgen', '-r']
Aug 11 21:04:00 pns-xen07 SM: [17729] preit SUCCESS
Aug 11 21:04:00 pns-xen07 SM: [17729] ['rbd', 'image-meta', 'list', 'VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44', '--format', 'json', '--name', 'client.admin']
Aug 11 21:04:00 pns-xen07 SM: [17729] preit SUCCESS
Aug 11 21:04:00 pns-xen07 SM: [17729] Pause request for 2851fb05-59fd-4159-ad0b-9a3b6219047e
Aug 11 21:04:00 pns-xen07 SM: [17729] Calling tap-pause on host OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df
Aug 11 21:04:00 pns-xen07 SM: [17816] lock: opening lock file /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:00 pns-xen07 SM: [17816] lock: acquired /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:00 pns-xen07 SM: [17816] Pause for 2851fb05-59fd-4159-ad0b-9a3b6219047e
Aug 11 21:04:00 pns-xen07 SM: [17816] Calling tap pause with minor 2
Aug 11 21:04:00 pns-xen07 SM: [17816] ['/usr/sbin/tap-ctl', 'pause', '-p', '7107', '-m', '2']
Aug 11 21:04:00 pns-xen07 SM: [17816] = 0
Aug 11 21:04:00 pns-xen07 SM: [17816] lock: released /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:00 pns-xen07 SM: [17816] lock: closed /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:00 pns-xen07 SM: [17729] Calling _unmap_VHD
Aug 11 21:04:00 pns-xen07 SM: [17729] Calling ceph_plugin
Aug 11 21:04:00 pns-xen07 SM: [17729] Calling rbd/nbd map on host OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df
Aug 11 21:04:00 pns-xen07 SM: [17824] ['realpath', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e']
Aug 11 21:04:00 pns-xen07 SM: [17824] preit SUCCESS
Aug 11 21:04:00 pns-xen07 SM: [17824] ['unlink', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e']
Aug 11 21:04:00 pns-xen07 SM: [17824] preit SUCCESS
Aug 11 21:04:00 pns-xen07 SM: [17824] ['rbd-nbd', 'unmap', '/dev/nbd2', '--name', 'client.admin']
Aug 11 21:04:00 pns-xen07 SM: [17824] preit SUCCESS
Aug 11 21:04:00 pns-xen07 SM: [17729] ['rbd', 'snap', 'create', 'VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e@SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44', '--name', 'client.admin']
Aug 11 21:04:01 pns-xen07 SM: [17729] preit SUCCESS
Aug 11 21:04:01 pns-xen07 SM: [17729] ['rbd', 'snap', 'protect', 'VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e@SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44', '--name', 'client.admin']
Aug 11 21:04:01 pns-xen07 SM: [17729] preit SUCCESS
Aug 11 21:04:01 pns-xen07 SM: [17729] Calling _map_VHD
Aug 11 21:04:01 pns-xen07 SM: [17729] Calling ceph_plugin
Aug 11 21:04:01 pns-xen07 SM: [17729] Calling rbd/nbd map on host OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df
Aug 11 21:04:02 pns-xen07 SM: [17913] ['rbd-nbd', '--nbds_max', '64', 'map', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e', '--name', 'client.admin']
Aug 11 21:04:02 pns-xen07 SM: [17913] preit SUCCESS
Aug 11 21:04:02 pns-xen07 SM: [17913] ['ln', '-s', '/dev/nbd2', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e']
Aug 11 21:04:02 pns-xen07 SM: [17913] preit SUCCESS
Aug 11 21:04:02 pns-xen07 SM: [17729] Unpause request for 2851fb05-59fd-4159-ad0b-9a3b6219047e secondary=None
Aug 11 21:04:02 pns-xen07 SM: [17729] Calling tap-unpause on host OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df
Aug 11 21:04:02 pns-xen07 SM: [17947] lock: opening lock file /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:02 pns-xen07 SM: [17947] lock: acquired /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:02 pns-xen07 SM: [17947] Unpause for 2851fb05-59fd-4159-ad0b-9a3b6219047e
Aug 11 21:04:02 pns-xen07 SM: [17947] Realpath: /dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e
Aug 11 21:04:02 pns-xen07 SM: [17947] Calling tap unpause with minor 2
Aug 11 21:04:02 pns-xen07 SM: [17947] ['/usr/sbin/tap-ctl', 'unpause', '-p', '7107', '-m', '2', '-a', 'aio:/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e']
Aug 11 21:04:02 pns-xen07 SM: [17947] = 0
Aug 11 21:04:02 pns-xen07 SM: [17947] lock: released /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:02 pns-xen07 SM: [17947] lock: closed /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:02 pns-xen07 SM: [17990] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Aug 11 21:04:03 pns-xen07 SM: [17990] preit SUCCESS
Aug 11 21:04:03 pns-xen07 SM: [17990] vdi_update {'sr_uuid': 'ff12160f-ff09-40bb-a874-1366ad907f44', 'subtask_of': 'DummyRef:|e602ebc0-6cc3-9649-9724-8c0ace59bfd4|VDI.update', 'vdi_ref': 'OpaqueRef:3e615ac2-6f17-d482-5792-8a688d6683de', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': '0850e980-6cb8-49bf-95d0-d777b1bf438f', 'host_ref': 'OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df', 'session_ref': 'OpaqueRef:c4b1c129-6b9c-7652-0b0d-32ca0d214127', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_update', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:5a051e6e-4e23-beff-e3c7-7f7c926575fc', 'vdi_uuid': '0850e980-6cb8-49bf-95d0-d777b1bf438f'}
Aug 11 21:04:03 pns-xen07 SM: [17990] RBDSR.update for 0850e980-6cb8-49bf-95d0-d777b1bf438f
Aug 11 21:04:03 pns-xen07 SM: [17990] ['rbd', 'image-meta', 'set', 'VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e', 'VDI_LABEL', 'Server2012R2 0', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44', '--name', 'client.admin']
Aug 11 21:04:03 pns-xen07 SM: [17990] preit SUCCESS
Aug 11 21:04:03 pns-xen07 SM: [17990] ['rbd', 'image-meta', 'set', 'VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e', 'VDI_DESCRIPTION', 'Created by template provisioner', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44', '--name', 'client.admin']
Aug 11 21:04:03 pns-xen07 SM: [17990] preit SUCCESS
Aug 11 21:04:03 pns-xen07 SM: [17990] ['rbd', 'image-meta', 'set', 'VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e', 'SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f', '20160811T19:03:59Z', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44', '--name', 'client.admin']
Aug 11 21:04:03 pns-xen07 SM: [17990] preit SUCCESS
Aug 11 21:04:04 pns-xen07 SM: [18140] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Aug 11 21:04:04 pns-xen07 SM: [18140] preit SUCCESS
Aug 11 21:04:04 pns-xen07 SM: [18140] vdi_attach {'sr_uuid': 'ff12160f-ff09-40bb-a874-1366ad907f44', 'subtask_of': 'DummyRef:|a14d28d2-c61e-5fef-8e3e-c734b15ac379|VDI.attach', 'vdi_ref': 'OpaqueRef:3e615ac2-6f17-d482-5792-8a688d6683de', 'vdi_on_boot': 'persist', 'args': ['false'], 'vdi_location': '0850e980-6cb8-49bf-95d0-d777b1bf438f', 'host_ref': 'OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df', 'session_ref': 'OpaqueRef:ba6f66ee-876c-ea29-36b8-5f7e41b03fc6', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_attach', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:5a051e6e-4e23-beff-e3c7-7f7c926575fc', 'vdi_uuid': '0850e980-6cb8-49bf-95d0-d777b1bf438f'}
Aug 11 21:04:04 pns-xen07 SM: [18140] lock: opening lock file /var/lock/sm/0850e980-6cb8-49bf-95d0-d777b1bf438f/vdi
Aug 11 21:04:04 pns-xen07 SM: [18140] result: {'o_direct_reason': 'LICENSE_RESTRICTION', 'params': '/dev/sm/backend/ff12160f-ff09-40bb-a874-1366ad907f44/0850e980-6cb8-49bf-95d0-d777b1bf438f', 'o_direct': True, 'xenstore_data': {'scsi/0x12/0x80': 'AIAAEjA4NTBlOTgwLTZjYjgtNDkgIA==', 'scsi/0x12/0x83': 'AIMAMQIBAC1YRU5TUkMgIDA4NTBlOTgwLTZjYjgtNDliZi05NWQwLWQ3NzdiMWJmNDM4ZiA=', 'vdi-uuid': '0850e980-6cb8-49bf-95d0-d777b1bf438f', 'mem-pool': 'ff12160f-ff09-40bb-a874-1366ad907f44'}}
Aug 11 21:04:04 pns-xen07 SM: [18140] lock: closed /var/lock/sm/0850e980-6cb8-49bf-95d0-d777b1bf438f/vdi
Aug 11 21:04:04 pns-xen07 SM: [18192] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Aug 11 21:04:05 pns-xen07 SM: [18192] preit SUCCESS
Aug 11 21:04:05 pns-xen07 SM: [18192] vdi_activate {'sr_uuid': 'ff12160f-ff09-40bb-a874-1366ad907f44', 'subtask_of': 'DummyRef:|dd797ae5-6eb4-2bef-0e64-62524ed3c5e1|VDI.activate', 'vdi_ref': 'OpaqueRef:3e615ac2-6f17-d482-5792-8a688d6683de', 'vdi_on_boot': 'persist', 'args': ['false'], 'vdi_location': '0850e980-6cb8-49bf-95d0-d777b1bf438f', 'host_ref': 'OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df', 'session_ref': 'OpaqueRef:4251c699-a33a-edb6-8e6c-4fd017286939', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_activate', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:5a051e6e-4e23-beff-e3c7-7f7c926575fc', 'vdi_uuid': '0850e980-6cb8-49bf-95d0-d777b1bf438f'}
Aug 11 21:04:05 pns-xen07 SM: [18192] lock: opening lock file /var/lock/sm/0850e980-6cb8-49bf-95d0-d777b1bf438f/vdi
Aug 11 21:04:05 pns-xen07 SM: [18192] blktap2.activate
Aug 11 21:04:05 pns-xen07 SM: [18192] lock: acquired /var/lock/sm/0850e980-6cb8-49bf-95d0-d777b1bf438f/vdi
Aug 11 21:04:05 pns-xen07 SM: [18192] Adding tag to: 0850e980-6cb8-49bf-95d0-d777b1bf438f
Aug 11 21:04:05 pns-xen07 SM: [18192] Activate lock succeeded
Aug 11 21:04:05 pns-xen07 SM: [18192] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Aug 11 21:04:05 pns-xen07 SM: [18192] preit SUCCESS
Aug 11 21:04:05 pns-xen07 SM: [18192] RBDVDI.attach for 0850e980-6cb8-49bf-95d0-d777b1bf438f
Aug 11 21:04:05 pns-xen07 SM: [18192] Calling _map_VHD
Aug 11 21:04:05 pns-xen07 SM: [18192] Calling ceph_plugin
Aug 11 21:04:05 pns-xen07 SM: [18192] Calling rbd/nbd map on host OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df
Aug 11 21:04:05 pns-xen07 SM: [18299] ['rbd-nbd', '--nbds_max', '64', 'map', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e@SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f', '--name', 'client.admin']
Aug 11 21:04:06 pns-xen07 SM: [18299] preit SUCCESS
Aug 11 21:04:06 pns-xen07 SM: [18299] ['ln', '-s', '/dev/nbd3', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e@SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f']
Aug 11 21:04:06 pns-xen07 SM: [18299] preit SUCCESS
Aug 11 21:04:06 pns-xen07 SM: [18192] PhyLink(/dev/sm/phy/ff12160f-ff09-40bb-a874-1366ad907f44/0850e980-6cb8-49bf-95d0-d777b1bf438f) -> /dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e@SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f
Aug 11 21:04:06 pns-xen07 SM: [18192] ['/usr/sbin/tap-ctl', 'allocate']
Aug 11 21:04:06 pns-xen07 SM: [18192] = 0
Aug 11 21:04:06 pns-xen07 SM: [18192] ['/usr/sbin/tap-ctl', 'spawn']
Aug 11 21:04:06 pns-xen07 SM: [18192] = 0
Aug 11 21:04:06 pns-xen07 SM: [18192] ['/usr/sbin/tap-ctl', 'attach', '-p', '18354', '-m', '4']
Aug 11 21:04:06 pns-xen07 SM: [18192] = 0
Aug 11 21:04:06 pns-xen07 SM: [18192] ['/usr/sbin/tap-ctl', 'open', '-p', '18354', '-m', '4', '-a', 'aio:/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e@SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f', '-R']
Aug 11 21:04:06 pns-xen07 SM: [18192] = 0
Aug 11 21:04:06 pns-xen07 SM: [18192] tap.activate: Launched Tapdisk(aio:/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e@SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f, pid=18354, minor=4, state=R)
Aug 11 21:04:06 pns-xen07 SM: [18192] Attempt to register tapdisk with RRDD as a plugin.
Aug 11 21:04:06 pns-xen07 SM: [18192] ERROR: Failed to register tapdisk with RRDD due to UnixStreamHTTP instance has no attribute 'get response'
Aug 11 21:04:06 pns-xen07 SM: [18192] DeviceNode(/dev/sm/backend/ff12160f-ff09-40bb-a874-1366ad907f44/0850e980-6cb8-49bf-95d0-d777b1bf438f) -> /dev/xen/blktap-2/tapdev4
Aug 11 21:04:06 pns-xen07 SM: [18192] lock: released /var/lock/sm/0850e980-6cb8-49bf-95d0-d777b1bf438f/vdi
Aug 11 21:04:06 pns-xen07 SM: [18192] lock: closed /var/lock/sm/0850e980-6cb8-49bf-95d0-d777b1bf438f/vdi
Aug 11 21:04:06 pns-xen07 SM: [18394] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Aug 11 21:04:06 pns-xen07 SM: [18394] preit SUCCESS
Aug 11 21:04:06 pns-xen07 SM: [18394] vdi_deactivate {'sr_uuid': 'ff12160f-ff09-40bb-a874-1366ad907f44', 'subtask_of': 'DummyRef:|f77d95b3-b1ff-148f-9ac5-19842d18777e|VDI.deactivate', 'vdi_ref': 'OpaqueRef:3e615ac2-6f17-d482-5792-8a688d6683de', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': '0850e980-6cb8-49bf-95d0-d777b1bf438f', 'host_ref': 'OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df', 'session_ref': 'OpaqueRef:40a50b63-2865-c3d3-913c-68a6202056f2', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_deactivate', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:5a051e6e-4e23-beff-e3c7-7f7c926575fc', 'vdi_uuid': '0850e980-6cb8-49bf-95d0-d777b1bf438f'}
Aug 11 21:04:06 pns-xen07 SM: [18394] lock: opening lock file /var/lock/sm/0850e980-6cb8-49bf-95d0-d777b1bf438f/vdi
Aug 11 21:04:06 pns-xen07 SM: [18394] blktap2.deactivate
Aug 11 21:04:06 pns-xen07 SM: [18394] lock: acquired /var/lock/sm/0850e980-6cb8-49bf-95d0-d777b1bf438f/vdi
Aug 11 21:04:06 pns-xen07 SM: [18394] ['/usr/sbin/tap-ctl', 'close', '-p', '18354', '-m', '4']
Aug 11 21:04:06 pns-xen07 SM: [18394] = 0
Aug 11 21:04:06 pns-xen07 SM: [18394] Attempt to deregister tapdisk with RRDD.
Aug 11 21:04:06 pns-xen07 SM: [18394] ERROR: Failed to deregister tapdisk with RRDD due to UnixStreamHTTP instance has no attribute 'get response'
Aug 11 21:04:06 pns-xen07 SM: [18394] ['/usr/sbin/tap-ctl', 'detach', '-p', '18354', '-m', '4']
Aug 11 21:04:07 pns-xen07 SM: [18394] = 0
Aug 11 21:04:07 pns-xen07 SM: [18394] ['/usr/sbin/tap-ctl', 'free', '-m', '4']
Aug 11 21:04:07 pns-xen07 SM: [18394] = 0
Aug 11 21:04:07 pns-xen07 SM: [18394] tap.deactivate: Shut down Tapdisk(aio:/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e@SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f, pid=18354, minor=4, state=R)
Aug 11 21:04:07 pns-xen07 SM: [18394] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Aug 11 21:04:07 pns-xen07 SM: [18394] preit SUCCESS
Aug 11 21:04:07 pns-xen07 SM: [18394] Calling _unmap_VHD
Aug 11 21:04:07 pns-xen07 SM: [18394] Calling ceph_plugin
Aug 11 21:04:07 pns-xen07 SM: [18394] Calling rbd/nbd map on host OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df
Aug 11 21:04:07 pns-xen07 SM: [18491] ['realpath', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e@SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f']
Aug 11 21:04:07 pns-xen07 SM: [18491] preit SUCCESS
Aug 11 21:04:07 pns-xen07 SM: [18491] ['unlink', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e@SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f']
Aug 11 21:04:07 pns-xen07 SM: [18491] preit SUCCESS
Aug 11 21:04:07 pns-xen07 SM: [18491] ['rbd-nbd', 'unmap', '/dev/nbd3', '--name', 'client.admin']
Aug 11 21:04:07 pns-xen07 SM: [18491] preit SUCCESS
Aug 11 21:04:07 pns-xen07 SM: [18394] Removed host key host_OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df for 0850e980-6cb8-49bf-95d0-d777b1bf438f
Aug 11 21:04:07 pns-xen07 SM: [18394] lock: released /var/lock/sm/0850e980-6cb8-49bf-95d0-d777b1bf438f/vdi
Aug 11 21:04:07 pns-xen07 SM: [18394] lock: closed /var/lock/sm/0850e980-6cb8-49bf-95d0-d777b1bf438f/vdi
Aug 11 21:04:07 pns-xen07 SM: [18514] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Aug 11 21:04:08 pns-xen07 SM: [18514] preit SUCCESS
Aug 11 21:04:08 pns-xen07 SM: [18514] vdi_detach {'sr_uuid': 'ff12160f-ff09-40bb-a874-1366ad907f44', 'subtask_of': 'DummyRef:|04752e88-2ea6-e5f8-5efe-9cb745726834|VDI.detach', 'vdi_ref': 'OpaqueRef:3e615ac2-6f17-d482-5792-8a688d6683de', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': '0850e980-6cb8-49bf-95d0-d777b1bf438f', 'host_ref': 'OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df', 'session_ref': 'OpaqueRef:a08c365a-7170-8f91-0afc-7da4f305e87f', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_detach', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:5a051e6e-4e23-beff-e3c7-7f7c926575fc', 'vdi_uuid': '0850e980-6cb8-49bf-95d0-d777b1bf438f'}
Aug 11 21:04:08 pns-xen07 SM: [18514] lock: opening lock file /var/lock/sm/0850e980-6cb8-49bf-95d0-d777b1bf438f/vdi
Aug 11 21:04:08 pns-xen07 SM: [18514] lock: closed /var/lock/sm/0850e980-6cb8-49bf-95d0-d777b1bf438f/vdi
Aug 11 21:04:08 pns-xen07 SM: [18561] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Aug 11 21:04:09 pns-xen07 SM: [18561] preit SUCCESS
Aug 11 21:04:09 pns-xen07 SM: [18561] vdi_delete {'sr_uuid': 'ff12160f-ff09-40bb-a874-1366ad907f44', 'subtask_of': 'DummyRef:|6fbc88f9-e5c9-9925-30e9-a4cbf5f06fd9|VDI.destroy', 'vdi_ref': 'OpaqueRef:3e615ac2-6f17-d482-5792-8a688d6683de', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': '0850e980-6cb8-49bf-95d0-d777b1bf438f', 'host_ref': 'OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df', 'session_ref': 'OpaqueRef:f0596daa-3a49-07ba-1dd7-44937f38643b', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_delete', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:5a051e6e-4e23-beff-e3c7-7f7c926575fc', 'vdi_uuid': '0850e980-6cb8-49bf-95d0-d777b1bf438f'}
Aug 11 21:04:09 pns-xen07 SM: [18561] RBDVDI.delete for 0850e980-6cb8-49bf-95d0-d777b1bf438f
Aug 11 21:04:09 pns-xen07 SM: [18561] Pause request for 2851fb05-59fd-4159-ad0b-9a3b6219047e
Aug 11 21:04:09 pns-xen07 SM: [18561] Calling tap-pause on host OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df
Aug 11 21:04:09 pns-xen07 SM: [18619] lock: opening lock file /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:09 pns-xen07 SM: [18619] lock: acquired /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:09 pns-xen07 SM: [18619] Pause for 2851fb05-59fd-4159-ad0b-9a3b6219047e
Aug 11 21:04:09 pns-xen07 SM: [18619] Calling tap pause with minor 2
Aug 11 21:04:09 pns-xen07 SM: [18619] ['/usr/sbin/tap-ctl', 'pause', '-p', '7107', '-m', '2']
Aug 11 21:04:09 pns-xen07 SM: [18619] = 0
Aug 11 21:04:09 pns-xen07 SM: [18619] lock: released /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:09 pns-xen07 SM: [18619] lock: closed /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:09 pns-xen07 SM: [18561] Calling _unmap_VHD
Aug 11 21:04:09 pns-xen07 SM: [18561] Calling ceph_plugin
Aug 11 21:04:09 pns-xen07 SM: [18561] Calling rbd/nbd map on host OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df
Aug 11 21:04:09 pns-xen07 SM: [18627] ['realpath', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e']
Aug 11 21:04:09 pns-xen07 SM: [18627] preit SUCCESS
Aug 11 21:04:09 pns-xen07 SM: [18627] ['unlink', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e']
Aug 11 21:04:09 pns-xen07 SM: [18627] preit SUCCESS
Aug 11 21:04:09 pns-xen07 SM: [18627] ['rbd-nbd', 'unmap', '/dev/nbd2', '--name', 'client.admin']
Aug 11 21:04:09 pns-xen07 SM: [18627] preit SUCCESS
Aug 11 21:04:09 pns-xen07 SM: [18561] ['rbd', 'snap', 'unprotect', 'VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e@SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44', '--name', 'client.admin']
Aug 11 21:04:09 pns-xen07 SM: [18561] preit SUCCESS
Aug 11 21:04:09 pns-xen07 SM: [18561] ['rbd', 'snap', 'rm', 'VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e@SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44', '--name', 'client.admin']
Aug 11 21:04:10 pns-xen07 SM: [18561] preit SUCCESS
Aug 11 21:04:10 pns-xen07 SM: [18561] ['rbd', 'image-meta', 'remove', 'VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e', 'SNAP-0850e980-6cb8-49bf-95d0-d777b1bf438f', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44', '--name', 'client.admin']
Aug 11 21:04:11 pns-xen07 SM: [18561] preit SUCCESS
Aug 11 21:04:11 pns-xen07 SM: [18561] Calling _map_VHD
Aug 11 21:04:11 pns-xen07 SM: [18561] Calling ceph_plugin
Aug 11 21:04:11 pns-xen07 SM: [18561] Calling rbd/nbd map on host OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df
Aug 11 21:04:11 pns-xen07 SM: [18809] ['rbd-nbd', '--nbds_max', '64', 'map', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e', '--name', 'client.admin']
Aug 11 21:04:11 pns-xen07 SM: [18809] preit SUCCESS
Aug 11 21:04:11 pns-xen07 SM: [18809] ['ln', '-s', '/dev/nbd2', '/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e']
Aug 11 21:04:11 pns-xen07 SM: [18809] preit SUCCESS
Aug 11 21:04:11 pns-xen07 SM: [18561] Unpause request for 2851fb05-59fd-4159-ad0b-9a3b6219047e secondary=None
Aug 11 21:04:11 pns-xen07 SM: [18561] Calling tap-unpause on host OpaqueRef:0e9c18cb-c243-2d9e-b4db-7bb854e066df
Aug 11 21:04:11 pns-xen07 SM: [18851] lock: opening lock file /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:11 pns-xen07 SM: [18851] lock: acquired /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:11 pns-xen07 SM: [18851] Unpause for 2851fb05-59fd-4159-ad0b-9a3b6219047e
Aug 11 21:04:11 pns-xen07 SM: [18851] Realpath: /dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e
Aug 11 21:04:11 pns-xen07 SM: [18851] Calling tap unpause with minor 2
Aug 11 21:04:11 pns-xen07 SM: [18851] ['/usr/sbin/tap-ctl', 'unpause', '-p', '7107', '-m', '2', '-a', 'aio:/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-2851fb05-59fd-4159-ad0b-9a3b6219047e']
Aug 11 21:04:11 pns-xen07 SM: [18851] = 0
Aug 11 21:04:11 pns-xen07 SM: [18851] lock: released /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi
Aug 11 21:04:11 pns-xen07 SM: [18851] lock: closed /var/lock/sm/2851fb05-59fd-4159-ad0b-9a3b6219047e/vdi

Placing the VM on local storage makes it work. So it just happens with VDIs on RBDSR Storage.
As mentioned in #11 XenOrchestra's Backup works now. However in DeltaBackup-mode it makes full backup on first backup and incremental on further backups by leaving one snapshot intact. Furthermore DeltaBackup uses the HTTP XenAPI to export the VDI which is a lot faster than exporting via xe, which Backup utilizes. So using DeltaBackup has a lot of improvements over Backup and i would love to see it working with RBDSR volumes.

Hi ,

I Just want to verify if anyone is facing very low speeds when running VMs on RBD backend using this plugin or the other plugin available .

I have done a test using 2 servers :
1- proxmox 4.3 server
2- xenserver 7.1 with this plugin

I connected both to same RBD pool and managed to create VM on both servers on this RBD pool.

The storage speeds I am getting on the KVM based VM on proxmox is more the 20 times faster than the one running on xenserver .

I disabled caching on proxmox KVM before doing the tests .

Is this expected ? or somthing is wrong with my setup

I thought I may loose 20 to 30% in speed compared to KVM based VMs but the speeds I am getting are unusable

Note: I tried to do caching on xenserver to improve the speed but that made the server heavily modified to the level I wont use it for anything serious anymore
Note 2 : I am using Infiniband 40GB connection to connect the client with CEPH (had to install the inifinband drivers on xenserver)

Hi, I try vdi copy , but failed when tap-ctl unpause.

source code version : master branch -> 9b977dc

SMlog:

Dec 19 10:38:17 xenserver90 SM: [28113] RBDVDI.snapshot: sr_uuid=a04f4451-3761-415b-a6c2-2b12656cb13a, vdi_uuid=8499f57e-ae12-499d-837f-8dbc4157b91a
Dec 19 10:38:17 xenserver90 SM: [28113] RBDVDI._snapshot: sr_uuid=a04f4451-3761-415b-a6c2-2b12656cb13a, vdi_uuid=8499f57e-ae12-499d-837f-8dbc4157b91a
Dec 19 10:38:17 xenserver90 SM: [28113] ['uuidgen', '-r']
Dec 19 10:38:17 xenserver90 SM: [28113]   pread SUCCESS
Dec 19 10:38:17 xenserver90 SM: [28113] Calling cephutils.VDI._get_vdi_info: vdi_uuid=8499f57e-ae12-499d-837f-8dbc4157b91a
Dec 19 10:38:17 xenserver90 SM: [28113] ['rbd', 'image-meta', 'list', 'VHD-8499f57e-ae12-499d-837f-8dbc4157b91a', '--pool', 'RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a', '--format', 'json', '--name', 'client.admin']
Dec 19 10:38:17 xenserver90 SM: [28113]   pread SUCCESS
Dec 19 10:38:17 xenserver90 SM: [28113] RBDVDI.load: vdi_uuid=84678ede-bcb3-462a-b58a-89c9f2a2b3ed
Dec 19 10:38:17 xenserver90 SM: [28113] Calling cephutils.SR._get_path: vdi_uuid=84678ede-bcb3-462a-b58a-89c9f2a2b3ed
Dec 19 10:38:17 xenserver90 SM: [28113] Calling cephutils.VDI.load: vdi_uuid=84678ede-bcb3-462a-b58a-89c9f2a2b3ed
Dec 19 10:38:17 xenserver90 SM: [28113] Calling cephutils.VDI._do_snapshot: vdi_uuid=8499f57e-ae12-499d-837f-8dbc4157b91a, snap_uuid=84678ede-bcb3-462a-b58a-89c9f2a2b3ed
Dec 19 10:38:17 xenserver90 SM: [28113] Pause request for 8499f57e-ae12-499d-837f-8dbc4157b91a
Dec 19 10:38:17 xenserver90 SM: [28113] Calling tap-pause on host OpaqueRef:698b2548-bdbe-91ea-35e7-76c7a49c3b4f
Dec 19 10:38:18 xenserver90 SM: [28210] lock: opening lock file /var/lock/sm/8499f57e-ae12-499d-837f-8dbc4157b91a/vdi
Dec 19 10:38:18 xenserver90 SM: [28210] lock: acquired /var/lock/sm/8499f57e-ae12-499d-837f-8dbc4157b91a/vdi
Dec 19 10:38:18 xenserver90 SM: [28210] Pause for 8499f57e-ae12-499d-837f-8dbc4157b91a
Dec 19 10:38:18 xenserver90 SM: [28210] Calling tap pause with minor 6
Dec 19 10:38:18 xenserver90 SM: [28210] ['/usr/sbin/tap-ctl', 'pause', '-p', '12010', '-m', '6']
Dec 19 10:38:18 xenserver90 SM: [28210]  = 0
Dec 19 10:38:18 xenserver90 SM: [28210] lock: released /var/lock/sm/8499f57e-ae12-499d-837f-8dbc4157b91a/vdi
Dec 19 10:38:18 xenserver90 SM: [28210] lock: closed /var/lock/sm/8499f57e-ae12-499d-837f-8dbc4157b91a/vdi
Dec 19 10:38:18 xenserver90 SM: [28113] Calling cephutills.VDI._unmap_VHD: vdi_uuid=8499f57e-ae12-499d-837f-8dbc4157b91a, dm=none, sharable=false
Dec 19 10:38:18 xenserver90 SM: [28113] Calling cephutils.VDI._call_plugin: op=_unmap
Dec 19 10:38:18 xenserver90 SM: [28113] Calling ceph_plugin
Dec 19 10:38:18 xenserver90 SM: [28113] Calling rbd/nbd map/unmap on host OpaqueRef:698b2548-bdbe-91ea-35e7-76c7a49c3b4f
Dec 19 10:38:18 xenserver90 SM: [28232] ['realpath', '/dev/nbd/RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a/VHD-8499f57e-ae12-499d-837f-8dbc4157b91a']
Dec 19 10:38:18 xenserver90 SM: [28232]   pread SUCCESS
Dec 19 10:38:18 xenserver90 SM: [28232] ['rbd-nbd', 'unmap', '/dev/nbd5', '--name', 'client.admin']
Dec 19 10:38:18 xenserver90 SM: [28232]   pread SUCCESS
Dec 19 10:38:18 xenserver90 SM: [28113] ['rbd', 'snap', 'create', 'VHD-8499f57e-ae12-499d-837f-8dbc4157b91a@SNAP-84678ede-bcb3-462a-b58a-89c9f2a2b3ed', '--pool', 'RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a', '--name', 'client.admin']
Dec 19 10:38:18 xenserver90 SM: [28113]   pread SUCCESS
Dec 19 10:38:18 xenserver90 SM: [28113] ['rbd', 'snap', 'protect', 'VHD-8499f57e-ae12-499d-837f-8dbc4157b91a@SNAP-84678ede-bcb3-462a-b58a-89c9f2a2b3ed', '--pool', 'RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a', '--name', 'client.admin']
Dec 19 10:38:19 xenserver90 SM: [28113]   pread SUCCESS
Dec 19 10:38:19 xenserver90 SM: [28113] Calling cephutills.VDI._map_VHD: vdi_uuid=8499f57e-ae12-499d-837f-8dbc4157b91a, dm=none, sharable=false
Dec 19 10:38:19 xenserver90 SM: [28113] Calling cephutils.VDI._call_plugin: op=_map
Dec 19 10:38:19 xenserver90 SM: [28113] Calling ceph_plugin
Dec 19 10:38:19 xenserver90 SM: [28113] Calling rbd/nbd map/unmap on host OpaqueRef:698b2548-bdbe-91ea-35e7-76c7a49c3b4f
Dec 19 10:38:19 xenserver90 SM: [28301] ['rbd-nbd', '--nbds_max', '64', 'map', 'RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a/VHD-8499f57e-ae12-499d-837f-8dbc4157b91a', '--name', 'client.admin']
Dec 19 10:38:19 xenserver90 SM: [28301]   pread SUCCESS
Dec 19 10:38:19 xenserver90 SM: [28113] Unpause request for 8499f57e-ae12-499d-837f-8dbc4157b91a secondary=None
Dec 19 10:38:19 xenserver90 SM: [28113] Calling tap-unpause on host OpaqueRef:698b2548-bdbe-91ea-35e7-76c7a49c3b4f
Dec 19 10:38:19 xenserver90 SM: [28333] lock: opening lock file /var/lock/sm/8499f57e-ae12-499d-837f-8dbc4157b91a/vdi
Dec 19 10:38:19 xenserver90 SM: [28333] lock: acquired /var/lock/sm/8499f57e-ae12-499d-837f-8dbc4157b91a/vdi
Dec 19 10:38:19 xenserver90 SM: [28333] Unpause for 8499f57e-ae12-499d-837f-8dbc4157b91a
Dec 19 10:38:19 xenserver90 SM: [28333] Realpath: /run/sr-mount/a04f4451-3761-415b-a6c2-2b12656cb13a/8499f57e-ae12-499d-837f-8dbc4157b91a
Dec 19 10:38:19 xenserver90 SM: [28333] Calling tap unpause with minor 6
Dec 19 10:38:19 xenserver90 SM: [28333] ['/usr/sbin/tap-ctl', 'unpause', '-p', '12010', '-m', '6', '-a', 'vhd:/run/sr-mount/a04f4451-3761-415b-a6c2-2b12656cb13a/8499f57e-ae12-499d-837f-8dbc4157b91a']
Dec 19 10:38:29 xenserver90 SM: [28333]  = 22
Dec 19 10:38:29 xenserver90 SM: [28333] ***** TAP-PAUSE:<function Unpause at 0x1794938>: EXCEPTION <class 'blktap2.CommandFailure'>, ['/usr/sbin/tap-ctl', 'unpause', '-p', '12010', '-m', '6', '-a', 'vhd:/run/sr-mount/a04f4451-3761-415b-a6c2-2b12656cb13a/8499f57e-ae12-499d-837f-8dbc4157b91a'] failed: status=22, pid=28345, errmsg=Invalid argument
Dec 19 10:38:29 xenserver90 SM: [28333]   File "/etc/xapi.d/plugins/tapdisk-pause", line 46, in wrapper
Dec 19 10:38:29 xenserver90 SM: [28333]     ret = op(self, *args)
Dec 19 10:38:29 xenserver90 SM: [28333]   File "/etc/xapi.d/plugins/tapdisk-pause", line 195, in Unpause
Dec 19 10:38:29 xenserver90 SM: [28333]     tapdisk.unpause(self.vdi_type, self.realpath, self.secondary)
Dec 19 10:38:29 xenserver90 SM: [28333]   File "/opt/xensource/sm/blktap2.py", line 872, in unpause
Dec 19 10:38:29 xenserver90 SM: [28333]     TapCtl.unpause(self.pid, self.minor, _type, path, mirror=mirror)
Dec 19 10:38:29 xenserver90 SM: [28333]   File "/opt/xensource/sm/blktap2.py", line 428, in unpause
Dec 19 10:38:29 xenserver90 SM: [28333]     cls._pread(args)
Dec 19 10:38:29 xenserver90 SM: [28333]   File "/opt/xensource/sm/blktap2.py", line 292, in _pread
Dec 19 10:38:29 xenserver90 SM: [28333]     tapctl._wait(quiet)
Dec 19 10:38:29 xenserver90 SM: [28333]   File "/opt/xensource/sm/blktap2.py", line 281, in _wait
Dec 19 10:38:29 xenserver90 SM: [28333]     raise self.CommandFailure(self.cmd, **info)
Dec 19 10:38:29 xenserver90 SM: [28333]
Dec 19 10:38:29 xenserver90 SM: [28333] lock: released /var/lock/sm/8499f57e-ae12-499d-837f-8dbc4157b91a/vdi
Dec 19 10:38:29 xenserver90 SM: [28333] lock: closed /var/lock/sm/8499f57e-ae12-499d-837f-8dbc4157b91a/vdi
Dec 19 10:38:29 xenserver90 SM: [28113] ***** BLKTAP2:call_pluginhandler ['XENAPI_PLUGIN_FAILURE', 'unpause', 'CommandFailure', "['/usr/sbin/tap-ctl', 'unpause', '-p', '12010', '-m', '6', '-a', 'vhd:/run/sr-mount/a04f4451-3761-415b-a6c2-2b12656cb13a/8499f57e-ae12-499d-837f-8dbc4157b91a'] failed: status=22, pid=28345, errmsg=Invalid argument"]: EXCEPTION <class 'XenAPI.Failure'>, ['XENAPI_PLUGIN_FAILURE', 'unpause', 'CommandFailure', "['/usr/sbin/tap-ctl', 'unpause', '-p', '12010', '-m', '6', '-a', 'vhd:/run/sr-mount/a04f4451-3761-415b-a6c2-2b12656cb13a/8499f57e-ae12-499d-837f-8dbc4157b91a'] failed: status=22, pid=28345, errmsg=Invalid argument"]
Dec 19 10:38:29 xenserver90 SM: [28113]   File "/opt/xensource/sm/blktap2.py", line 1406, in call_pluginhandler
Dec 19 10:38:29 xenserver90 SM: [28113]     args)
Dec 19 10:38:29 xenserver90 SM: [28113]   File "/usr/lib/python2.7/site-packages/XenAPI.py", line 248, in __call__
Dec 19 10:38:29 xenserver90 SM: [28113]     return self.__send(self.__name, args)
Dec 19 10:38:29 xenserver90 SM: [28113]   File "/usr/lib/python2.7/site-packages/XenAPI.py", line 150, in xenapi_request
Dec 19 10:38:29 xenserver90 SM: [28113]     result = _parse_result(getattr(self, methodname)(*full_params))
Dec 19 10:38:29 xenserver90 SM: [28113]   File "/usr/lib/python2.7/site-packages/XenAPI.py", line 222, in _parse_result
Dec 19 10:38:29 xenserver90 SM: [28113]     raise Failure(result['ErrorDescription'])
Dec 19 10:38:29 xenserver90 SM: [28113]
Dec 19 10:38:29 xenserver90 SM: [28113] Calling cephutils.SR._get_path: vdi_uuid=84678ede-bcb3-462a-b58a-89c9f2a2b3ed
Dec 19 10:38:29 xenserver90 SM: [28113] RBDSR._updateStats: sr_uuid=a04f4451-3761-415b-a6c2-2b12656cb13a, virtAllocDelta=1073741824
Dec 19 10:38:29 xenserver90 SM: [28453] RBDSR.load: sr_uuid=a04f4451-3761-415b-a6c2-2b12656cb13a
Dec 19 10:38:29 xenserver90 SM: [28453] Calling cephutils.SR.load: sr_uuid=a04f4451-3761-415b-a6c2-2b12656cb13a, ceph_user=admin
Dec 19 10:38:29 xenserver90 SM: [28453] Calling cephutils.SR._get_srlist
Dec 19 10:38:29 xenserver90 SM: [28453] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Dec 19 10:38:30 xenserver90 SM: [28453]   pread SUCCESS
Dec 19 10:38:30 xenserver90 SM: [28453] Calling cephutils.SR._get_sr_uuid_by_name: pool=RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a
Dec 19 10:38:30 xenserver90 SM: [28453] Calling cephutils.SR._get_sr_uuid_by_name: pool=RBD_XenStorage-36a078c3-f5e1-4eab-b095-9dea93261baa
Dec 19 10:38:30 xenserver90 SM: [28453] Calling cephutils.SR._get_sr_uuid_by_name: pool=RBD_XenStorage-8c016c8c-cd0d-4a56-95ca-71f6d6bcf3f6
Dec 19 10:38:30 xenserver90 SM: [28453] RBDVDI.load: vdi_uuid=84678ede-bcb3-462a-b58a-89c9f2a2b3ed
Dec 19 10:38:30 xenserver90 SM: [28453] Calling cephutils.SR._get_path: vdi_uuid=84678ede-bcb3-462a-b58a-89c9f2a2b3ed
Dec 19 10:38:30 xenserver90 SM: [28453] Calling cephutils.VDI.load: vdi_uuid=84678ede-bcb3-462a-b58a-89c9f2a2b3ed
Dec 19 10:38:30 xenserver90 SM: [28453] vdi_update {'sr_uuid': 'a04f4451-3761-415b-a6c2-2b12656cb13a', 'subtask_of': 'DummyRef:|4d3a80e5-130b-86a3-0990-3585957cdddc|VDI.update', 'vdi_ref': 'OpaqueRef:7a56c6aa-a51f-fdea-4275-baa0df0e9713', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': '84678ede-bcb3-462a-b58a-89c9f2a2b3ed', 'host_ref': 'OpaqueRef:698b2548-bdbe-91ea-35e7-76c7a49c3b4f', 'session_ref': 'OpaqueRef:19420815-70e3-1850-7a41-0e106ec52109', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_update', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:c2bc7247-9c5d-b110-7704-625513d0d50a', 'vdi_uuid': '84678ede-bcb3-462a-b58a-89c9f2a2b3ed'}
Dec 19 10:38:30 xenserver90 SM: [28453] RBDVDI.update: sr_uuid=a04f4451-3761-415b-a6c2-2b12656cb13a, vdi_uuid=84678ede-bcb3-462a-b58a-89c9f2a2b3ed
Dec 19 10:38:30 xenserver90 SM: [28453] Calling cephutils.VDI.update: sr_uuid=a04f4451-3761-415b-a6c2-2b12656cb13a, vdi_uuid=8499f57e-ae12-499d-837f-8dbc4157b91a
Dec 19 10:38:30 xenserver90 SM: [28453] ['rbd', 'image-meta', 'set', 'VHD-8499f57e-ae12-499d-837f-8dbc4157b91a', 'VDI_LABEL', 'i-2-2650-VM-DATA', '--pool', 'RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a', '--name', 'client.admin']
Dec 19 10:38:30 xenserver90 SM: [28453]   pread SUCCESS
Dec 19 10:38:30 xenserver90 SM: [28453] ['rbd', 'image-meta', 'set', 'VHD-8499f57e-ae12-499d-837f-8dbc4157b91a', 'SNAP-84678ede-bcb3-462a-b58a-89c9f2a2b3ed', '20161219T02:38:17Z', '--pool', 'RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a', '--name', 'client.admin']
Dec 19 10:38:30 xenserver90 SM: [28453]   pread SUCCESS
Dec 19 10:38:50 xenserver90 SM: [28943] ['uuidgen', '-r']
Dec 19 10:38:50 xenserver90 SM: [28943]   pread SUCCESS
Dec 19 10:38:50 xenserver90 SM: [28943] RBDSR.load: sr_uuid=a04f4451-3761-415b-a6c2-2b12656cb13a
Dec 19 10:38:50 xenserver90 SM: [28943] Calling cephutils.SR.load: sr_uuid=a04f4451-3761-415b-a6c2-2b12656cb13a, ceph_user=admin
Dec 19 10:38:50 xenserver90 SM: [28943] Calling cephutils.SR._get_srlist
Dec 19 10:38:50 xenserver90 SM: [28943] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Dec 19 10:38:51 xenserver90 SM: [28943]   pread SUCCESS

I'm not aware about the diff between these 2 devices.
Then why nbd default and not kernel?

Is it a choice based on performance?

ceph version: jewel
xenserver version: xenserver 7
operation: migrate vdi from rbd storage to local storage
SMlog:

Dec 29 22:57:09 localhost SM: [24983] lock: opening lock file /var/lock/sm/d32bf3ca-5d8a-4c83-918e-32251301e766/vdi
Dec 29 22:57:09 localhost SM: [24983] blktap2.activate
Dec 29 22:57:09 localhost SM: [24983] lock: acquired /var/lock/sm/d32bf3ca-5d8a-4c83-918e-32251301e766/vdi
Dec 29 22:57:09 localhost SM: [24983] Adding tag to: d32bf3ca-5d8a-4c83-918e-32251301e766
Dec 29 22:57:09 localhost SM: [24983] Activate lock succeeded
Dec 29 22:57:09 localhost SM: [24983] lock: opening lock file /var/lock/sm/ab443e69-d87c-800c-ecb1-41f58a9858b5/sr
Dec 29 22:57:09 localhost SM: [24983] ['/usr/sbin/td-util', 'query', 'vhd', '-vpfb', '/var/run/sr-mount/ab443e69-d87c-800c-ecb1-41f58a9858b5/d32bf3ca-5d8a-4c83-918e-32251301e766.vhd']
Dec 29 22:57:09 localhost SM: [24983] pread SUCCESS
Dec 29 22:57:09 localhost SM: [24983] PhyLink(/dev/sm/phy/ab443e69-d87c-800c-ecb1-41f58a9858b5/d32bf3ca-5d8a-4c83-918e-32251301e766) -> /var/run/sr-mount/ab443e69-d87c-800c-ecb1-41f58a9858b5/d32bf3ca-5d8a-4c83-918e-32251301e766.vhd
Dec 29 22:57:09 localhost SM: [24983] ['/usr/sbin/tap-ctl', 'allocate']
Dec 29 22:57:09 localhost SM: [24983] = 0
Dec 29 22:57:09 localhost SM: [24983] ['/usr/sbin/tap-ctl', 'spawn']
Dec 29 22:57:09 localhost SM: [24983] = 0
Dec 29 22:57:09 localhost SM: [24983] ['/usr/sbin/tap-ctl', 'attach', '-p', '25023', '-m', '0']
Dec 29 22:57:09 localhost SM: [24983] = 0
Dec 29 22:57:09 localhost SM: [24983] ['/usr/sbin/tap-ctl', 'open', '-p', '25023', '-m', '0', '-a', 'vhd:/var/run/sr-mount/ab443e69-d87c-800c-ecb1-41f58a9858b5/d32bf3ca-5d8a-4c83-918e-32251301e766.vhd']
Dec 29 22:57:09 localhost SM: [24983] = 0
Dec 29 22:57:09 localhost SM: [24983] tap.activate: Launched Tapdisk(vhd:/var/run/sr-mount/ab443e69-d87c-800c-ecb1-41f58a9858b5/d32bf3ca-5d8a-4c83-918e-32251301e766.vhd, pid=25023, minor=0, state=R)
Dec 29 22:57:09 localhost SM: [24983] Attempt to register tapdisk with RRDD as a plugin.
Dec 29 22:57:09 localhost SM: [24983] ERROR: Failed to register tapdisk with RRDD due to UnixStreamHTTP instance has no attribute 'getresponse'
Dec 29 22:57:09 localhost SM: [24983] DeviceNode(/dev/sm/backend/ab443e69-d87c-800c-ecb1-41f58a9858b5/d32bf3ca-5d8a-4c83-918e-32251301e766) -> /dev/xen/blktap-2/tapdev0
Dec 29 22:57:09 localhost SM: [24983] lock: released /var/lock/sm/d32bf3ca-5d8a-4c83-918e-32251301e766/vdi

there was no error that migrate vm from local storage to rbd storage.

We have evaluated RBDSR in combination with a ceph jewel cluster (ubuntu 14.04) and XenServer 7.
From our testing, it seems that every mode of RBDSR has it's pros/cons.
Our results:
kernel mode
+really fast
-forces ceph cluster into compatibility mode
+most features like VDI creation, snapshot, etc work

fuse mode
-quite slow (kernel seems like 5 times faster)
+full jewel compatibility
+most features like VDI creation, snapshot, etc work

nbd mode
+almost (?) as fast as kernel mode
+full jewel compatibility
-snapshot of a running VM hangs VM and XenServer :-(

Thats why for us the most interesting mode is nbd-Mode.
Other ideas welcome :-)

However the crash of the VM you run a snapshot on and the corresponding XenServer Host is a real show stopper.
Any idea about that?

The SMLog doesn't seem to reveal any errors:

Aug 1 16:52:10 pns-xen06 SM: [16457] ['rbd', 'ls', '-l', '--format', 'json', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44']
Aug 1 16:52:10 pns-xen06 SM: [16457] preit SUCCESS
Aug 1 16:52:10 pns-xen06 SM: [16457] ['ceph', 'df', '-f', 'json']
Aug 1 16:52:11 pns-xen06 SM: [16457] preit SUCCESS
Aug 1 16:52:11 pns-xen06 SM: [16457] vdi_snapshot {'sr_uuid': 'ff12160f-ff09-40bb-a874-1366ad907f44', 'subtask_of': 'DummyRef:|67c03c61-f2e5-f725-2758-a646f10845b3|VDI.snapshot', 'vdi_ref': 'OpaqueRef:f25db949-ec0e-e414-8f87-7fa393c228fe', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': 'bb086701-2e94-4dad-91b0-3e9e0bd56a5d', 'host_ref': 'OpaqueRef:4eac2447-bf4e-c909-560b-ff67a467dd29', 'session_ref': 'OpaqueRef:613194dd-7d4a-b036-2f9e-09fa8a86652f', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_snapshot', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:6d76056b-1874-c808-a9b9-ee9abaa31513', 'driver_params': {'epochhint': 'c187be94-3e5c-c945-db14-2234971c71ee'}, 'vdi_uuid': 'bb086701-2e94-4dad-91b0-3e9e0bd56a5d'}
Aug 1 16:52:11 pns-xen06 SM: [16457] RBDVDI.snapshot for bb086701-2e94-4dad-91b0-3e9e0bd56a5d
Aug 1 16:52:11 pns-xen06 SM: [16457] Pause request for bb086701-2e94-4dad-91b0-3e9e0bd56a5d
Aug 1 16:52:11 pns-xen06 SM: [16457] Calling tap-pause on host OpaqueRef:4eac2447-bf4e-c909-560b-ff67a467dd29
Aug 1 16:52:11 pns-xen06 SM: [16525] lock: opening lock file /var/lock/sm/bb086701-2e94-4dad-91b0-3e9e0bd56a5d/vdi
Aug 1 16:52:11 pns-xen06 SM: [16525] lock: acquired /var/lock/sm/bb086701-2e94-4dad-91b0-3e9e0bd56a5d/vdi
Aug 1 16:52:11 pns-xen06 SM: [16525] Pause for bb086701-2e94-4dad-91b0-3e9e0bd56a5d
Aug 1 16:52:11 pns-xen06 SM: [16525] Calling tap pause with minor 0
Aug 1 16:52:11 pns-xen06 SM: [16525] ['/usr/sbin/tap-ctl', 'pause', '-p', '15665', '-m', '0']
Aug 1 16:52:11 pns-xen06 SM: [16525] = 0
Aug 1 16:52:11 pns-xen06 SM: [16525] lock: released /var/lock/sm/bb086701-2e94-4dad-91b0-3e9e0bd56a5d/vdi
Aug 1 16:52:11 pns-xen06 SM: [16525] lock: closed /var/lock/sm/bb086701-2e94-4dad-91b0-3e9e0bd56a5d/vdi
Aug 1 16:52:11 pns-xen06 SM: [16457] ['uuidgen', '-r']
Aug 1 16:52:11 pns-xen06 SM: [16457] preit SUCCESS
Aug 1 16:52:11 pns-xen06 SM: [16457] ['rbd', 'image-meta', 'list', 'VHD-bb086701-2e94-4dad-91b0-3e9e0bd56a5d', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44', '--format', 'son']
Aug 1 16:52:11 pns-xen06 SM: [16457] preit SUCCESS
Aug 1 16:52:11 pns-xen06 SM: [16457] ['rbd', 'snap', 'create', 'VHD-bb086701-2e94-4dad-91b0-3e9e0bd56a5d@SNAP-b2bb2d93-9201-43b2-844b-9e029461b853', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44']
Aug 1 16:52:17 pns-xen06 SM: [16457] preit SUCCESS
Aug 1 16:52:17 pns-xen06 SM: [16457] ['rbd', 'snap', 'protect', 'VHD-bb086701-2e94-4dad-91b0-3e9e0bd56a5d@SNAP-b2bb2d93-9201-43b2-844b-9e029461b853', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44']
Aug 1 16:52:22 pns-xen06 SM: [16457] preit SUCCESS
Aug 1 16:52:22 pns-xen06 SM: [16457] Unpause request for bb086701-2e94-4dad-91b0-3e9e0bd56a5d secondary=None
Aug 1 16:52:22 pns-xen06 SM: [16457] Calling tap-unpause on host OpaqueRef:4eac2447-bf4e-c909-560b-ff67a467dd29
Aug 1 16:52:22 pns-xen06 SM: [16657] lock: opening lock file /var/lock/sm/bb086701-2e94-4dad-91b0-3e9e0bd56a5d/vdi
Aug 1 16:52:22 pns-xen06 SM: [16657] lock: acquired /var/lock/sm/bb086701-2e94-4dad-91b0-3e9e0bd56a5d/vdi
Aug 1 16:52:22 pns-xen06 SM: [16657] Unpause for bb086701-2e94-4dad-91b0-3e9e0bd56a5d
Aug 1 16:52:22 pns-xen06 SM: [16657] Realpath: /dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-bb086701-2e94-4dad-91b0-3e9e0bd56a5d
Aug 1 16:52:22 pns-xen06 SM: [16657] Calling tap unpause with minor 0
Aug 1 16:52:22 pns-xen06 SM: [16657] ['/usr/sbin/tap-ctl', 'unpause', '-p', '15665', '-m', '0', '-a', 'aio:/dev/nbd/RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44/VHD-bb086701-2e94-4dad-91b0-3e9e0bd56a5d']
Aug 1 16:52:22 pns-xen06 SM: [16657] = 0
Aug 1 16:52:22 pns-xen06 SM: [16657] lock: released /var/lock/sm/bb086701-2e94-4dad-91b0-3e9e0bd56a5d/vdi
Aug 1 16:52:22 pns-xen06 SM: [16657] lock: closed /var/lock/sm/bb086701-2e94-4dad-91b0-3e9e0bd56a5d/vdi
Aug 1 16:52:22 pns-xen06 SM: [16675] ['rbd', 'ls', '-l', '--format', 'json', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44']
Aug 1 16:52:22 pns-xen06 SM: [16675] preit SUCCESS
Aug 1 16:52:22 pns-xen06 SM: [16675] ['ceph', 'df', '-f', 'json']
Aug 1 16:52:23 pns-xen06 SM: [16675] preit SUCCESS
Aug 1 16:52:23 pns-xen06 SM: [16675] vdi_update {'sr_uuid': 'ff12160f-ff09-40bb-a874-1366ad907f44', 'subtask_of': 'DummyRef:|e25e4db4-b375-e312-35ce-85071213de7b|VDI.update', 'vdi_ref': 'OpaqueRef:b31bce15-406e-560d-a13a-6a153b7958bd', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': 'b2bb2d93-9201-43b2-844b-9e029461b853', 'host_ref': 'OpaqueRef:4eac2447-bf4e-c909-560b-ff67a467dd29', 'session_ref': 'OpaqueRef:f7f95e8b-a6cb-e051-7fff-0a07fe962cd0', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_update', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:6d76056b-1874-c808-a9b9-ee9abaa31513', 'vdi_uuid': 'b2bb2d93-9201-43b2-844b-9e029461b853'}
Aug 1 16:52:23 pns-xen06 SM: [16675] RBDSR.update for b2bb2d93-9201-43b2-844b-9e029461b853
Aug 1 16:52:23 pns-xen06 SM: [16675] ['rbd', 'image-meta', 'set', 'VHD-bb086701-2e94-4dad-91b0-3e9e0bd56a5d', 'VDI_LABEL', 'Ubi16 0', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44']
Aug 1 16:52:23 pns-xen06 SM: [16675] preit SUCCESS
Aug 1 16:52:23 pns-xen06 SM: [16675] ['rbd', 'image-meta', 'set', 'VHD-bb086701-2e94-4dad-91b0-3e9e0bd56a5d', 'VDI_DESCRIPTION', 'Created by template provisioner', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44']
Aug 1 16:52:23 pns-xen06 SM: [16675] preit SUCCESS
Aug 1 16:52:23 pns-xen06 SM: [16675] ['rbd', 'image-meta', 'set', 'VHD-bb086701-2e94-4dad-91b0-3e9e0bd56a5d', 'SNAP-b2bb2d93-9201-43b2-844b-9e029461b853', '20160801T14:52:10Z', '--pool', 'RBD_XenStorage-ff12160f-ff09-40bb-a874-1366ad907f44']
Aug 1 16:52:23 pns-xen06 SM: [16675] preit SUCCESS

It seems that the VM cannot access its disk anymore - running OS of VM complains that disk does not response.
However VM cannot be shut down and even Host Server (XenServer7) refuses to force stop VM. Hard reboot via console is necessary.

Just gave latest commit (29) a try but fails with the following error:

Aug 4 17:56:20 pns-xen06 SM: [29056] ***** RBD: EXCEPTION <type 'exceptions.UnboundLocalError'>, local variable 'ceph_user' referenced before assignment
Aug 4 17:56:20 pns-xen06 SM: [29056] File "/opt/xensource/sm/SRCommand.py", line 350, in run
Aug 4 17:56:20 pns-xen06 SM: [29056] sr = driver(cmd, cmd.sr_uuid)
Aug 4 17:56:20 pns-xen06 SM: [29056] File "/opt/xensource/sm/SR.py", line 147, in init
Aug 4 17:56:20 pns-xen06 SM: [29056] self.load(sr_uuid)
Aug 4 17:56:20 pns-xen06 SM: [29056] File "/opt/xensource/sm/RBDSR", line 177, in load
Aug 4 17:56:20 pns-xen06 SM: [29056] cephutils.SR.load(self,sr_uuid, ceph_user)
Aug 4 17:56:20 pns-xen06 SM: [29056]

Went back to commit 20 for now. Anything i should have configured first or is it a bug?

XenServer <=7 kernel is too old, so only image-format 1 can be used.
As a consequence snap protection fails: it needs layering feature.

A weird network issue caused a disconnect between the Ceph SR and Xenserver pool. Cloudstack shut-down a number of VMs that wouldn't come back up once connectivity was re-established. It was a weird, difficult problem to debug, and may have exposed a bug:

When attempting to attach a VDI to a VM the following occured in /var/log/SMlog

Jun 1 22:53:27 cloud102-6 SM: [22135] ['rbd-nbd', '--nbds_max', '64', 'map', 'RBD_XenStorage-2dd455e9-0de4-4ed8-af62-64e1a4ace678/VHD-54c1f244-d62c-47ac-90d2-f40be0f6fe5a', '--name', 'client.admin']
Jun 1 22:53:27 cloud102-6 SM: [22135] pread SUCCESS
Jun 1 22:53:27 cloud102-6 SM: [22135] ['ln', '-s', '/dev/nbd4', '/dev/nbd/RBD_XenStorage-2dd455e9-0de4-4ed8-af62-64e1a4ace678/VHD-54c1f244-d62c-47ac-90d2-f40be0f6fe5a']
Jun 1 22:53:28 cloud102-6 SM: [22135] pread SUCCESS
Jun 1 22:53:28 cloud102-6 SM: [22135] ['ln', '-s', '/dev/nbd4', '/run/sr-mount/2dd455e9-0de4-4ed8-af62-64e1a4ace678/54c1f244-d62c-47ac-90d2-f40be0f6fe5a']
Jun 1 22:53:28 cloud102-6 SM: [22135] FAILED in util.pread: (rc 1) stdout: '', stderr: 'ln: failed to create symbolic link '/run/sr-mount/2dd455e9-0de4-4ed8-af62-64e1a4ace678/54c1f244-d62c-47ac-90d2-f40be0f6fe5a': File exists
Jun 1 22:53:28 cloud102-6 SM: [22135] '
Jun 1 22:53:28 cloud102-6 SM: [21718] Exception in activate/attach
Jun 1 22:53:28 cloud102-6 SM: [21718] Removed host key host_OpaqueRef:24b3b5c5-996a-6b74-90c8-0c930c1ba751 for 54c1f244-d62c-47ac-90d2-f40be0f6fe5a
Jun 1 22:53:28 cloud102-6 SM: [21718] ***** BLKTAP2:<function _activate_locked at 0x13fa6e0>: EXCEPTION <class 'XenAPI.Failure'>, ['XENAPI_PLUGIN_FAILURE', 'map', 'CommandException', 'Operation not permitted']
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/blktap2.py", line 87, in wrapper
Jun 1 22:53:28 cloud102-6 SM: [21718] ret = op(self, *args)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/blktap2.py", line 1574, in _activate_locked
Jun 1 22:53:28 cloud102-6 SM: [21718] self._attach(sr_uuid, vdi_uuid)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/blktap2.py", line 1639, in _attach
Jun 1 22:53:28 cloud102-6 SM: [21718] attach_info = xmlrpclib.loads(self.target.attach(sr_uuid, vdi_uuid))[0][0]
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/blktap2.py", line 1112, in attach
Jun 1 22:53:28 cloud102-6 SM: [21718] return self.vdi.attach(sr_uuid, vdi_uuid)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/RBDSR", line 418, in attach
Jun 1 22:53:28 cloud102-6 SM: [21718] self._map_VHD(vdi_uuid, self.size, "none")
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/cephutils.py", line 530, in _map_VHD
Jun 1 22:53:28 cloud102-6 SM: [21718] self._call_plugin('map',args)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/cephutils.py", line 435, in _call_plugin
Jun 1 22:53:28 cloud102-6 SM: [21718] if not self.session.xenapi.host.call_plugin(host_ref, "ceph_plugin", op, args):
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/usr/lib/python2.7/site-packages/XenAPI.py", line 254, in call
Jun 1 22:53:28 cloud102-6 SM: [21718] return self.__send(self.__name, args)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/usr/lib/python2.7/site-packages/XenAPI.py", line 150, in xenapi_request
Jun 1 22:53:28 cloud102-6 SM: [21718] result = _parse_result(getattr(self, methodname)(*full_params))
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/usr/lib/python2.7/site-packages/XenAPI.py", line 228, in _parse_result
Jun 1 22:53:28 cloud102-6 SM: [21718] raise Failure(result['ErrorDescription'])
Jun 1 22:53:28 cloud102-6 SM: [21718]
Jun 1 22:53:28 cloud102-6 SM: [21718] Raising exception [46, The VDI is not available [opterr=['XENAPI_PLUGIN_FAILURE', 'map', 'CommandException', 'Operation not permitted']]]
Jun 1 22:53:28 cloud102-6 SM: [21718] lock: released /var/lock/sm/54c1f244-d62c-47ac-90d2-f40be0f6fe5a/vdi
Jun 1 22:53:28 cloud102-6 SM: [21718] ***** generic exception: vdi_activate: EXCEPTION <class 'SR.SROSError'>, The VDI is not available [opterr=['XENAPI_PLUGIN_FAILURE', 'map', 'CommandException', 'Operation not permitted']]
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/SRCommand.py", line 110, in run
Jun 1 22:53:28 cloud102-6 SM: [21718] return self._run_locked(sr)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/SRCommand.py", line 159, in _run_locked
Jun 1 22:53:28 cloud102-6 SM: [21718] rv = self._run(sr, target)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/SRCommand.py", line 264, in _run
Jun 1 22:53:28 cloud102-6 SM: [21718] writable, caching_params)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/blktap2.py", line 1541, in activate
Jun 1 22:53:28 cloud102-6 SM: [21718] if self._activate_locked(sr_uuid, vdi_uuid, options):
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/blktap2.py", line 95, in wrapper
Jun 1 22:53:28 cloud102-6 SM: [21718] raise xs_errors.XenError(excType, opterr=msg)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/xs_errors.py", line 52, in init
Jun 1 22:53:28 cloud102-6 SM: [21718] raise SR.SROSError(errorcode, errormessage)
Jun 1 22:53:28 cloud102-6 SM: [21718]
Jun 1 22:53:28 cloud102-6 SM: [21718] ***** RBD: EXCEPTION <class 'SR.SROSError'>, The VDI is not available [opterr=['XENAPI_PLUGIN_FAILURE', 'map', 'CommandException', 'Operation not permitted']]
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/SRCommand.py", line 353, in run
Jun 1 22:53:28 cloud102-6 SM: [21718] ret = cmd.run(sr)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/SRCommand.py", line 110, in run
Jun 1 22:53:28 cloud102-6 SM: [21718] return self._run_locked(sr)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/SRCommand.py", line 159, in _run_locked
Jun 1 22:53:28 cloud102-6 SM: [21718] rv = self._run(sr, target)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/SRCommand.py", line 264, in _run
Jun 1 22:53:28 cloud102-6 SM: [21718] writable, caching_params)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/blktap2.py", line 1541, in activate
Jun 1 22:53:28 cloud102-6 SM: [21718] if self._activate_locked(sr_uuid, vdi_uuid, options):
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/blktap2.py", line 95, in wrapper
Jun 1 22:53:28 cloud102-6 SM: [21718] raise xs_errors.XenError(excType, opterr=msg)
Jun 1 22:53:28 cloud102-6 SM: [21718] File "/opt/xensource/sm/xs_errors.py", line 52, in init
Jun 1 22:53:28 cloud102-6 SM: [21718] raise SR.SROSError(errorcode, errormessage)
Jun 1 22:53:28 cloud102-6 SM: [21718]
Jun 1 22:53:28 cloud102-6 SM: [21718] lock: closed /var/lock/sm/54c1f244-d62c-47ac-90d2-f40be0f6fe5a/vdi

Seems existing symlinks were present, causing a crash.

This was ultimately resolved by removing ALL symlinks on every pool server:

cd /run/sr-mount/
rm -f *
cd /dev/nbd/RBD_XenStorage-
rm -f *

I also did a mass vdi-forget and sr-scan, but I don't think those actually helped with the fix at all.

Could a future version remove existing symlinks before trying to create them? Also removing any existing locks in ceph may help too (rbd lock remove ...)

Hi.. I got this error when running the install script. and the the process crash
cp: invalid option -- n

Install the release.asc key
error: https://download.ceph.com/keys/release.asc: import read failed(-1).
Install new Repos
cp: invalid option -- n
Try `cp --help' for more information.

The plugin see the repository as a thick storage:

PROVISIONING_TYPES = ["thin", "thick"]
PROVISIONING_DEFAULT = "thick"

Is this right?
Does this lock the button: "reclaim free space" in xencenter?
Should this be modify in order to maximize the thin provisioning on the xen pools?

Or not?

hi
I try to copy vdi , but failed.

command line:

xe vdi-copy sr-uuid=a04f4451-3761-415b-a6c2-2b12656cb13a uuid=6a571d0a-99da-405e-8bfe-76bb1c79c608
The VDI copy action has failed
<extra>: End_of_file

xensource.log say a exception VDI_COPY_FAILED, [End_of_file].
but, SMlog no error.

xensource.log:

Dec 16 16:49:02 xenserver90 xapi: [debug|xenserver90|7401 UNIX /var/lib/xcp/xapi|VDI.db_forget R:badd76e6ee92|xapi] db_forget uuid=159c5306-fb1a-48ed-980b-e517762a5247
Dec 16 16:49:02 xenserver90 xapi: [ info|xenserver90|7366 |sm_exec D:9e52034d6d8d|xapi] Session.destroy trackid=f8b10c5d21747bb7ba9fd1a22b01d90f
Dec 16 16:49:02 xenserver90 xapi: [debug|xenserver90|202 INET :::80|VDI.destroy R:e27331f4fa33|xapi] Unmarking SR after VDI.destroy (task=OpaqueRef:e27331f4-fa33-537e-09b5-4e5d514ee96e)
Dec 16 16:49:02 xenserver90 xapi: [debug|xenserver90|7314 UNIX /var/lib/xcp/xapi|VDI.copy R:dcad2835578f|xmlrpc_client] stunnel pid: 25601 (cached = true) returned stunnel to cache
Dec 16 16:49:02 xenserver90 xapi: [ info|xenserver90|7314 UNIX /var/lib/xcp/xapi|VDI.copy R:dcad2835578f|xapi] Session.destroy trackid=7de92aa3fe91acadf24925dd5dda7b20
Dec 16 16:49:02 xenserver90 xapi: [debug|xenserver90|7314 UNIX /var/lib/xcp/xapi|VDI.copy R:dcad2835578f|taskhelper] the status of R:dcad2835578f is failure; cannot set it to `failure
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi|dispatch:VDI.copy D:043f2fef673f|backtrace] VDI.copy R:dcad2835578f failed with exception Server_error(VDI_COPY_FAILED, [ End_of_file ])
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi|dispatch:VDI.copy D:043f2fef673f|backtrace] Raised Server_error(VDI_COPY_FAILED, [ End_of_file ])
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi|dispatch:VDI.copy D:043f2fef673f|backtrace] 1/14 xapi @ xenserver90 Raised at file client.ml, line 6
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi|dispatch:VDI.copy D:043f2fef673f|backtrace] 2/14 xapi @ xenserver90 Called from file client.ml, line 18
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi|dispatch:VDI.copy D:043f2fef673f|backtrace] 3/14 xapi @ xenserver90 Called from file client.ml, line 10623
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi|dispatch:VDI.copy D:043f2fef673f|backtrace] 4/14 xapi @ xenserver90 Called from file lib/pervasiveext.ml, line 22
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi|dispatch:VDI.copy D:043f2fef673f|backtrace] 5/14 xapi @ xenserver90 Called from file lib/pervasiveext.ml, line 26
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi|dispatch:VDI.copy D:043f2fef673f|backtrace] 6/14 xapi @ xenserver90 Called from file message_forwarding.ml, line 106
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi|dispatch:VDI.copy D:043f2fef673f|backtrace] 7/14 xapi @ xenserver90 Called from file message_forwarding.ml, line 3386
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi|dispatch:VDI.copy D:043f2fef673f|backtrace] 8/14 xapi @ xenserver90 Called from file lib/pervasiveext.ml, line 22
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi|dispatch:VDI.copy D:043f2fef673f|backtrace] 9/14 xapi @ xenserver90 Called from file rbac.ml, line 236
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi|dispatch:VDI.copy D:043f2fef673f|backtrace] 10/14 xapi @ xenserver90 Called from file server_helpers.ml, line 75
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi||cli] Converting exception VDI_COPY_FAILED: [ End_of_file ] into a CLI response
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi||backtrace] Raised Server_error(VDI_COPY_FAILED, [ End_of_file ])
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi||backtrace] 1/1 xapi @ xenserver90 Raised at file (Thread 7314 has no backtrace table. Was with_backtraces called?, line 0
Dec 16 16:49:02 xenserver90 xapi: [error|xenserver90|7314 UNIX /var/lib/xcp/xapi||backtrace]
Dec 16 16:49:03 xenserver90 xapi: [debug|xenserver90|7402 UNIX /var/lib/xcp/xapi||cli] xe sr-list type=rbd username=root password=(omitted)
Dec 16 16:49:03 xenserver90 xapi: [ info|xenserver90|7402 UNIX /var/lib/xcp/xapi|session.login_with_password D:523a350c00e1|xapi] Session.create trackid=f1d2261cb14aa0761c3a7ecd58bf38d4 pool=false uname=root originator=cli is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Dec 16 16:49:03 xenserver90 xapi: [debug|xenserver90|7402 UNIX /var/lib/xcp/xapi|session.login_with_password D:523a350c00e1|mscgen] xapi=>xapi [label="pool.get_all"];
Dec 16 16:49:03 xenserver90 xapi: [debug|xenserver90|7403 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:0116e34d9bd1 created by task D:523a350c00e1
Dec 16 16:49:03 xenserver90 xapi: [ info|xenserver90|7402 UNIX /var/lib/xcp/xapi|session.logout D:bcf38b811408|xapi] Session.destroy trackid=f1d2261cb14aa0761c3a7ecd58bf38d4
Dec 16 16:49:03 xenserver90 xapi: [debug|xenserver90|7404 UNIX /var/lib/xcp/xapi||cli] xe sr-list type=rbd username=root password=(omitted)
Dec 16 16:49:03 xenserver90 xapi: [ info|xenserver90|7404 UNIX /var/lib/xcp/xapi|session.login_with_password D:ff099a47ec19|xapi] Session.create trackid=8623a14e5e9b25d8b48107fda658b14c pool=false uname=root originator=cli is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
Dec 16 16:49:03 xenserver90 xapi: [debug|xenserver90|7404 UNIX /var/lib/xcp/xapi|session.login_with_password D:ff099a47ec19|mscgen] xapi=>xapi [label="pool.get_all"];
Dec 16 16:49:03 xenserver90 xapi: [debug|xenserver90|7405 UNIX /var/lib/xcp/xapi||dummytaskhelper] task dispatch:pool.get_all D:554175289bbd created by task D:ff099a47ec19
Dec 16 16:49:03 xenserver90 xapi: [ info|xenserver90|7404 UNIX /var/lib/xcp/xapi|session.logout D:440ec21eefb7|xapi] Session.destroy trackid=8623a14e5e9b25d8b48107fda658b14c

SMlog(no error) :

Dec 16 16:56:45 xenserver90 SM: [28821] ['uuidgen', '-r']
Dec 16 16:56:45 xenserver90 SM: [28821]   pread SUCCESS
Dec 16 16:56:45 xenserver90 SM: [28821] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Dec 16 16:56:46 xenserver90 SM: [28821]   pread SUCCESS
Dec 16 16:56:46 xenserver90 SM: [28821] ['rbd', 'ls', '-l', '--format', 'json', '--pool', 'RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a', '--name', 'client.admin']
Dec 16 16:56:46 xenserver90 SM: [28821]   pread SUCCESS
Dec 16 16:56:46 xenserver90 SM: [28821] vdi_create {'sr_uuid': 'a04f4451-3761-415b-a6c2-2b12656cb13a', 'subtask_of': 'DummyRef:|b841ac12-2b43-1709-1c08-35475065a4d0|VDI.create', 'vdi_type': 'user', 'args': ['1075838976', 'xen_server_vol_1', '', '', 'false', '19700101T00:00:00Z$, '', 'false'], 'host_ref': 'OpaqueRef:698b2548-bdbe-91ea-35e7-76c7a49c3b4f', 'session_ref': 'OpaqueRef:9be6f546-ea71-a566-f8a7-02bf29df7e79', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_create', 'sr_ref': 'OpaqueRef:c2bc7247-9c5d-b110-7704-625513d0d50a', 'vdi_sm_co$fig': {}}
Dec 16 16:56:46 xenserver90 SM: [28821] RBDVDI.create for 84168a75-0829-4612-b0cc-a04ceff4b184
Dec 16 16:56:46 xenserver90 SM: [28821] ['rbd', 'create', 'VHD-84168a75-0829-4612-b0cc-a04ceff4b184', '--size', '1028', '--object-size', '2097152', '--image-format', '2', '--pool', 'RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a', '--name', 'client.admin']
Dec 16 16:56:46 xenserver90 SM: [28821]   pread SUCCESS
Dec 16 16:56:46 xenserver90 SM: [28821] ['rbd', 'image-meta', 'set', 'VHD-84168a75-0829-4612-b0cc-a04ceff4b184', 'VDI_LABEL', 'xen_server_vol_1', '--pool', 'RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a', '--name', 'client.admin']
Dec 16 16:56:46 xenserver90 SM: [28821]   pread SUCCESS
Dec 16 16:56:55 xenserver90 SM: [29065] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Dec 16 16:56:56 xenserver90 SM: [29065]   pread SUCCESS
Dec 16 16:56:56 xenserver90 SM: [29065] ['rbd', 'ls', '-l', '--format', 'json', '--pool', 'RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a', '--name', 'client.admin']
Dec 16 16:56:56 xenserver90 SM: [29065]   pread SUCCESS
Dec 16 16:56:56 xenserver90 SM: [29065] vdi_delete {'sr_uuid': 'a04f4451-3761-415b-a6c2-2b12656cb13a', 'subtask_of': 'DummyRef:|d71324d1-77d2-078c-2823-99011b7a19b8|VDI.destroy', 'vdi_ref': 'OpaqueRef:3b5c7454-d6d3-f07f-8506-6990d40caf8f', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': '84168a75-0829-4612-b0cc-a04ceff4b184', 'host_ref': 'OpaqueRef:698b2548-bdbe-91ea-35e7-76c7a49c3b4f', 'session_ref': 'OpaqueRef:57bb1d9e-32a5-7ad0-1ec4-65fd3f2b9cef', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_delete', 'vdi_allow_caching': 'false', $sr_ref': 'OpaqueRef:c2bc7247-9c5d-b110-7704-625513d0d50a', 'vdi_uuid': '84168a75-0829-4612-b0cc-a04ceff4b184'}
Dec 16 16:56:56 xenserver90 SM: [29065] RBDVDI.delete for 84168a75-0829-4612-b0cc-a04ceff4b184
Dec 16 16:56:56 xenserver90 SM: [29065] RBDVDI.delete vdi_uuid : 84168a75-0829-4612-b0cc-a04ceff4b184
Dec 16 16:56:56 xenserver90 SM: [29065] ['rbd', 'rm', 'VHD-84168a75-0829-4612-b0cc-a04ceff4b184', '--pool', 'RBD_XenStorage-a04f4451-3761-415b-a6c2-2b12656cb13a', '--name', 'client.admin']
Dec 16 16:56:56 xenserver90 SM: [29065]   pread SUCCESS
Dec 16 16:57:04 xenserver90 SM: [29254] lock: opening lock file /var/lock/sm/d5905479-8c07-1d71-3150-61be2d340e91/sr
Dec 16 16:57:04 xenserver90 SM: [29254] lock: acquired /var/lock/sm/d5905479-8c07-1d71-3150-61be2d340e91/sr
Dec 16 16:57:04 xenserver90 SM: [29254] sr_scan {'sr_uuid': 'd5905479-8c07-1d71-3150-61be2d340e91', 'subtask_of': 'DummyRef:|dbf19442-fef9-7c2c-3024-09ae503fc91d|SR.scan', 'args': [], 'host_ref': 'OpaqueRef:698b2548-bdbe-91ea-35e7-76c7a49c3b4f', 'session_ref': 'OpaqueRef:cea38$e4-4c9c-93bb-d799-788950cdf108', 'device_config': {'SRmaster': 'true', 'serverpath': '/export/psXen7', 'server': '192.168.1.14'}, 'command': 'sr_scan', 'sr_ref': 'OpaqueRef:557aaf76-9b3d-9eb2-7252-fc2b47b53f6b'}
Dec 16 16:57:04 xenserver90 SM: [29254] ['/usr/bin/vhd-util', 'scan', '-f', '-c', '-m', '/var/run/sr-mount/d5905479-8c07-1d71-3150-61be2d340e91/*.vhd']
Dec 16 16:57:04 xenserver90 SM: [29254]   pread SUCCESS
Dec 16 16:57:04 xenserver90 SM: [29254] FileVDI.load vdi_uuid : b79785de-d311-4273-8186-304b4699f1d7
Dec 16 16:57:04 xenserver90 SM: [29254] FileVDI.load vdi_uuid : 7ce5d03d-925d-49f5-bea0-323041cc6bfb
Dec 16 16:57:04 xenserver90 SM: [29254] FileVDI.load vdi_uuid : 8dd11cfd-2681-423c-934e-bcb2ba103a3c
Dec 16 16:57:04 xenserver90 SM: [29254] FileVDI.load vdi_uuid : eb3e08e5-563c-469d-997d-09ff15551e2b
Dec 16 16:57:04 xenserver90 SM: [29254] FileVDI.load vdi_uuid : 41fa87b2-9175-4bb3-b052-38b0fe971d02
Dec 16 16:57:04 xenserver90 SM: [29254] FileVDI.load vdi_uuid : 1730ecd0-5f12-453d-8d96-e7121e148419
Dec 16 16:57:04 xenserver90 SM: [29254] FileVDI.load vdi_uuid : dbf23b5f-13c8-4c37-812d-941ee28782ec
Dec 16 16:57:04 xenserver90 SM: [29254] FileVDI.load vdi_uuid : e38c121c-9bd0-4392-b464-6a499fa5f798
Dec 16 16:57:04 xenserver90 SM: [29254] FileVDI.load vdi_uuid : f44a2e66-9b28-4831-a56f-7ff9b2bd66f9
Dec 16 16:57:04 xenserver90 SM: [29254] FileVDI.load vdi_uuid : c29f5c5a-5c80-4bc1-923e-750bb2f24a92
Dec 16 16:57:04 xenserver90 SM: [29254] FileVDI.load vdi_uuid : 4bdef00e-d50e-49e9-8ab4-8659ce35c3c9

There is a small spelling error in cephutils.py where self is miss spelt as 'slef' this error looks to only trigger during a SXM migration.

453c453
<         util.pread2(["dmsetup", "create", slef.DM_MIRROR_NAME, "--table", "0 %s snapshot %s %s P 1" % (str(int(size) / 512), self.DM_ZERO_DEV, self.RBD_SXM_MIRROR_DEV)])

---
>         util.pread2(["dmsetup", "create", self.DM_MIRROR_NAME, "--table", "0 %s snapshot %s %s P 1" % (str(int(size) / 512), self.DM_ZERO_DEV, self.RBD_SXM_MIRROR_DEV)])

cephutil.py
line 285:
vdi_ref = self.session.xenapi.VDI.get_by_uuid(vdi_uuid)
the right is:
vdi_ref = self.session.xenapi.VDI.get_by_uuid(clone_uuid)

Now, the features of RBDSR is almost complete. But the biggist trouble is vdi.migrate.
In migrate progress, the vdi delete may be conflict with snapshot delete. (the value of compose_vdi1 not same with snapshot-of in fact)。 And, unmap in ceph_plugin may be conflict with composing(dmsetup cannot remove dm-in-using)。
I think, after (parent)vdi.delete called, hide the rbd from SR instead of rename it。Is this method more effective?

Don't know why.

If someone has a clue (SR_PROBE missing in caps?) I could work on implementation.

Xenserver 7.1

"Copying the master image" went OK but after snapshot creation I get this error:

Error Id: XDDS:0DAA3833

Exception:
Citrix.Console.Models.Exceptions.ProvisioningTaskException An error occurred while preparing the image.
at Citrix.Console.PowerShellSdk.ProvisioningSchemeService.BackgroundTasks.ProvisioningSchemeTask.CheckForTerminatingError(SdkProvisioningSchemeAction sdkProvisioningSchemeAction)
at Citrix.Console.PowerShellSdk.ProvisioningSchemeService.BackgroundTasks.ProvisioningSchemeTask.WaitForProvisioningSchemeActionCompletion(Guid taskId, Action`1 actionResultsObtained)
at Citrix.Console.PowerShellSdk.ProvisioningSchemeService.BackgroundTasks.ProvisioningSchemeCreationTask.StartProvisioningAction()
at Citrix.Console.PowerShellSdk.ProvisioningSchemeService.BackgroundTasks.ProvisioningSchemeCreationTask.RunTask()
at Citrix.Console.PowerShellSdk.BackgroundTaskService.BackgroundTask.Task.Run()

DesktopStudio_ErrorId : ProvisioningTaskError
ErrorCategory : NotSpecified
ErrorID : FailedToCreateImagePreparationVm
TaskErrorInformation : Terminated
InternalErrorMessage : Unable to write data to the transport connection: An existing connection was forcibly closed by the remote host.

In xensource and SMlog this errors

[error|hs-0226|26142 INET :::80|Create disk prepare-identity R:2833924336c6|vhd_tool_wrapper] vhd-tool failed, returning VDI_IO_ERROR
[error|hs-0226|26142 INET :::80|Create disk prepare-identity R:2833924336c6|vhd_tool_wrapper] vhd-tool output:
[error|hs-0226|26142 INET :::80|Create disk prepare-identity R:2833924336c6|import] Caught exception: VDI_IO_ERROR: [ Device I/O errors ]
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] Create disk prepare-identity R:2833924336c6 failed with exception Server_error(VDI_IO_ERROR, [ Device I/O errors ])
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] Raised Server_error(VDI_IO_ERROR, [ Device I/O errors ])
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] 1/12 xapi @ hs-0226 Raised at file vhd_tool_wrapper.ml, line 61
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] 2/12 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 22
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] 3/12 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 26
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] 4/12 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 22
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] 5/12 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 26
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] 6/12 xapi @ hs-0226 Called from file import_raw_vdi.ml, line 72
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] 7/12 xapi @ hs-0226 Called from file import_raw_vdi.ml, line 93
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] 8/12 xapi @ hs-0226 Called from file server_helpers.ml, line 73
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] 9/12 xapi @ hs-0226 Called from file server_helpers.ml, line 91
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] 10/12 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 22
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] 11/12 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 26
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace] 12/12 xapi @ hs-0226 Called from file lib/backtrace.ml, line 176
[error|hs-0226|26142 INET :::80|VDI.import D:957db04a95bf|backtrace]
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] VDI.import D:957db04a95bf failed with exception Server_error(VDI_IO_ERROR, [ Device I/O errors ])
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] Raised Server_error(VDI_IO_ERROR, [ Device I/O errors ])
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 1/13 xapi @ hs-0226 Raised at file lib/debug.ml, line 185
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 2/13 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 22
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 3/13 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 26
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 4/13 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 22
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 5/13 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 26
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 6/13 xapi @ hs-0226 Called from file xapi_http.ml, line 199
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 7/13 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 22
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 8/13 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 26
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 9/13 xapi @ hs-0226 Called from file server_helpers.ml, line 73
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 10/13 xapi @ hs-0226 Called from file server_helpers.ml, line 91
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 11/13 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 22
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 12/13 xapi @ hs-0226 Called from file lib/pervasiveext.ml, line 26
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace] 13/13 xapi @ hs-0226 Called from file lib/backtrace.ml, line 176
[error|hs-0226|26142 INET :::80|VDI.import D:f0e41008bffe|backtrace]
[error|hs-0226|26142 INET :::80||backtrace] VDI.import D:f0e41008bffe failed with exception Server_error(VDI_IO_ERROR, [ Device I/O errors ])
[error|hs-0226|26142 INET :::80||backtrace] Raised Server_error(VDI_IO_ERROR, [ Device I/O errors ])
[error|hs-0226|26142 INET :::80||backtrace] 1/1 xapi @ hs-0226 Raised at file (Thread 26142 has no backtrace table. Was with_backtraces called?, line 0
[error|hs-0226|26142 INET :::80||backtrace]
[error|hs-0226|26142 INET :::80||xapi] Unhandled Api_errors.Server_error(VDI_IO_ERROR, [ Device I/O errors ])

hs-0226 SM: [6949] tap.activate: Launched Tapdisk(vhd:/run/sr-mount/976e0ed5-2901-47b0-8962-ad6e76d6b55a/0866041a-2509-4caf-8acc-31f1183e601b, pid=7116, minor=0, state=R)
hs-0226 SM: [6949] Attempt to register tapdisk with RRDD as a plugin.
hs-0226 SM: [6949] ERROR: Failed to register tapdisk with RRDD due to UnixStreamHTTP instance has no attribute 'getresponse'
hs-0226 SM: [6949] DeviceNode(/dev/sm/backend/976e0ed5-2901-47b0-8962-ad6e76d6b55a/0866041a-2509-4caf-8acc-31f1183e601b) -> /dev/xen/blktap-2/tapdev0
hs-0226 SM: [6949] lock: released /var/lock/sm/0866041a-2509-4caf-8acc-31f1183e601b/vdi
hs-0226 SM: [6949] lock: closed /var/lock/sm/0866041a-2509-4caf-8acc-31f1183e601b/vdi
hs-0226 SM: [7200] RBDSR.load: sr_uuid=976e0ed5-2901-47b0-8962-ad6e76d6b55a
hs-0226 SM: [7200] Calling cephutils.SR.load: sr_uuid=976e0ed5-2901-47b0-8962-ad6e76d6b55a, ceph_user=admin
hs-0226 SM: [7200] Calling cephutils.SR._get_srlist
hs-0226 SM: [7200] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
hs-0226 SM: [7200] pread SUCCESS
hs-0226 SM: [7200] Calling cephutils.SR._get_sr_uuid_by_name: pool=RBD_XenStorage-976e0ed5-2901-47b0-8962-ad6e76d6b55a
hs-0226 SM: [7200] RBDVDI.load: vdi_uuid=0866041a-2509-4caf-8acc-31f1183e601b
hs-0226 SM: [7200] Calling cephutils.SR._get_path: vdi_uuid=0866041a-2509-4caf-8acc-31f1183e601b
hs-0226 SM: [7200] Calling cephutils.VDI.load: vdi_uuid=0866041a-2509-4caf-8acc-31f1183e601b
hs-0226 SM: [7200] vdi_deactivate {'sr_uuid': '976e0ed5-2901-47b0-8962-ad6e76d6b55a', 'subtask_of': 'DummyRef:|9cee1fdb-dffc-e8e0-bc53-919380dc13de|VDI.deactivate', 'vdi_ref': 'OpaqueRef:f14b7de4-80f9-30fd-b0e8-dcbb301bf05e', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': '0866041a-2509-4caf-8acc-31f1183e601b', 'host_ref': 'OpaqueRef:928e5d5e-23a2-9bda-6155-8fc1f52ea64e', 'session_ref': 'OpaqueRef:23aed438-2313-c026-f6a1-7c2dc36564c2', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_deactivate', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:88cb8c50-c240-d970-05fa-86c11d40a376', 'local_cache_sr': 'c3a3e630-7c5c-ed64-e258-049ba83839f5', 'vdi_uuid': '0866041a-2509-4caf-8acc-31f1183e601b'}
hs-0226 SM: [7200] lock: opening lock file /var/lock/sm/0866041a-2509-4caf-8acc-31f1183e601b/vdi
hs-0226 SM: [7200] blktap2.deactivate
hs-0226 SM: [7200] lock: acquired /var/lock/sm/0866041a-2509-4caf-8acc-31f1183e601b/vdi
hs-0226 SM: [7200] ['/usr/sbin/tap-ctl', 'close', '-p', '7116', '-m', '0']
hs-0226 SM: [7200] = 0
hs-0226 SM: [7200] Attempt to deregister tapdisk with RRDD.
hs-0226 SM: [7200] ERROR: Failed to deregister tapdisk with RRDD due to UnixStreamHTTP instance has no attribute 'getresponse'
hs-0226 SM: [7200] ['/usr/sbin/tap-ctl', 'detach', '-p', '7116', '-m', '0']
hs-0226 SM: [7200] = 0
hs-0226 SM: [7200] ['/usr/sbin/tap-ctl', 'free', '-m', '0']
hs-0226 SM: [7200] = 0
hs-0226 SM: [7200] tap.deactivate: Shut down Tapdisk(vhd:/run/sr-mount/976e0ed5-2901-47b0-8962-ad6e76d6b55a/0866041a-2509-4caf-8acc-31f1183e601b, pid=7116, minor=0, state=R)

Try to delete a VM will retrieve the following error: "The attempt to mark the VDI as hidden failed"

Hi there,

XenServer 7.1, Ceph Kraken, and Cloudstack 4.9.2.0

Our pool master is getting stuck with task that's preventing other disk events from happening:

uuid ( RO) : 5f192420-7643-efe4-912b-a0c4edd34e48
name-label ( RO): VDI.set_name_description
name-description ( RO):
status ( RO): pending
progress ( RO): 0.000

It seems to be something that's firing this inside Cloudstack's management. After a period of activity I get a one of these for every VDI in the xensource log:

May 27 14:26:20 cloud102-1 xapi: [debug|cloud102-1|1783 UNIX /var/lib/xcp/xapi|VDI.set_name_description R:0c1eadc11704|audit] VDI.set_name_description: VDI = 'a33d38cc-8a17-4998-b49d-a5ce4f750a31' name-description = ''
May 27 14:26:21 cloud102-1 xapi: [debug|cloud102-1|1985 UNIX /var/lib/xcp/xapi|VDI.set_name_description R:ec836d040bc1|audit] VDI.set_name_description: VDI = '38d3849d-dd17-4b95-b0bf-f4cf9fffacbd' name-description = ''

(there's about 70 of these and they fire around 1 second apart)
...etc...

There's no indication of error, and the task doesn't go away even after 24 hours.

The problem is that VDI tasks like migration wait for this task to complete, so a backlog of activity eventually drives load up on the pool master.

I haven't found any specific VDI that's problematic.

Help would be appreciated. The issue started this week, we've been successfully running the RBD storage plugin for the week before.

I'm going to try recreating the issue by running manual vdi-param-set commands on each uuid, but that's a fairly time-intensive process.

Thanks!

Sorry for my poor English
I used Xenserver 7.1 and Ceph jewel (10.2.10)
It works with one VM with one VDI
When I attach another VDI to VM, it became unstable
sometimes it can reboot normally, sometimes it can't, and I will get "tapdisk experienced an error" or "VDI is not available"

Hi there, Thanks for putting this project together. The other RBDSR (using lvmoiscsi) was just broken by the latest XS Storage patch.... I'm trying to migrate my guests from both a gluster backed NFS SR and the lvmoiscsi SR. Both have failed so far. Here is the output from SMlog after attempting to migrate from the NFS SR:

May 19 12:01:34 xen5 SM: [28496] Calling cephutils.SR.load: sr_uuid=f60dd3ac-50e9-4a27-8465-51374131de5d, ceph_user=admin
May 19 12:01:34 xen5 SM: [28496] Calling cephutils.SR._get_srlist
May 19 12:01:34 xen5 SM: [28496] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
May 19 12:01:36 xen5 SM: [28496]   pread SUCCESS
May 19 12:01:36 xen5 SM: [28496] Calling cephutils.SR._get_sr_uuid_by_name: pool=RBD_XenStorage-f60dd3ac-50e9-4a27-8465-51374131de5d
May 19 12:01:36 xen5 SM: [28496] RBDVDI.load: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:36 xen5 SM: [28496] Calling cephutils.SR._get_path: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:36 xen5 SM: [28496] Calling cephutils.VDI.load: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:36 xen5 SM: [28496] vdi_attach {'sr_uuid': 'f60dd3ac-50e9-4a27-8465-51374131de5d', 'subtask_of': 'DummyRef:|42495455-1ad8-a55c-0a9c-ce0868677b25|VDI.attach', 'vdi_ref': 'OpaqueRef:e91caf96-d3aa-4b17-203b-207c9912fb94', 'vdi_on_boot': 'persist', 'args': ['true'
], 'vdi_location': 'c468488b-6072-43f6-a57e-59a739370948', 'host_ref': 'OpaqueRef:1d1e830b-2197-f11e-e450-49a9e3fdb9bf', 'session_ref': 'OpaqueRef:57be2022-0945-e2f4-9443-2aac7d4b079b', 'device_config': {'SRmaster': 'false'}, 'command': 'vdi_attach', 'vdi_allow_caching': '
false', 'sr_ref': 'OpaqueRef:44e02825-9f99-d6e4-735f-6c0295d53280', 'vdi_uuid': 'c468488b-6072-43f6-a57e-59a739370948'}
May 19 12:01:36 xen5 SM: [28496] lock: opening lock file /var/lock/sm/c468488b-6072-43f6-a57e-59a739370948/vdi
May 19 12:01:36 xen5 SM: [28496] result: {'o_direct_reason': 'LICENSE_RESTRICTION', 'params': '/dev/sm/backend/f60dd3ac-50e9-4a27-8465-51374131de5d/c468488b-6072-43f6-a57e-59a739370948', 'o_direct': True, 'xenstore_data': {'scsi/0x12/0x80': 'AIAAEmM0Njg0ODhiLTYwNzItNDMgIA=
=', 'scsi/0x12/0x83': 'AIMAMQIBAC1YRU5TUkMgIGM0Njg0ODhiLTYwNzItNDNmNi1hNTdlLTU5YTczOTM3MDk0OCA=', 'vdi-uuid': 'c468488b-6072-43f6-a57e-59a739370948', 'mem-pool': 'f60dd3ac-50e9-4a27-8465-51374131de5d'}}
May 19 12:01:36 xen5 SM: [28496] lock: closed /var/lock/sm/c468488b-6072-43f6-a57e-59a739370948/vdi
May 19 12:01:36 xen5 SM: [28584] RBDSR.load: sr_uuid=f60dd3ac-50e9-4a27-8465-51374131de5d
May 19 12:01:36 xen5 SM: [28584] Calling cephutils.SR.load: sr_uuid=f60dd3ac-50e9-4a27-8465-51374131de5d, ceph_user=admin
May 19 12:01:36 xen5 SM: [28584] Calling cephutils.SR._get_srlist
May 19 12:01:36 xen5 SM: [28584] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
May 19 12:01:36 xen5 SM: [28584]   pread SUCCESS
May 19 12:01:36 xen5 SM: [28584] Calling cephutils.SR._get_sr_uuid_by_name: pool=RBD_XenStorage-f60dd3ac-50e9-4a27-8465-51374131de5d
May 19 12:01:36 xen5 SM: [28584] RBDVDI.load: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:36 xen5 SM: [28584] Calling cephutils.SR._get_path: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:36 xen5 SM: [28584] Calling cephutils.VDI.load: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:36 xen5 SM: [28584] vdi_activate {'sr_uuid': 'f60dd3ac-50e9-4a27-8465-51374131de5d', 'subtask_of': 'DummyRef:|50d10f4d-a152-6a68-a1d6-a92f7d268c22|VDI.activate', 'vdi_ref': 'OpaqueRef:e91caf96-d3aa-4b17-203b-207c9912fb94', 'vdi_on_boot': 'persist', 'args': ['t
rue'], 'vdi_location': 'c468488b-6072-43f6-a57e-59a739370948', 'host_ref': 'OpaqueRef:1d1e830b-2197-f11e-e450-49a9e3fdb9bf', 'session_ref': 'OpaqueRef:e82ecd77-7982-2679-7dcf-78cd62658377', 'device_config': {'SRmaster': 'false'}, 'command': 'vdi_activate', 'vdi_allow_cachi
ng': 'false', 'sr_ref': 'OpaqueRef:44e02825-9f99-d6e4-735f-6c0295d53280', 'vdi_uuid': 'c468488b-6072-43f6-a57e-59a739370948'}
May 19 12:01:36 xen5 SM: [28584] lock: opening lock file /var/lock/sm/c468488b-6072-43f6-a57e-59a739370948/vdi
May 19 12:01:36 xen5 SM: [28584] blktap2.activate
May 19 12:01:36 xen5 SM: [28584] lock: acquired /var/lock/sm/c468488b-6072-43f6-a57e-59a739370948/vdi
May 19 12:01:36 xen5 SM: [28584] Adding tag to: c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:36 xen5 SM: [28584] Activate lock succeeded
May 19 12:01:37 xen5 SM: [28584] RBDSR.handles type rbd
May 19 12:01:37 xen5 SM: [28584] RBDSR.load: sr_uuid=f60dd3ac-50e9-4a27-8465-51374131de5d
May 19 12:01:37 xen5 SM: [28584] Calling cephutils.SR.load: sr_uuid=f60dd3ac-50e9-4a27-8465-51374131de5d, ceph_user=admin
May 19 12:01:37 xen5 SM: [28584] Calling cephutils.SR._get_srlist
May 19 12:01:37 xen5 SM: [28584] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
May 19 12:01:37 xen5 SM: [28584]   pread SUCCESS
May 19 12:01:37 xen5 SM: [28584] Calling cephutils.SR._get_sr_uuid_by_name: pool=RBD_XenStorage-f60dd3ac-50e9-4a27-8465-51374131de5d
May 19 12:01:37 xen5 SM: [28584] RBDVDI.load: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:37 xen5 SM: [28584] Calling cephutils.SR._get_path: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:37 xen5 SM: [28584] Calling cephutils.VDI.load: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:37 xen5 SM: [28584] RBDVDI.attach: sr_uuid=f60dd3ac-50e9-4a27-8465-51374131de5d, vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:37 xen5 SM: [28584] Calling cephutils.SR._get_path: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:37 xen5 SM: [28584] Calling cephutills.VDI._map_sxm_mirror: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948, size=8589934592, dm=mirror, sharable=false
May 19 12:01:37 xen5 SM: [28584] Calling cephutils.VDI._call_plugin: op=map
May 19 12:01:37 xen5 SM: [28584] Calling ceph_plugin
May 19 12:01:37 xen5 SM: [28584] Calling rbd/nbd map/unmap on host OpaqueRef:1d1e830b-2197-f11e-e450-49a9e3fdb9bf
May 19 12:01:37 xen5 SM: [28695] ['rbd-nbd', '--nbds_max', '64', 'map', 'RBD_XenStorage-f60dd3ac-50e9-4a27-8465-51374131de5d/VHD-c468488b-6072-43f6-a57e-59a739370948', '--name', 'client.admin']
May 19 12:01:37 xen5 SM: [28695] FAILED in util.pread: (rc 1) stdout: '', stderr: 'rbd-nbd: unknown args: --name
May 19 12:01:37 xen5 SM: [28695] '
May 19 12:01:37 xen5 SM: [28584] Exception in activate/attach
May 19 12:01:37 xen5 SM: [28584] Removed host key host_OpaqueRef:1d1e830b-2197-f11e-e450-49a9e3fdb9bf for c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:37 xen5 SM: [28584] ***** BLKTAP2:<function _activate_locked at 0x14ffd70>: EXCEPTION <class 'XenAPI.Failure'>, ['XENAPI_PLUGIN_FAILURE', 'map', 'CommandException', 'Operation not permitted']
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/blktap2.py", line 87, in wrapper
May 19 12:01:37 xen5 SM: [28584]     ret = op(self, *args)
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/blktap2.py", line 1596, in _activate_locked
May 19 12:01:37 xen5 SM: [28584]     self._attach(sr_uuid, vdi_uuid)
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/blktap2.py", line 1661, in _attach
May 19 12:01:37 xen5 SM: [28584]     attach_info = xmlrpclib.loads(self.target.attach(sr_uuid, vdi_uuid))[0][0]
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/blktap2.py", line 1116, in attach
May 19 12:01:37 xen5 SM: [28584]     return self.vdi.attach(sr_uuid, vdi_uuid)
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/RBDSR", line 400, in attach
May 19 12:01:37 xen5 SM: [28584]     self._map_sxm_mirror(vdi_uuid, self.size)
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/cephutils.py", line 638, in _map_sxm_mirror
May 19 12:01:37 xen5 SM: [28584]     self._call_plugin('map',args)
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/cephutils.py", line 413, in _call_plugin
May 19 12:01:37 xen5 SM: [28584]     if not self.session.xenapi.host.call_plugin(host_ref, "ceph_plugin", op, args):
May 19 12:01:37 xen5 SM: [28584]   File "/usr/lib/python2.7/site-packages/XenAPI.py", line 248, in __call__
May 19 12:01:37 xen5 SM: [28584]     return self.__send(self.__name, args)
May 19 12:01:37 xen5 SM: [28584]   File "/usr/lib/python2.7/site-packages/XenAPI.py", line 150, in xenapi_request
May 19 12:01:37 xen5 SM: [28584]     result = _parse_result(getattr(self, methodname)(*full_params))
May 19 12:01:37 xen5 SM: [28584]   File "/usr/lib/python2.7/site-packages/XenAPI.py", line 222, in _parse_result
May 19 12:01:37 xen5 SM: [28584]     raise Failure(result['ErrorDescription'])
May 19 12:01:37 xen5 SM: [28584]
May 19 12:01:37 xen5 SM: [28584] Raising exception [46, The VDI is not available [opterr=['XENAPI_PLUGIN_FAILURE', 'map', 'CommandException', 'Operation not permitted']]]
May 19 12:01:37 xen5 SM: [28584] lock: released /var/lock/sm/c468488b-6072-43f6-a57e-59a739370948/vdi
May 19 12:01:37 xen5 SM: [28584] ***** generic exception: vdi_activate: EXCEPTION <class 'SR.SROSError'>, The VDI is not available [opterr=['XENAPI_PLUGIN_FAILURE', 'map', 'CommandException', 'Operation not permitted']]
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/SRCommand.py", line 110, in run
May 19 12:01:37 xen5 SM: [28584]     return self._run_locked(sr)
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/SRCommand.py", line 159, in _run_locked
May 19 12:01:37 xen5 SM: [28584]     rv = self._run(sr, target)
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/SRCommand.py", line 264, in _run
May 19 12:01:37 xen5 SM: [28584]     writable, caching_params)
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/blktap2.py", line 1563, in activate
May 19 12:01:37 xen5 SM: [28584]     if self._activate_locked(sr_uuid, vdi_uuid, options):
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/blktap2.py", line 95, in wrapper
May 19 12:01:37 xen5 SM: [28584]     raise xs_errors.XenError(excType, opterr=msg)
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/xs_errors.py", line 52, in __init__
May 19 12:01:37 xen5 SM: [28584]     raise SR.SROSError(errorcode, errormessage)
May 19 12:01:37 xen5 SM: [28584]
May 19 12:01:37 xen5 SM: [28584] ***** RBD: EXCEPTION <class 'SR.SROSError'>, The VDI is not available [opterr=['XENAPI_PLUGIN_FAILURE', 'map', 'CommandException', 'Operation not permitted']]
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/SRCommand.py", line 352, in run
May 19 12:01:37 xen5 SM: [28584]     ret = cmd.run(sr)
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/SRCommand.py", line 110, in run
May 19 12:01:37 xen5 SM: [28584]     return self._run_locked(sr)
May 19 12:01:37 xen5 SM: [28584]   File "/opt/xensource/sm/SRCommand.py", line 159, in _run_locked
May 19 12:01:37 xen5 SM: [28584]     rv = self._run(sr, target)
May 19 12:01:38 xen5 SM: [28584]   File "/opt/xensource/sm/SRCommand.py", line 264, in _run
May 19 12:01:38 xen5 SM: [28584]     writable, caching_params)
May 19 12:01:38 xen5 SM: [28584]   File "/opt/xensource/sm/blktap2.py", line 1563, in activate
May 19 12:01:38 xen5 SM: [28584]     if self._activate_locked(sr_uuid, vdi_uuid, options):
May 19 12:01:38 xen5 SM: [28584]   File "/opt/xensource/sm/blktap2.py", line 95, in wrapper
May 19 12:01:38 xen5 SM: [28584]     raise xs_errors.XenError(excType, opterr=msg)
May 19 12:01:38 xen5 SM: [28584]   File "/opt/xensource/sm/xs_errors.py", line 52, in __init__
May 19 12:01:38 xen5 SM: [28584]     raise SR.SROSError(errorcode, errormessage)
May 19 12:01:38 xen5 SM: [28584]
May 19 12:01:38 xen5 SM: [28584] lock: closed /var/lock/sm/c468488b-6072-43f6-a57e-59a739370948/vdi
May 19 12:01:39 xen5 SM: [28719] RBDSR.load: sr_uuid=f60dd3ac-50e9-4a27-8465-51374131de5d
May 19 12:01:39 xen5 SM: [28719] Calling cephutils.SR.load: sr_uuid=f60dd3ac-50e9-4a27-8465-51374131de5d, ceph_user=admin
May 19 12:01:39 xen5 SM: [28719] Calling cephutils.SR._get_srlist
May 19 12:01:39 xen5 SM: [28719] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
May 19 12:01:39 xen5 SM: [28719]   pread SUCCESS
May 19 12:01:39 xen5 SM: [28719] Calling cephutils.SR._get_sr_uuid_by_name: pool=RBD_XenStorage-f60dd3ac-50e9-4a27-8465-51374131de5d
May 19 12:01:39 xen5 SM: [28719] RBDVDI.load: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:39 xen5 SM: [28719] Calling cephutils.SR._get_path: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:39 xen5 SM: [28719] Calling cephutils.VDI.load: vdi_uuid=c468488b-6072-43f6-a57e-59a739370948
May 19 12:01:39 xen5 SM: [28719] vdi_detach {'sr_uuid': 'f60dd3ac-50e9-4a27-8465-51374131de5d', 'subtask_of': 'DummyRef:|9161d7af-20b1-db48-9606-ea9e4f363544|VDI.detach', 'vdi_ref': 'OpaqueRef:e91caf96-d3aa-4b17-203b-207c9912fb94', 'vdi_on_boot': 'persist', 'args': [], 'vd
i_location': 'c468488b-6072-43f6-a57e-59a739370948', 'host_ref': 'OpaqueRef:1d1e830b-2197-f11e-e450-49a9e3fdb9bf', 'session_ref': 'OpaqueRef:af8e1488-388e-a274-ab21-69ec1e1d55f6', 'device_config': {'SRmaster': 'false'}, 'command': 'vdi_detach', 'vdi_allow_caching': 'false'
, 'sr_ref': 'OpaqueRef:44e02825-9f99-d6e4-735f-6c0295d53280', 'vdi_uuid': 'c468488b-6072-43f6-a57e-59a739370948'}
May 19 12:01:39 xen5 SM: [28719] lock: opening lock file /var/lock/sm/c468488b-6072-43f6-a57e-59a739370948/vdi
May 19 12:01:39 xen5 SM: [28719] lock: closed /var/lock/sm/c468488b-6072-43f6-a57e-59a739370948/vdi

Installation goes smooth and everything seems right but our XenServer broke after installation.
# xe vm-start vm=UXVN0016
There was an SR backend failure. status: non-zero exit stdout:
stderr: Traceback (most recent call last): File "/opt/xensource/sm/NFSSR", line 295, in <module> SRCommand.run(NFSSR, DRIVER_INFO) File "/opt/xensource/sm/SRCommand.py", line 352, in run ret = cmd.run(sr) File "/opt/xensource/sm/SRCommand.py", line 110, in run return self._run_locked(sr) File "/opt/xensource/sm/SRCommand.py", line 159, in _run_locked rv = self._run(sr, target) File "/opt/xensource/sm/SRCommand.py", line 264, in _run writable, caching_params) File "/opt/xensource/sm/blktap2.py", line 1560, in activate if self._activate_locked(sr_uuid, vdi_uuid, options): File "/opt/xensource/sm/blktap2.py", line 86, in wrapper ret = op(self, *args) File "/opt/xensource/sm/blktap2.py", line 1607, in _activate_locked dev_path = self._activate(sr_uuid, vdi_uuid, options) File "/opt/xensource/sm/blktap2.py", line 1651, in _activate self._get_pool_config(sr_uuid).get("mem-pool-size")) File "/opt/xensource/sm/blktap2.py", line 1305, in _tap_activate options) File "/opt/xensource/sm/blktap2.py", line 810, in launch_on_tap exc_info = sys.exc_info()
NameError: global name 'sys' is not defined

Update 1: restored /sbin/tap-ctl back to original version, problem fixed.

Hello, while I am in the process of trying to re-attach a somehow lost VDI connection, I tested creating a simple VDI, forgetting it, and then introducing it again. (This was done in the hopes of being a way to re-connect my VDI that now will no longer boot....)

I can see that the RBD exists in my ceph cluster

[root@xen5 ~]# rbd image-meta list VHD-551f9479-940b-4d95-a0d2-c1beb3f53a08 --pool RBD_XenStorage-ab0fe076-12f7-4a7e-8792-73a70a7a2301                                             
There are 2 metadatas on this image.
Key             Value                                                             
VDI_DESCRIPTION Test disk image for the purposes of forgetting and re-introducing 
VDI_LABEL       NB_TEST_FORGET_INTRO                                              
[root@xen5 ~]# 

When I run the introduce command:

 xe vdi-introduce name-label=NB_TESTED_NOW_INTROD name-description="Test disk image forgotten, now remembered" location=551f9479-940b-4d95-a0d2-c1beb3f53a08 type=user sr-uuid=ab0fe076-12f7-4a7e-8792-73a70a7a2301 uuid=551f9479-940b-4d95-a0d2-c1beb3f53a08 sm-config:vdi_type=aio 

# I get:

The server failed to handle your request, due to an internal error.  The given message may give details useful for debugging the problem.
message: Storage_interface.Vdi_does_not_exist("551f9479-940b-4d95-a0d2-c1beb3f53a08")

The introduction fails, and SMlog has the following:

Jun  6 22:43:52 xen3 SM: [20527] RBDSR.load: sr_uuid=ab0fe076-12f7-4a7e-8792-73a70a7a2301
Jun  6 22:43:52 xen3 SM: [20527] Calling cephutils.SR.load: sr_uuid=ab0fe076-12f7-4a7e-8792-73a70a7a2301, ceph_user=admin
Jun  6 22:43:52 xen3 SM: [20527] Calling cephutils.SR._get_srlist
Jun  6 22:43:52 xen3 SM: [20527] ['ceph', 'df', '--format', 'json', '--name', 'client.admin']
Jun  6 22:43:53 xen3 SM: [20527]   pread SUCCESS
Jun  6 22:43:53 xen3 SM: [20527] Calling cephutils.SR._get_sr_uuid_by_name: pool=RBD_XenStorage-f60dd3ac-50e9-4a27-8465-51374131de5d
Jun  6 22:43:53 xen3 SM: [20527] Calling cephutils.SR._get_sr_uuid_by_name: pool=RBD_XenStorage-ab0fe076-12f7-4a7e-8792-73a70a7a2301
Jun  6 22:43:53 xen3 SM: [20527] vdi_introduce {'sr_uuid': 'ab0fe076-12f7-4a7e-8792-73a70a7a2301', 'subtask_of': 'DummyRef:|749726ce-a2fa-cb4e-6b50-bbfc75fa08bc|VDI.introduce', 'args': [], 'vdi_location': '551f9479-940b-4d95-a0d2-c1beb3f53a08', 'host_ref': 'OpaqueRef:f9942fa1-4705-0914-0468-fb54bcbdaa68', 'session_ref': 'OpaqueRef:743c4d30-3059-80b9-a5db-22a339b58eb5', 'device_config': {'SRmaster': 'true'}, 'command': 'vdi_introduce', 'sr_ref': 'OpaqueRef:ddd35779-b212-ecf2-486d-83a0be957f9c', 'new_uuid': '551f9479-940b-4d95-a0d2-c1beb3f53a08', 'vdi_sm_config': {'vdi_type': 'aio'}}
Jun  6 22:43:53 xen3 SM: [20527] RBDVDI.load: vdi_uuid=551f9479-940b-4d95-a0d2-c1beb3f53a08
Jun  6 22:43:53 xen3 SM: [20527] Calling cephutils.SR._get_path: vdi_uuid=551f9479-940b-4d95-a0d2-c1beb3f53a08
Jun  6 22:43:53 xen3 SM: [20527] Calling cephutils.VDI.load: vdi_uuid=551f9479-940b-4d95-a0d2-c1beb3f53a08
Jun  6 22:43:53 xen3 SM: [20527] Raising exception [38, The requested method is not supported/implemented]
Jun  6 22:43:53 xen3 SM: [20527] ***** generic exception: vdi_introduce: EXCEPTION <class 'SR.SROSError'>, The requested method is not supported/implemented
Jun  6 22:43:53 xen3 SM: [20527]   File "/opt/xensource/sm/SRCommand.py", line 110, in run
Jun  6 22:43:53 xen3 SM: [20527]     return self._run_locked(sr)
Jun  6 22:43:53 xen3 SM: [20527]   File "/opt/xensource/sm/SRCommand.py", line 159, in _run_locked
Jun  6 22:43:53 xen3 SM: [20527]     rv = self._run(sr, target)
Jun  6 22:43:53 xen3 SM: [20527]   File "/opt/xensource/sm/SRCommand.py", line 234, in _run
Jun  6 22:43:53 xen3 SM: [20527]     return target.introduce(self.params['sr_uuid'], self.params['new_uuid'])
Jun  6 22:43:53 xen3 SM: [20527]   File "/opt/xensource/sm/VDI.py", line 163, in introduce
Jun  6 22:43:53 xen3 SM: [20527]     raise xs_errors.XenError('Unimplemented')
Jun  6 22:43:53 xen3 SM: [20527]   File "/opt/xensource/sm/xs_errors.py", line 52, in __init__
Jun  6 22:43:53 xen3 SM: [20527]     raise SR.SROSError(errorcode, errormessage)
Jun  6 22:43:53 xen3 SM: [20527]
Jun  6 22:43:53 xen3 SM: [20527] ***** RBD: EXCEPTION <class 'SR.SROSError'>, The requested method is not supported/implemented
Jun  6 22:43:53 xen3 SM: [20527]   File "/opt/xensource/sm/SRCommand.py", line 353, in run
Jun  6 22:43:53 xen3 SM: [20527]     ret = cmd.run(sr)
Jun  6 22:43:53 xen3 SM: [20527]   File "/opt/xensource/sm/SRCommand.py", line 110, in run
Jun  6 22:43:53 xen3 SM: [20527]     return self._run_locked(sr)
Jun  6 22:43:53 xen3 SM: [20527]   File "/opt/xensource/sm/SRCommand.py", line 159, in _run_locked
Jun  6 22:43:53 xen3 SM: [20527]     rv = self._run(sr, target)
Jun  6 22:43:53 xen3 SM: [20527]   File "/opt/xensource/sm/SRCommand.py", line 234, in _run
Jun  6 22:43:53 xen3 SM: [20527]     return target.introduce(self.params['sr_uuid'], self.params['new_uuid'])
Jun  6 22:43:53 xen3 SM: [20527]   File "/opt/xensource/sm/VDI.py", line 163, in introduce
Jun  6 22:43:53 xen3 SM: [20527]     raise xs_errors.XenError('Unimplemented')