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

[Top] [All Lists]
<prev [Date] next>
[Advanced]
 <prev [Thread] next>

[Xen-users] hotplug scripts not working

from [Igor Serebryany] [Permanent Link][Original]
To: Xen Users Mailing List <xen-users@xxxxxxxxxxxxxxxxxxx>
Subject: [Xen-users] hotplug scripts not working
From: Igor Serebryany <igor47@xxxxxxxxxxx>
Date: Fri, 8 Oct 2010 15:15:34 -0500
Delivery-date: Fri, 08 Oct 2010 13:16:59 -0700
Envelope-to: www-data@xxxxxxxxxxxxxxxxxxx
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>
Sender: xen-users-bounces@xxxxxxxxxxxxxxxxxxx
User-agent: Mutt/1.5.20 (2009-06-14) 
Hi Friends! 

        I've been having this occasional but persistent problem where Xen
        hosts which had been working properly will get into a state where I
        cannot start any new VMs. Attempts will error out with the following
        message:
        
        'Device 51712 (vbd) could not be connected. Hotplug scripts not
        working.'

        I have seen this both on Debian Lenny with Xen 3.2.1 and on Debian
        Squeeze with Xen 4.0.1

        I have scoured the net for this, and it seems for some people the
        problem is the wrong file name for their backing store -- not the
        problem in my case -- or something wrong with their network drivers
        -- also maybe (?) not the problem for me, as it is the disk device I
        get hung up on.

        The domains which have trouble starting get created and paused. I am
        able to unpause and console them, in which case they get to a point
        in their bootup where a message says:

        XENBUS: Waiting for devices to initialise: 295s...290s...

        Eventually the countdown times out and the VM crashes (it will show
        up as crashed in 'xm list').

        Before I fill the rest of the email with tracebacks, I should point
        out that this happens with several different types of backing stores
        (raw tap, tap2:aio, file), with several different kinds of booting
        mechanisms (pygrub, local kernel). The only solution appears to be
        to reboot the node -- restarting xend, xenconsoled, udev or anything
        else doesn't seem to help.

        I would love pointers on how to prevent this issue from happening,
        or how to resolve it without a reboot once it happens. I'm all out
        of ideas for how to debug it further.

        Here is the traceback from the xend log that shows the problem, from
        the moment I attempt to start the VM to the moment xen finishes
        cleaning up:

[2010-10-08 02:34:09 2481] DEBUG (XendDomainInfo:101) 
XendDomainInfo.create(['vm', ['name', 'vmprovision.testdomain.net'], ['memory', 
'500'], ['maxmem', '8057'], ['vcpus', '4'], ['uuid', 
'29afdd70-8030-db14-f318-d512a43d2d76'], ['description', 'VM ID 29567 Uber ID 
173687'], ['on_poweroff', 'destroy'], ['on_reboot', 'destroy'], ['on_crash', 
'preserve'], ['image', ['linux', ['kernel', '/tmp/vmlinuz.WelUc'], ['ramdisk', 
'/tmp/initrd.gz.WelUc']]], ['device', ['vbd', ['dev', 'xvda'], ['uname', 
'tap:tapdisk:/distributed/vms/29567/disk.img'], ['mode', 'w']]], ['device', 
['vbd', ['dev', 'xvdb'], ['uname', 
'phy:/dev/VMSwapParts/vmprovision.testdomain.net'], ['mode', 'w']]], ['device', 
['vif', ['mac', '02:00:00:01:cd:fc'], ['bridge', 'xenbr0'], ['script', 
'vif-bridge']]], ['device', ['vif', ['mac', '02:00:00:01:cd:fd'], ['bridge', 
'vlanbr338'], ['script', 'vif-bridge-vlan']]]])
[2010-10-08 02:34:09 2481] DEBUG (XendDomainInfo:2508) 
XendDomainInfo.constructDomain
[2010-10-08 02:34:09 2481] DEBUG (balloon:220) Balloon: 8033248 KiB free; need 
16384; done.
[2010-10-08 02:34:09 2481] DEBUG (XendDomain:464) Adding Domain: 30
[2010-10-08 02:34:09 2481] DEBUG (XendDomainInfo:2818) 
XendDomainInfo.initDomain: 30 256
[2010-10-08 02:34:09 2481] DEBUG (XendDomainInfo:2845) 
_initDomain:shadow_memory=0x0, memory_static_max=0x1f7900000, 
memory_static_min=0x0.
[2010-10-08 02:34:09 2481] INFO (image:182) buildDomain os=linux dom=30 vcpus=4
[2010-10-08 02:34:09 2481] DEBUG (image:721) domid          = 30
[2010-10-08 02:34:09 2481] DEBUG (image:722) memsize        = 500
[2010-10-08 02:34:09 2481] DEBUG (image:723) image          = /tmp/vmlinuz.WelUc
[2010-10-08 02:34:09 2481] DEBUG (image:724) store_evtchn   = 1
[2010-10-08 02:34:09 2481] DEBUG (image:725) console_evtchn = 2
[2010-10-08 02:34:09 2481] DEBUG (image:726) cmdline        = 
[2010-10-08 02:34:09 2481] DEBUG (image:727) ramdisk        = 
/tmp/initrd.gz.WelUc
[2010-10-08 02:34:09 2481] DEBUG (image:728) vcpus          = 4
[2010-10-08 02:34:09 2481] DEBUG (image:729) features       = 
[2010-10-08 02:34:09 2481] DEBUG (image:730) flags          = 0
[2010-10-08 02:34:09 2481] DEBUG (image:731) superpages     = 0
[2010-10-08 02:34:10 2481] INFO (XendDomainInfo:2367) createDevice: vbd : 
{'uuid': '7e7e9d2f-a176-2c11-92a4-f90e1e09a1f6', 'bootable': 1, 'driver': 
'paravirtualised', 'dev': 'xvda', 'uname': 
'tap:tapdisk:/distributed/vms/29567/disk.img', 'mode': 'w'}
[2010-10-08 02:34:10 2481] DEBUG (DevController:95) DevController: writing 
{'virtual-device': '51712', 'device-type': 'disk', 'protocol': 'x86_64-abi', 
'backend-id': '0', 'state': '1', 'backend': 
'/local/domain/0/backend/vbd/30/51712'} to /local/domain/30/device/vbd/51712.
[2010-10-08 02:34:10 2481] DEBUG (DevController:97) DevController: writing 
{'domain': 'vmprovision.testdomain.net', 'frontend': 
'/local/domain/30/device/vbd/51712', 'uuid': 
'7e7e9d2f-a176-2c11-92a4-f90e1e09a1f6', 'bootable': '1', 'dev': 'xvda', 
'state': '1', 'params': 'tapdisk:/distributed/vms/29567/disk.img', 'mode': 'w', 
'online': '1', 'frontend-id': '30', 'type': 'tap'} to 
/local/domain/0/backend/vbd/30/51712.
[2010-10-08 02:34:10 2481] INFO (XendDomainInfo:2367) createDevice: vbd : 
{'uuid': '909d2c77-576a-92d4-d7fc-117352f3febe', 'bootable': 0, 'driver': 
'paravirtualised', 'dev': 'xvdb', 'uname': 
'phy:/dev/VMSwapParts/vmprovision.testdomain.net', 'mode': 'w'}
[2010-10-08 02:34:10 2481] DEBUG (DevController:95) DevController: writing 
{'virtual-device': '51728', 'device-type': 'disk', 'protocol': 'x86_64-abi', 
'backend-id': '0', 'state': '1', 'backend': 
'/local/domain/0/backend/vbd/30/51728'} to /local/domain/30/device/vbd/51728.
[2010-10-08 02:34:10 2481] DEBUG (DevController:97) DevController: writing 
{'domain': 'vmprovision.testdomain.net', 'frontend': 
'/local/domain/30/device/vbd/51728', 'uuid': 
'909d2c77-576a-92d4-d7fc-117352f3febe', 'bootable': '0', 'dev': 'xvdb', 
'state': '1', 'params': '/dev/VMSwapParts/vmprovision.testdomain.net', 'mode': 
'w', 'online': '1', 'frontend-id': '30', 'type': 'phy'} to 
/local/domain/0/backend/vbd/30/51728.
[2010-10-08 02:34:10 2481] INFO (XendDomainInfo:2367) createDevice: vif : 
{'bridge': 'xenbr0', 'mac': '02:00:00:01:cd:fc', 'uuid': 
'b444b3f2-a360-4a81-74b8-5e1d9c16ab13', 'script': 'vif-bridge'}
[2010-10-08 02:34:10 2481] DEBUG (DevController:95) DevController: writing 
{'mac': '02:00:00:01:cd:fc', 'handle': '0', 'protocol': 'x86_64-abi', 
'backend-id': '0', 'state': '1', 'backend': '/local/domain/0/backend/vif/30/0'} 
to /local/domain/30/device/vif/0.
[2010-10-08 02:34:10 2481] DEBUG (DevController:97) DevController: writing 
{'bridge': 'xenbr0', 'domain': 'vmprovision.testdomain.net', 'handle': '0', 
'uuid': 'b444b3f2-a360-4a81-74b8-5e1d9c16ab13', 'script': 
'/etc/xen/scripts/vif-bridge', 'mac': '02:00:00:01:cd:fc', 'frontend-id': '30', 
'state': '1', 'online': '1', 'frontend': '/local/domain/30/device/vif/0'} to 
/local/domain/0/backend/vif/30/0.
[2010-10-08 02:34:10 2481] INFO (XendDomainInfo:2367) createDevice: vif : 
{'bridge': 'vlanbr338', 'mac': '02:00:00:01:cd:fd', 'uuid': 
'190b64aa-fb9a-e6de-fc07-b32b4a254588', 'script': 'vif-bridge-vlan'}
[2010-10-08 02:34:10 2481] DEBUG (DevController:95) DevController: writing 
{'mac': '02:00:00:01:cd:fd', 'handle': '1', 'protocol': 'x86_64-abi', 
'backend-id': '0', 'state': '1', 'backend': '/local/domain/0/backend/vif/30/1'} 
to /local/domain/30/device/vif/1.
[2010-10-08 02:34:10 2481] DEBUG (DevController:97) DevController: writing 
{'bridge': 'vlanbr338', 'domain': 'vmprovision.testdomain.net', 'handle': '1', 
'uuid': '190b64aa-fb9a-e6de-fc07-b32b4a254588', 'script': 
'/etc/xen/scripts/vif-bridge-vlan', 'mac': '02:00:00:01:cd:fd', 'frontend-id': 
'30', 'state': '1', 'online': '1', 'frontend': '/local/domain/30/device/vif/1'} 
to /local/domain/0/backend/vif/30/1.
[2010-10-08 02:34:10 2481] DEBUG (XendDomainInfo:3400) Storing VM details: 
{'on_xend_stop': 'ignore', 'shadow_memory': '0', 'uuid': 
'29afdd70-8030-db14-f318-d512a43d2d76', 'on_reboot': 'destroy', 'start_time': 
'1286523250.48', 'on_poweroff': 'destroy', 'bootloader_args': '', 
'on_xend_start': 'ignore', 'on_crash': 'preserve', 'xend/restart_count': '0', 
'vcpus': '4', 'vcpu_avail': '15', 'bootloader': '', 'image': "(linux (kernel 
/tmp/vmlinuz.WelUc) (ramdisk /tmp/initrd.gz.WelUc) (superpages 0) (tsc_mode 0) 
(pci ()) (nomigrate 0) (notes (HV_START_LOW 18446603336221196288) (FEATURES 
'!writable_page_tables|pae_pgdir_above_4gb') (VIRT_BASE 18446744071562067968) 
(GUEST_VERSION 2.6) (PADDR_OFFSET 0) (GUEST_OS linux) (HYPERCALL_PAGE 
18446744071578882048) (LOADER generic) (SUSPEND_CANCEL 1) (PAE_MODE yes) (ENTRY 
18446744071587533312) (XEN_VERSION xen-3.0)))", 'name': 
'vmprovision.testdomain.net'}
[2010-10-08 02:34:10 2481] DEBUG (XendDomainInfo:1804) Storing domain details: 
{'console/ring-ref': '2200931', 'image/entry': '18446744071587533312', 
'console/port': '2', 'cpu/3/availability': 'online', 'store/ring-ref': 
'2200932', 'image/loader': 'generic', 'vm': 
'/vm/29afdd70-8030-db14-f318-d512a43d2d76', 
'control/platform-feature-multiprocessor-suspend': '1', 'image/hv-start-low': 
'18446603336221196288', 'description': 'VM ID 29567 Uber ID 173687', 
'cpu/2/availability': 'online', 'cpu/1/availability': 'online', 
'image/virt-base': '18446744071562067968', 'memory/target': '512000', 
'image/guest-version': '2.6', 'image/pae-mode': 'yes', 'image/guest-os': 
'linux', 'console/limit': '1048576', 'image/paddr-offset': '0', 
'image/hypercall-page': '18446744071578882048', 'image/suspend-cancel': '1', 
'cpu/0/availability': 'online', 'image/features/pae-pgdir-above-4gb': '1', 
'image/features/writable-page-tables': '0', 'console/type': 'xenconsoled', 
'name': 'vmprovision.testdomain.net', 'domid': '30', 'image/xen-version': 
'xen-3.0', 'store/port': '1'}
[2010-10-08 02:34:10 2481] DEBUG (DevController:95) DevController: writing 
{'protocol': 'x86_64-abi', 'state': '1', 'backend-id': '0', 'backend': 
'/local/domain/0/backend/console/30/0'} to /local/domain/30/device/console/0.
[2010-10-08 02:34:10 2481] DEBUG (DevController:97) DevController: writing 
{'domain': 'vmprovision.testdomain.net', 'frontend': 
'/local/domain/30/device/console/0', 'uuid': 
'aa279c46-47df-7512-3655-7fcea7402d02', 'frontend-id': '30', 'state': '1', 
'location': '2', 'online': '1', 'protocol': 'vt100'} to 
/local/domain/0/backend/console/30/0.
[2010-10-08 02:34:10 2481] DEBUG (XendDomainInfo:1891) 
XendDomainInfo.handleShutdownWatch
[2010-10-08 02:34:11 2481] DEBUG (DevController:139) Waiting for devices vif2.
[2010-10-08 02:34:11 2481] DEBUG (DevController:139) Waiting for devices vif.
[2010-10-08 02:34:11 2481] DEBUG (DevController:144) Waiting for 0.
[2010-10-08 02:34:11 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vif/30/0/hotplug-status.
[2010-10-08 02:34:11 2481] DEBUG (DevController:642) hotplugStatusCallback 1.
[2010-10-08 02:34:11 2481] DEBUG (DevController:144) Waiting for 1.
[2010-10-08 02:34:11 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vif/30/1/hotplug-status.
[2010-10-08 02:34:11 2481] DEBUG (DevController:642) hotplugStatusCallback 1.
[2010-10-08 02:34:11 2481] DEBUG (DevController:139) Waiting for devices vscsi.
[2010-10-08 02:34:11 2481] DEBUG (DevController:139) Waiting for devices vbd.
[2010-10-08 02:34:11 2481] DEBUG (DevController:144) Waiting for 51712.
[2010-10-08 02:34:11 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/30/51712/hotplug-status.
[2010-10-08 02:35:51 2481] ERROR (SrvBase:88) Request wait_for_devices failed.
Traceback (most recent call last):
  File "/usr/lib/xen-4.0/lib/python/xen/web/SrvBase.py", line 85, in perform
    return op_method(op, req)
  File "/usr/lib/xen-4.0/lib/python/xen/xend/server/SrvDomain.py", line 85, in 
op_wait_for_devices
    return self.dom.waitForDevices()
  File "/usr/lib/xen-4.0/lib/python/xen/xend/XendDomainInfo.py", line 1247, in 
waitForDevices
    self.getDeviceController(devclass).waitForDevices()
  File "/usr/lib/xen-4.0/lib/python/xen/xend/server/DevController.py", line 
140, in waitForDevices
    return map(self.waitForDevice, self.deviceIDs())
  File "/usr/lib/xen-4.0/lib/python/xen/xend/server/DevController.py", line 
155, in waitForDevice
    (devid, self.deviceClass))
VmError: Device 51712 (vbd) could not be connected. Hotplug scripts not working.
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:3053) XendDomainInfo.destroy: 
domid=30
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2411) Destroying device model
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2418) Releasing devices
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2424) Removing vif/0
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:1286) 
XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2424) Removing vif/1
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:1286) 
XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/1
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2424) Removing vbd/51712
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:1286) 
XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/51712
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2424) Removing vbd/51728
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:1286) 
XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/51728
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2424) Removing console/0
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:1286) 
XendDomainInfo.destroyDevice: deviceClass = console, device = console/0
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2416) No device model
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2418) Releasing devices
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2424) Removing vif/0
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:1286) 
XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2424) Removing vif/1
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:1286) 
XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/1
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2424) Removing vbd/51712
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:1286) 
XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/51712
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:2424) Removing vbd/51728
[2010-10-08 02:35:51 2481] DEBUG (XendDomainInfo:1286) 
XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/51728
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/30/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/30/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/7/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/8/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/9/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/17/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/18/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/19/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/20/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/21/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/22/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/23/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/24/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/25/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/26/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/27/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/28/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/29/51712/hotplug-status.
[2010-10-08 02:35:51 2481] DEBUG (DevController:628) hotplugStatusCallback 
/local/domain/0/backend/vbd/30/51712/hotplug-status.

Attachment: signature.asc
Description: Digital signature

_______________________________________________
Xen-users mailing list
Xen-users@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/xen-users
[More with this subject...]
<Prev in Thread] Current Thread [Next in Thread>
  • [Xen-users] hotplug scripts not working, Igor Serebryany <=
Previous by Date:  [Xen-users] error during installation of XCP, Péter Somogyvári
Next by Date:  [Xen-users] VT-d with P6T Deluxe, Thomas Jepp
Previous by Thread:  [Xen-users] error during installation of XCP, Péter Somogyvári
Next by Thread:  [Xen-users] VT-d with P6T Deluxe, Thomas Jepp
Indexes:  [Date] [Thread] [Top] [All Lists]
 
   

Copyright , Citrix Systems Inc. All rights reserved. Legal and Privacy