WARNING - OLD ARCHIVES

This is an archived copy of the Xen.org mailing list, which we have preserved to ensure that existing links to archives are not broken. The live archive, which contains the latest emails, can be found at http://lists.xen.org/
   
 
 
Xen 
 
Home Products Support Community News
 
   
 

xen-users

Re: [Xen-users] XCP : Failed load VDI information on NFS shared repo

To: admin@xxxxxxxxxxx
Subject: Re: [Xen-users] XCP : Failed load VDI information on NFS shared repo
From: Ciaran Kendellen <ciaran@xxxxxxxxxxxxxxx>
Date: Mon, 12 Sep 2011 13:23:05 +0100
Cc: Grant McWilliams <grantmasterflash@xxxxxxxxx>, xen-users@xxxxxxxxxxxxxxxxxxx
Delivery-date: Mon, 12 Sep 2011 05:27:11 -0700
Envelope-to: www-data@xxxxxxxxxxxxxxxxxxx
In-reply-to: <CANXrN=0JnkKjYD4jNn3ZtHZ0uOgH7heuqD_xeFgw9kE8ekbUjg@xxxxxxxxxxxxxx>
List-help: <mailto:xen-users-request@lists.xensource.com?subject=help>
List-id: Xen user discussion <xen-users.lists.xensource.com>
List-post: <mailto:xen-users@lists.xensource.com>
List-subscribe: <http://lists.xensource.com/mailman/listinfo/xen-users>, <mailto:xen-users-request@lists.xensource.com?subject=subscribe>
List-unsubscribe: <http://lists.xensource.com/mailman/listinfo/xen-users>, <mailto:xen-users-request@lists.xensource.com?subject=unsubscribe>
References: <4E64F317.2070300@xxxxxxxxxxxxxxx> <CAGnmK4y45arSQeTaVD8ndXMsN=JNRycWJBTPoP8TL+yyouMNEw@xxxxxxxxxxxxxx> <CANXrN=0JnkKjYD4jNn3ZtHZ0uOgH7heuqD_xeFgw9kE8ekbUjg@xxxxxxxxxxxxxx>
Sender: xen-users-bounces@xxxxxxxxxxxxxxxxxxx
User-agent: Mozilla/5.0 (X11; U; Linux x86_64; en-GB; rv:1.9.2.17) Gecko/20110414 SUSE/3.1.10 Thunderbird/3.1.10
Many thanks for your replies.

Grant, I don't think its an inherent problem with the SR as I have other VMs operating on it no problem - it is just a couple of them giving trouble at the moment.

David,

That is my suspicion too, but I'm not sure where to start repairing.

I've discovered a second VM displaying the same symptoms, this is just an xvp appliance so I can merrily break it if breaking it enables me to fix the vm in my original mail... Just thought I'd mention that in case you were comparing the logs below with the original post and saw different uuids, names etc.

SM Log for the call is as follows :

[3104] 2011-09-12 13:12:04.988006       lock: acquired /var/lock/sm/0554f47c-1a12-9bd1-ea9b-d2b68984f0ed/sr
[3104] 2011-09-12 13:12:04.990879       ['/usr/sbin/td-util', 'query', 'vhd', '-vpf', '/var/run/sr-mount/0554f47c-1a12-9bd1-ea9b-d2b68984f0ed/f2c83f05-ee59-4a49-ad5d-2ecdfd6a8ca1.vhd']
[3104] 2011-09-12 13:12:05.013444       FAILED: (rc 22) stdout: '102400
failed getting parent: -22
hidden: 0
', stderr: ''
[3104] 2011-09-12 13:12:05.044769       Raising exception [65, Failed to load VDI [opterr=Failed load VDI information /var/run/sr-mount/0554f47c-1a12-9bd1-ea9b-d2b68984f0ed/f2c83f05-ee59-4a49-ad5d-2ecdfd6a8ca1.vhd]]
[3104] 2011-09-12 13:12:05.044944       lock: released /var/lock/sm/0554f47c-1a12-9bd1-ea9b-d2b68984f0ed/sr
[3104] 2011-09-12 13:12:05.046128       ***** vdi_attach: EXCEPTION SR.SROSError, Failed to load VDI [opterr=Failed load VDI information /var/run/sr-mount/0554f47c-1a12-9bd1-ea9b-d2b68984f0ed/f2c83f05-ee59-4a49-ad5d-2ecdfd6a8ca1.vhd]
  File "/opt/xensource/sm/SRCommand.py", line 94, in run
    return self._run_locked(sr)
  File "/opt/xensource/sm/SRCommand.py", line 125, in _run_locked
    target = sr.vdi(self.vdi_uuid)
  File "/opt/xensource/sm/NFSSR", line 213, in vdi
    return NFSFileVDI(self, uuid)
  File "/opt/xensource/sm/VDI.py", line 99, in __init__
    self.load(uuid)
  File "/opt/xensource/sm/FileSR.py", line 376, in load
    opterr='Failed load VDI information %s' % self.path)
  File "/opt/xensource/sm/xs_errors.py", line 49, in __init__
    raise SR.SROSError(errorcode, errormessage)

[3104] 2011-09-12 13:12:05.046441       lock: closed /var/lock/sm/0554f47c-1a12-9bd1-ea9b-d2b68984f0ed/sr

messages just has one line for the call as follows :

Sep 12 13:16:28 xen01 xapi: [error|xen01|187930 inet-RPC|VM.start_on R:54f73923094c|xapi] Memory F 13309484 KiB S 0 KiB T 32766 MiB

xensource log is as follows for the event :

[20110912T12:22:01.648Z|debug|xen01|188035 unix-RPC||cli] xe vm-start name-label=xvpappliance on=xen01 username=root password=null
[20110912T12:22:01.653Z| info|xen01|188035 unix-RPC|session.login_with_password D:3889bc894187|xapi] Session.create trackid=9d2394cc4c3c07700fec4b221c0593c4 pool=false uname=root is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
[20110912T12:22:01.656Z|debug|xen01|188036 unix-RPC||dummytaskhelper] task dispatch:session.get_uuid D:b827cde7e378 created by task D:3889bc894187
[20110912T12:22:01.727Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|audit] VM.start_on: VM = 'e08866f7-a4d5-f5c2-edfd-dffc23beceb8 (xvpappliance)'; host '30a88fb8-6af8-46b5-8605-7f64db400ee4 (xen01)'
[20110912T12:22:01.729Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] No operations are valid because current-operations = [ OpaqueRef:5ecc0b72-1dea-5f18-4cd2-eb22be407a8f -> attach ]
[20110912T12:22:01.730Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at db_cache_types.ml:75.27-76 -> db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110912T12:22:01.735Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] host xen01; available_memory = 30781935616; memory_required = 272629760
[20110912T12:22:01.735Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi_ha_vm_failover] assert_configuration_change_preserves_ha_plan c = configuration_change = { old_vms_leaving = [  ]; new_vms_arriving = [ a748ce74 (xen01) 78d1c316 (xvpappliance) ]; hosts_to_disable = [  ]; num_failures = no change; new_vms = [  ] }
[20110912T12:22:01.741Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|thread_queue] push(vm_lifecycle_op, VM.start VM.start_on R:5ecc0b721dea): queue = [ VM.start VM.start_on R:5ecc0b721dea ](1)
[20110912T12:22:01.741Z|debug|xen01|957||thread_queue] pop(vm_lifecycle_op) = VM.start VM.start_on R:5ecc0b721dea
[20110912T12:22:01.743Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|locking_helpers] Acquired lock on VM OpaqueRef:78d1c316-5765-d95a-e2d1-fb0cec16a7c4 with token 49
[20110912T12:22:01.743Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] start: making sure the VM really is halted
[20110912T12:22:01.743Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] start: checking that VM can run on this host
[20110912T12:22:01.745Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] start: bringing up domain in the paused state
[20110912T12:22:01.745Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|memory_control] reserve_memory_range min=266240 max=266240
[20110912T12:22:01.745Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenstore-rpc] Checking pid 7203
[20110912T12:22:01.747Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenstore-rpc] Written request using id: c30f6136-a243-f9bd-b75b-6dfa78173255
[20110912T12:22:01.747Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] watch: watching xenstore paths: [ /squeezed/rpc/response/reserve-memory-range/c30f6136-a243-f9bd-b75b-6dfa78173255 ] with timeout 1200.000000 seconds
[20110912T12:22:01.757Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|memory_control] reserve_memory_range actual = 266240
[20110912T12:22:01.757Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|memory_control] reserved_memory = 266240; min = 266240; max = 266240
[20110912T12:22:01.757Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] VM will have 1 hotplugged vcpus out of 1
[20110912T12:22:01.757Z| info|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Memory free = 13309592; scrub = 0
[20110912T12:22:01.758Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] Regenerating the xenstored tree under: [/local/domain/18]
[20110912T12:22:01.764Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] Created domain with id: 18
[20110912T12:22:01.764Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Created domain with domid: 18
[20110912T12:22:01.764Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|memory_control] transfer_reservation_to_domain a7ac5907-2820-ec8b-de21-b2521e461134 -> 18
[20110912T12:22:01.764Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenstore-rpc] Checking pid 7203
[20110912T12:22:01.766Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenstore-rpc] Written request using id: c1daa892-24b0-9ea0-e7bd-5c667f5afaa2
[20110912T12:22:01.766Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] watch: watching xenstore paths: [ /squeezed/rpc/response/transfer-reservation-to-domain/c1daa892-24b0-9ea0-e7bd-5c667f5afaa2 ] with timeout 1200.000000 seconds
[20110912T12:22:01.772Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|memory_control] delete_reservation a7ac5907-2820-ec8b-de21-b2521e461134
[20110912T12:22:01.772Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenstore-rpc] Checking pid 7203
[20110912T12:22:01.774Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenstore-rpc] Written request using id: ac98c903-5f74-9e3c-2fe6-800b927317ea
[20110912T12:22:01.774Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] watch: watching xenstore paths: [ /squeezed/rpc/response/delete-reservation/ac98c903-5f74-9e3c-2fe6-800b927317ea ] with timeout 1200.000000 seconds
[20110912T12:22:01.777Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Verifying VDI records exist
[20110912T12:22:01.777Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] set machine address size dom18 to 36 bits
[20110912T12:22:01.777Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] creating kernel
[20110912T12:22:01.779Z|debug|xen01|188039 unix-RPC||dummytaskhelper] task dispatch:session.slave_login D:f5c56a9e8395 created by task R:5ecc0b721dea
[20110912T12:22:01.782Z| info|xen01|188039 unix-RPC|session.slave_login D:e44606796cb5|xapi] Session.create trackid=b7aea96e08d6354f7b3cb6b2f7b2d024 pool=true uname= is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
[20110912T12:22:01.785Z|debug|xen01|188040 unix-RPC||dummytaskhelper] task dispatch:session.get_uuid D:3ef100522433 created by task D:e44606796cb5
[20110912T12:22:01.791Z|debug|xen01|188041 unix-RPC||dummytaskhelper] task dispatch:VBD.create D:c9808a91c978 created by task R:5ecc0b721dea
[20110912T12:22:01.794Z| info|xen01|188041 unix-RPC|dispatch:VBD.create D:c9808a91c978|taskhelper] task VBD.create R:ad6ec37bb77c (uuid:b43f0be3-cc14-7e08-2fec-da0ea9b7cd83) created (trackid=b7aea96e08d6354f7b3cb6b2f7b2d024) by task R:5ecc0b721dea
[20110912T12:22:01.794Z|debug|xen01|188041 unix-RPC|VBD.create R:ad6ec37bb77c|audit] VBD.create: VM = '4ec9bdb8-f506-442f-867c-92bdb27cbfc2 (Control domain on host: xen01)'; VDI = 'f2c83f05-ee59-4a49-ad5d-2ecdfd6a8ca1'
[20110912T12:22:01.794Z|debug|xen01|188041 unix-RPC|VBD.create R:ad6ec37bb77c|xapi] Raised at db_cache_types.ml:75.27-76 -> db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110912T12:22:01.796Z|debug|xen01|188041 unix-RPC|VBD.create R:ad6ec37bb77c|xapi] VBD.create (device = 0; uuid = 364b066b-ccaa-b312-f79c-e881da1c8a81; ref = OpaqueRef:51a0f891-852f-6064-041e-43928f448989)
[20110912T12:22:01.799Z|debug|xen01|188041 unix-RPC|VBD.create R:ad6ec37bb77c|xapi] Raised at db_cache_types.ml:75.27-76 -> db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110912T12:22:01.803Z|debug|xen01|188042 unix-RPC||dummytaskhelper] task dispatch:VBD.get_uuid D:2261910bf682 created by task R:5ecc0b721dea
[20110912T12:22:01.807Z|debug|xen01|188043 unix-RPC||dummytaskhelper] task dispatch:VM.get_uuid D:eb246c01b688 created by task R:5ecc0b721dea
[20110912T12:22:01.810Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] created VBD (uuid 364b066b-ccaa-b312-f79c-e881da1c8a81); attempting to hotplug to VM (uuid: 4ec9bdb8-f506-442f-867c-92bdb27cbfc2)
[20110912T12:22:01.812Z|debug|xen01|188044 unix-RPC||dummytaskhelper] task dispatch:VBD.plug D:4a0ea10c8fe8 created by task R:5ecc0b721dea
[20110912T12:22:01.815Z| info|xen01|188044 unix-RPC|dispatch:VBD.plug D:4a0ea10c8fe8|taskhelper] task VBD.plug R:6147287d2941 (uuid:20d8b42b-d7b5-2b48-4211-704a6d82f12f) created (trackid=b7aea96e08d6354f7b3cb6b2f7b2d024) by task R:5ecc0b721dea
[20110912T12:22:01.815Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|audit] VBD.plug: VBD = '364b066b-ccaa-b312-f79c-e881da1c8a81'
[20110912T12:22:01.816Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|xapi] Raised at db_cache_types.ml:75.27-76 -> db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110912T12:22:01.816Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|xapi] Raised at db_cache_types.ml:75.27-76 -> db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110912T12:22:01.816Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|locking_helpers] Acquired lock on VM OpaqueRef:38786ebf-38e6-97b0-7a31-333ddf8dea49 with token 50
[20110912T12:22:01.816Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|xapi] vbd_plug: attempting to attach vbd
[20110912T12:22:01.816Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|xapi] Attempting to dynamically attach VBD to domid 0
[20110912T12:22:01.816Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|sm] SM nfs vdi_attach sr=OpaqueRef:2fb2c4e1-43f1-1290-f005-6bed602a3531 vdi=OpaqueRef:e8cdc9a8-4975-20d7-dce8-71887c184a91 writable=false
[20110912T12:22:01.818Z|debug|xen01|188044 unix-RPC|sm_exec D:f965d1e6b383|xapi] Raised at db_cache_types.ml:75.27-76 -> db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110912T12:22:01.821Z| info|xen01|188044 unix-RPC|sm_exec D:7b8969b683cd|xapi] Session.create trackid=e1dd4867640158cddca03b3de87ddb32 pool=false uname= is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
[20110912T12:22:01.823Z|debug|xen01|188045 unix-RPC||dummytaskhelper] task dispatch:session.get_uuid D:88796cb2eac4 created by task D:7b8969b683cd
[20110912T12:22:01.920Z|debug|xen01|188046 unix-RPC||dummytaskhelper] task dispatch:host.get_other_config D:1220d380196e created by task R:6147287d2941
[20110912T12:22:03.191Z|debug|xen01|188044 unix-RPC|sm_exec D:7b8969b683cd|xapi] Raised at sm_exec.ml:213.7-69 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.192Z| info|xen01|188044 unix-RPC|sm_exec D:7b8969b683cd|xapi] Session.destroy trackid=e1dd4867640158cddca03b3de87ddb32
[20110912T12:22:03.192Z|debug|xen01|188044 unix-RPC|sm_exec D:7b8969b683cd|backtrace] Raised at pervasiveext.ml:26.22-25 -> server_helpers.ml:74.11-23
[20110912T12:22:03.192Z|debug|xen01|188044 unix-RPC|sm_exec D:7b8969b683cd|dispatcher] Server_helpers.exec exception_handler: Got exception SR_BACKEND_FAILURE_65: [ ; Failed to load VDI [opterr=Failed load VDI information /var/run/sr-mount/0554f47c-1a12-9bd1-ea9b-d2b68984f0ed/f2c83f05-ee59-4a49-ad5d-2ecdfd6a8ca1.vhd];  ]
[20110912T12:22:03.192Z|debug|xen01|188044 unix-RPC|sm_exec D:7b8969b683cd|dispatcher] Raised at string.ml:150.25-34 -> stringext.ml:108.13-29
[20110912T12:22:03.192Z|debug|xen01|188044 unix-RPC|sm_exec D:7b8969b683cd|backtrace] Raised at string.ml:150.25-34 -> stringext.ml:108.13-29
[20110912T12:22:03.192Z|debug|xen01|188044 unix-RPC|sm_exec D:7b8969b683cd|xapi] Raised at server_helpers.ml:92.14-15 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.192Z|debug|xen01|188044 unix-RPC|sm_exec D:7b8969b683cd|xapi] Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.192Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|xapi] Raised at pervasiveext.ml:26.22-25 -> sm.ml:152.23-96 -> storage_access.ml:191.6-152 -> threadext.ml:20.23-27 -> threadext.ml:20.65-68 -> storage_access.ml:271.2-39 -> xapi_vbd.ml:41.1-47 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.192Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|xapi] Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.192Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|locking_helpers] Released lock on VM OpaqueRef:38786ebf-38e6-97b0-7a31-333ddf8dea49 with token 50
[20110912T12:22:03.192Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|xapi] Raised at pervasiveext.ml:26.22-25 -> message_forwarding.ml:232.27-46 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.193Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|xapi] Raised at db_cache_types.ml:75.27-76 -> db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.193Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|backtrace] Raised at pervasiveext.ml:26.22-25 -> message_forwarding.ml:3026.6-194 -> rbac.ml:230.16-23
[20110912T12:22:03.194Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|backtrace] Raised at rbac.ml:239.10-15 -> server_helpers.ml:77.11-41
[20110912T12:22:03.194Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|dispatcher] Server_helpers.exec exception_handler: Got exception SR_BACKEND_FAILURE_65: [ ; Failed to load VDI [opterr=Failed load VDI information /var/run/sr-mount/0554f47c-1a12-9bd1-ea9b-d2b68984f0ed/f2c83f05-ee59-4a49-ad5d-2ecdfd6a8ca1.vhd];  ]
[20110912T12:22:03.194Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|dispatcher] Raised at string.ml:150.25-34 -> stringext.ml:108.13-29
[20110912T12:22:03.194Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|backtrace] Raised at string.ml:150.25-34 -> stringext.ml:108.13-29
[20110912T12:22:03.194Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|xapi] Raised at server_helpers.ml:92.14-15 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.195Z|debug|xen01|188044 unix-RPC|VBD.plug R:6147287d2941|xapi] Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.195Z|debug|xen01|188044 unix-RPC|dispatch:VBD.plug D:4a0ea10c8fe8|backtrace] Raised at pervasiveext.ml:26.22-25 -> server_helpers.ml:152.10-106 -> server.ml:26150.19-167 -> server_helpers.ml:118.4-7
[20110912T12:22:03.198Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at client.ml:6.37-75 -> client.ml:9082.12-61 -> list.ml:69.12-15 -> attach_helpers.ml:63.7-787 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.201Z|debug|xen01|188047 unix-RPC||dummytaskhelper] task dispatch:session.slave_login D:aa0468e635a0 created by task R:5ecc0b721dea
[20110912T12:22:03.204Z| info|xen01|188047 unix-RPC|session.slave_login D:96a7944a8155|xapi] Session.create trackid=1533c84883b45b2892655b2656c4b2b1 pool=true uname= is_local_superuser=true auth_user_sid= parent=trackid=9834f5af41c964e225f24279aefe4e49
[20110912T12:22:03.207Z|debug|xen01|188048 unix-RPC||dummytaskhelper] task dispatch:session.get_uuid D:c5ba8309fd09 created by task D:96a7944a8155
[20110912T12:22:03.212Z|debug|xen01|188049 unix-RPC||dummytaskhelper] task dispatch:VBD.unplug D:c02fcb41ad59 created by task R:5ecc0b721dea
[20110912T12:22:03.215Z| info|xen01|188049 unix-RPC|dispatch:VBD.unplug D:c02fcb41ad59|taskhelper] task VBD.unplug R:5d27ceacd0ed (uuid:16537a45-d957-ccac-8632-d7cd0ea4107b) created (trackid=1533c84883b45b2892655b2656c4b2b1) by task R:5ecc0b721dea
[20110912T12:22:03.215Z|debug|xen01|188049 unix-RPC|VBD.unplug R:5d27ceacd0ed|audit] VBD.unplug: VBD = '364b066b-ccaa-b312-f79c-e881da1c8a81'
[20110912T12:22:03.215Z|debug|xen01|188049 unix-RPC|VBD.unplug R:5d27ceacd0ed|xapi] Raised at db_cache_types.ml:75.27-76 -> db_cache_types.ml:118.2-40 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.215Z|debug|xen01|188049 unix-RPC|VBD.unplug R:5d27ceacd0ed|backtrace] Raised at xapi_vbd_helpers.ml:185.33-72 -> message_forwarding.ml:2970.4-64 -> message_forwarding.ml:285.6-9
[20110912T12:22:03.216Z|debug|xen01|188049 unix-RPC|VBD.unplug R:5d27ceacd0ed|xapi] Caught exception while DEVICE_ALREADY_DETACHED: [ OpaqueRef:51a0f891-852f-6064-041e-43928f448989 ] in message forwarder: marking VBD for VBD.unplug
[20110912T12:22:03.216Z|debug|xen01|188049 unix-RPC|VBD.unplug R:5d27ceacd0ed|backtrace] Raised at message_forwarding.ml:288.10-11 -> threadext.ml:20.23-27 -> threadext.ml:20.65-68 -> message_forwarding.ml:152.16-22 -> message_forwarding.ml:2975.6-90 -> message_forwarding.ml:3035.6-199 -> rbac.ml:230.16-23
[20110912T12:22:03.216Z|debug|xen01|188049 unix-RPC|VBD.unplug R:5d27ceacd0ed|backtrace] Raised at rbac.ml:239.10-15 -> server_helpers.ml:77.11-41
[20110912T12:22:03.216Z|debug|xen01|188049 unix-RPC|VBD.unplug R:5d27ceacd0ed|dispatcher] Server_helpers.exec exception_handler: Got exception DEVICE_ALREADY_DETACHED: [ OpaqueRef:51a0f891-852f-6064-041e-43928f448989 ]
[20110912T12:22:03.216Z|debug|xen01|188049 unix-RPC|VBD.unplug R:5d27ceacd0ed|dispatcher] Raised at string.ml:150.25-34 -> stringext.ml:108.13-29
[20110912T12:22:03.216Z|debug|xen01|188049 unix-RPC|VBD.unplug R:5d27ceacd0ed|backtrace] Raised at string.ml:150.25-34 -> stringext.ml:108.13-29
[20110912T12:22:03.216Z|debug|xen01|188049 unix-RPC|VBD.unplug R:5d27ceacd0ed|xapi] Raised at server_helpers.ml:92.14-15 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.217Z|debug|xen01|188049 unix-RPC|VBD.unplug R:5d27ceacd0ed|xapi] Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.217Z|debug|xen01|188049 unix-RPC|dispatch:VBD.unplug D:c02fcb41ad59|backtrace] Raised at pervasiveext.ml:26.22-25 -> server_helpers.ml:152.10-106 -> server.ml:26174.19-167 -> server_helpers.ml:118.4-7
[20110912T12:22:03.217Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|backtrace] Raised at client.ml:6.37-75 -> client.ml:9088.12-63 -> attach_helpers.ml:26.4-41 -> helpers.ml:34.35-38
[20110912T12:22:03.217Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|helpers] Ignoring exception: DEVICE_ALREADY_DETACHED: [ OpaqueRef:51a0f891-852f-6064-041e-43928f448989 ] while unplugging disk from VM
[20110912T12:22:03.219Z|debug|xen01|188050 unix-RPC||dummytaskhelper] task dispatch:VBD.destroy D:c47bd3576d47 created by task R:5ecc0b721dea
[20110912T12:22:03.223Z| info|xen01|188050 unix-RPC|dispatch:VBD.destroy D:c47bd3576d47|taskhelper] task VBD.destroy R:95470c39df5c (uuid:eb8534b6-f644-d2d5-48af-425491e0f88b) created (trackid=1533c84883b45b2892655b2656c4b2b1) by task R:5ecc0b721dea
[20110912T12:22:03.223Z|debug|xen01|188050 unix-RPC|VBD.destroy R:95470c39df5c|audit] VBD.destroy: VBD = '364b066b-ccaa-b312-f79c-e881da1c8a81'
[20110912T12:22:03.223Z|debug|xen01|188050 unix-RPC|VBD.destroy R:95470c39df5c|xapi] VBD.destroy (uuid = 364b066b-ccaa-b312-f79c-e881da1c8a81; ref = OpaqueRef:51a0f891-852f-6064-041e-43928f448989)
[20110912T12:22:03.226Z|debug|xen01|188051 unix-RPC||dummytaskhelper] task dispatch:session.logout D:e33a5c1c5b93 created by task R:5ecc0b721dea
[20110912T12:22:03.229Z| info|xen01|188051 unix-RPC|session.logout D:e6d11b45345d|xapi] Session.destroy trackid=1533c84883b45b2892655b2656c4b2b1
[20110912T12:22:03.229Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.231Z|debug|xen01|188052 unix-RPC||dummytaskhelper] task dispatch:session.logout D:323e65aad0e3 created by task R:5ecc0b721dea
[20110912T12:22:03.233Z| info|xen01|188052 unix-RPC|session.logout D:4fe260a5a195|xapi] Session.destroy trackid=b7aea96e08d6354f7b3cb6b2f7b2d024
[20110912T12:22:03.234Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|backtrace] Raised at pervasiveext.ml:26.22-25 -> vmops.ml:272.4-333 -> vmops.ml:1050.8-64
[20110912T12:22:03.234Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Vmops.start_paused caught: SR_BACKEND_FAILURE_65: [ ; Failed to load VDI [opterr=Failed load VDI information /var/run/sr-mount/0554f47c-1a12-9bd1-ea9b-d2b68984f0ed/f2c83f05-ee59-4a49-ad5d-2ecdfd6a8ca1.vhd];  ]: calling domain_destroy
[20110912T12:22:03.234Z|error|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Memory F 13309484 KiB S 0 KiB T 32766 MiB
[20110912T12:22:03.235Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] Domain.destroy: all known devices = [  ]
[20110912T12:22:03.235Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] Domain.destroy calling Xc.domain_destroy (domid 18)
[20110912T12:22:03.235Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] No qemu-dm pid in xenstore; assuming this domain was PV
[20110912T12:22:03.241Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] Domain.destroy: rm /local/domain/18
[20110912T12:22:03.241Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] Domain.destroy: deleting backend paths
[20110912T12:22:03.242Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] Xc.domain_getinfo 18 threw: getinfo failed: domain 18: domain 18 - vcpu 0 getinfo failed: hypercall 36 fail: 3: No such process (ret -1) -- assuming domain nolonger exists
[20110912T12:22:03.242Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xenops] Xc.domain_getinfo 18 threw: getinfo failed: domain 18: getinfo failed: domain 18: domain 18 - vcpu 0 getinfo failed: hypercall 36 fail: 3: No such process (ret -1) -- assuming domain nolonger exists
[20110912T12:22:03.242Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at vmops.ml:1136.14-51 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.243Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at pervasiveext.ml:26.22-25 -> xc.ml:125.13-17 -> xc.ml:125.56-59 -> xapi_vm.ml:247.1-110 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.243Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.243Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|locking_helpers] Released lock on VM OpaqueRef:78d1c316-5765-d95a-e2d1-fb0cec16a7c4 with token 49
[20110912T12:22:03.243Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.243Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at pervasiveext.ml:26.22-25 -> message_forwarding.ml:232.27-46 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.245Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.245Z|debug|xen01|957||thread_queue] vm_lifecycle_op: completed processing 1 items: queue = [  ](0)
[20110912T12:22:03.249Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.249Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.250Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Checking for vdis_reset_and_caching...
[20110912T12:22:03.250Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Op allowed!
[20110912T12:22:03.250Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|backtrace] Raised at pervasiveext.ml:26.22-25 -> message_forwarding.ml:1063.6-957 -> rbac.ml:230.16-23
[20110912T12:22:03.251Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|backtrace] Raised at rbac.ml:239.10-15 -> server_helpers.ml:77.11-41
[20110912T12:22:03.251Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|dispatcher] Server_helpers.exec exception_handler: Got exception SR_BACKEND_FAILURE_65: [ ; Failed to load VDI [opterr=Failed load VDI information /var/run/sr-mount/0554f47c-1a12-9bd1-ea9b-d2b68984f0ed/f2c83f05-ee59-4a49-ad5d-2ecdfd6a8ca1.vhd];  ]
[20110912T12:22:03.251Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|dispatcher] Raised at string.ml:150.25-34 -> stringext.ml:108.13-29
[20110912T12:22:03.251Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|backtrace] Raised at string.ml:150.25-34 -> stringext.ml:108.13-29
[20110912T12:22:03.251Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at server_helpers.ml:92.14-15 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.251Z|debug|xen01|188035 unix-RPC|VM.start_on R:5ecc0b721dea|xapi] Raised at pervasiveext.ml:26.22-25 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.252Z|debug|xen01|188035 unix-RPC|dispatch:VM.start_on D:a30b3a88e0cf|backtrace] Raised at pervasiveext.ml:26.22-25 -> server_helpers.ml:152.10-106 -> server.ml:8033.19-167 -> server_helpers.ml:118.4-7
[20110912T12:22:03.252Z|debug|xen01|188035 unix-RPC||xapi] Raised at client.ml:6.37-75 -> client.ml:4118.12-89 -> cli_operations.ml:1670.14-18 -> cli_operations.ml:1715.13-29 -> cli_operations.ml:1935.7-418 -> xapi_cli.ml:120.18-56 -> pervasiveext.ml:22.2-9
[20110912T12:22:03.255Z| info|xen01|188035 unix-RPC|session.logout D:8e5c3a9d5346|xapi] Session.destroy trackid=9d2394cc4c3c07700fec4b221c0593c4
[20110912T12:22:03.255Z|debug|xen01|188035 unix-RPC||backtrace] Raised at pervasiveext.ml:26.22-25 -> xapi_cli.ml:119.2-138 -> xapi_cli.ml:208.7-44 -> xapi_cli.ml:260.4-23
[20110912T12:22:03.255Z|debug|xen01|188035 unix-RPC||cli] Xapi_cli.exception_handler: Got exception SR_BACKEND_FAILURE_65: [ ; Failed to load VDI [opterr=Failed load VDI information /var/run/sr-mount/0554f47c-1a12-9bd1-ea9b-d2b68984f0ed/f2c83f05-ee59-4a49-ad5d-2ecdfd6a8ca1.vhd];  ]
[20110912T12:22:03.255Z|debug|xen01|188035 unix-RPC||cli] Raised at string.ml:150.25-34 -> stringext.ml:108.13-29

Any assistance would be very much appreciated.

Kindest regards,

Ciaran.



On 09/09/11 13:47, David Markey wrote:
I bet your VHD is corrupt.

Can you give a bit more SMlog context, i.e. 10 lines above and below?

Can you give dmesg output also.


On 9 September 2011 06:32, Grant McWilliams <grantmasterflash@xxxxxxxxx> wrote:


On Mon, Sep 5, 2011 at 9:04 AM, Ciaran Kendellen <ciaran@xxxxxxxxxxxxxxx> wrote:
Hello there.

I had cause to force shutdown a vm recently and on attempting to restart it I get :

Error code: SR_BACKEND_FAILURE_65
Error parameters: , Failed to load VDI [opterr=Failed load VDI information /var/run/sr-mount/0554f47c-1a12-9bd1-ea9b-d2b68984f0ed/e82a1032-5a0c-4ff7-96cf-1f62f32938db.vhd]

The VDI is on a shared NFS repository, other vm's came back up no problem.

Any ideas what to try anyone?

Thanks in advance,

Ciaran.

___
NFS is sideways. Start at the low layers on the host with the NFS share and make sure everything is good there first. For instance if you have more than one NFS mount or you change the mount, or it doesn't mount up etc. you will get these errors. I got this when I had an SR connected and I shut down NFS, renamed the export and started it back up. The SR sat there twitching until I realised what I did.

Grant McWilliams
http://grantmcwilliams.com/



_______________________________________________
Xen-users mailing list
Xen-users@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/xen-users


_______________________________________________
Xen-users mailing list
Xen-users@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/xen-users