[Pkg-xen-devel] Bug#674161: Bug#674161: xcp-xapi: 'the device disappeared from xenstore' message during vbd-plug (vm-start)

Wed May 23 22:09:49 UTC 2012

On 23.05.2012 19:28, Mike McClurg wrote:
> vbd plug to PV domain cause following error:
>
> The server failed to handle your request, due to an internal error.  The given message may give details useful for debugging the problem.
> message: the device disappeared from xenstore (frontend (domid=4 | kind=vbd | devid=51760); backend (domid=0 | kind=vbd | devid=51760))
> <snip>
>
>> # xe sr-create type=file name-label=fileSR device-config:location=/mnt
>> 319f3eaa-d1ba-a81d-acb3-493ecbdaab17
> Here's the problem. The SR type "file" doesn't work the way you'd want
> it to. It's actually the base class for the ext and NFS backends, and
> isn't meant to be accessed directly. This class doesn't actually have
> the create methods required to actually create the appropriate
> directories necessary for a file-based SR.
>
> Could you please try to reproduce this bug with a different backend?
> NFS would probably be easiest. If the VBD plug happens on a different
> SR type, then I'll consider this a bug.
>
> Mike
>
> PS: As an aside, it should be possible to manually create an SR of
> this type yourself (or so the storage team leads me to believe). If
> you create a fresh uuid using uuidgen, you can then create a directory
> called /var/run/sm/<new uuid>, and then call 'xe sr-introduce
> type=file uuid=<new uuid> name-label=name'. I haven't tried this yet,
> but I'm about to.

Ok, i've done it with nfs SM.
  xe vbd-plug uuid=605c8d8b-b91d-bca8-4df2-ee1b6ee3cf31
The server failed to handle your request, due to an internal error. The 
given message may give details useful for debugging the problem.
message: the device disappeared from xenstore (frontend (domid=1 | 
kind=vbd | devid=51712); backend (domid=0 | kind=vbd | devid=51712))

After do manual 'xenstore-write /local/domain/0/vm hello' vbd-plug does 
not return error, but disk does not appear in guest domain (and no 
messages in dmesg of guest). Not in 'initrd' stage, not in debian 
netinst installer.

But at least I see it (vdi) in /dev/sm:

ls -la 
/dev/sm/backend/4c15ea03-5d70-938e-8265-d5424c0fda5e/651d7a25-d702-47dd-aa01-0469dec75c2a 

brw------- 1 root root 252, 0 May 24 01:50 
/dev/sm/backend/4c15ea03-5d70-938e-8265-d5424c0fda5e/651d7a25-d702-47dd-aa01-0469dec75c2a

here cut from xcp-xapi.log:

[20120523T21:55:32.346Z| info|lab-xh3|370 UNIX /var/lib/xcp/xapi||cli] 
xe vbd-plug uuid=605c8d8b-b91d-bca8-4df2-ee1b6ee3cf31 username=root 
password=null
[20120523T21:55:32.348Z| info|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|session.login_with_password D:e241022d2c76|xapi] 
Session.create trackid=9ffe2bef6f34023ee4bdc35a2f2b9195 pool=false 
uname=root is_local_superuser=true auth_user_sid= 
parent=trackid=9834f5af41c964e225f24279aefe4e49
[20120523T21:55:32.349Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|session.login_with_password D:e241022d2c76|xapi] 
Attempting to open /var/lib/xcp/xapi
[20120523T21:55:32.350Z|debug|lab-xh3|371 UNIX 
/var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.get_uuid 
D:52c338ab77c1 created by task D:e241022d2c76
[20120523T21:55:32.356Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|audit] VBD.plug: VBD = 
'605c8d8b-b91d-bca8-4df2-ee1b6ee3cf31'
[20120523T21:55:32.360Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|locking_helpers] Acquired lock 
on VM OpaqueRef:39e6d669-5b1d-c589-1ea7-82f668c8bea4 with token 5
[20120523T21:55:32.360Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|xapi] vbd_plug: attempting to 
attach vbd
[20120523T21:55:32.360Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|xapi] Attempting to 
dynamically attach VBD to domid 1
[20120523T21:55:32.361Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|xapi] VBD device name 0 
interpreted as Xen(0, 0) (hvm = false)
[20120523T21:55:32.361Z| info|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|storage_impl] VDI.attach 
task:OpaqueRef:fc05dc0c-bc95-c277-1b9f-041d6d3a0d76 dp:vbd/1/0 
sr:4c15ea03-5d70-938e-8265-d5424c0fda5e 
vdi:651d7a25-d702-47dd-aa01-0469dec75c2a read_write:true
[20120523T21:55:32.361Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|storage_impl] 
task:OpaqueRef:fc05dc0c-bc95-c277-1b9f-041d6d3a0d76 dp:vbd/1/0 
sr:4c15ea03-5d70-938e-8265-d5424c0fda5e 
vdi:651d7a25-d702-47dd-aa01-0469dec75c2a superstate:activated RW
[20120523T21:55:32.362Z| info|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|storage_impl] VDI.activate 
task:OpaqueRef:fc05dc0c-bc95-c277-1b9f-041d6d3a0d76 dp:vbd/1/0 
sr:4c15ea03-5d70-938e-8265-d5424c0fda5e 
vdi:651d7a25-d702-47dd-aa01-0469dec75c2a
[20120523T21:55:32.362Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|storage_impl] 
task:OpaqueRef:fc05dc0c-bc95-c277-1b9f-041d6d3a0d76 dp:vbd/1/0 
sr:4c15ea03-5d70-938e-8265-d5424c0fda5e 
vdi:651d7a25-d702-47dd-aa01-0469dec75c2a superstate:activated RW
[20120523T21:55:32.363Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|xenops] Device.Vbd.add 
(device_number=Xen(0, 0) | 
params=/dev/sm/backend/4c15ea03-5d70-938e-8265-d5424c0fda5e/651d7a25-d702-47dd-aa01-0469dec75c2a 
| phystype=vhd)
[20120523T21:55:32.363Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|xenops] adding device 
B0[/local/domain/0/backend/vbd/1/51712] 
F1[/local/domain/1/device/vbd/51712]  H[/xapi/1/hotplug/vbd/51712]
[20120523T21:55:32.377Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|hotplug] 
Hotplug.wait_for_plug: frontend (domid=1 | kind=vbd | devid=51712); 
backend (domid=0 | kind=vbd | devid=51712)
[20120523T21:55:32.378Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|xenops] watch: watching 
xenstore paths: [ /local/domain/0/backend/vbd/1/51712/hotplug-status ] 
with timeout 300.000000 seconds
[20120523T21:55:32.542Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|hotplug] Synchronised ok with 
hotplug script: frontend (domid=1 | kind=vbd | devid=51712); backend 
(domid=0 | kind=vbd | devid=51712)
[20120523T21:55:32.543Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|xapi] set_currently_attached 
to true for VBD uuid 605c8d8b-b91d-bca8-4df2-ee1b6ee3cf31
[20120523T21:55:32.543Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|xapi] vbd_plug: successfully 
hotplugged device
[20120523T21:55:32.543Z|debug|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|VBD.plug R:fc05dc0cbc95|locking_helpers] Released lock 
on VM OpaqueRef:39e6d669-5b1d-c589-1ea7-82f668c8bea4 with token 5
[20120523T21:55:32.553Z| info|lab-xh3|370 UNIX 
/var/lib/xcp/xapi|session.logout D:923228986950|xapi] Session.destroy 
trackid=9ffe2bef6f34023ee4bdc35a2f2b9195
[20120523T21:55:55.053Z| info|lab-xh3|5 dbflush 
[/var/lib/xcp/state.db]||redo_log] Flushing database to all active redo-logs
[20120523T21:55:55.508Z|debug|lab-xh3|19|session_revalidation_func 
D:1abe801db75a|xapi] revalidating all external sessions in the local host
[20120523T21:55:55.508Z|debug|lab-xh3|19|Starting periodic scheduler 
D:de1eab10d315|backgroundscheduler] Adding function Revalidating 
externally-authenticated sessions to queue, start=300.000000, 
type=Periodic(300.000000)
[20120523T21:55:55.508Z|debug|lab-xh3|19|Starting periodic scheduler 
D:de1eab10d315|backgroundscheduler] Sleeping until next event 
(120.040193 seconds)