[one-users] Nebula 4.0.1 Xen 4.1.4 Debian Wheezy - VM stuck in BOOT state

Javier Fontan jfontan at opennebula.org
Wed Jun 5 03:44:52 PDT 2013


What is the network driver you are using in that host? Can you do the
same test using network dummy drivers if you are using other driver?

On Wed, Jun 5, 2013 at 9:16 AM, Jacek Jarosiewicz <nebula at supermedia.pl> wrote:
> Hi,
>
> I've searched google and this list but with no luck..
>
> I have setup an opennebula cloud (4.0.1) with xen (4.1) on debian wheezy. My
> problem is that vm's are deployed correctly (vm is running, networking is
> set up, I can ssh to it, run programs within it etc.) but opennebula shows
> vm stuck in boot state and i can't do anything with it from either sunstone
> nor with the onevm command.
>
> I can only delete the vm.
>
> The VM is debian squeeze from marketplace (
> http://marketplace.c12g.com/appliance/4fec9fb28fb81d2ebc000002 )
>
> no errors in oned.log - only monitoring stuff.. any help is appreciated!
>
> The deployment.0 file is:
>
> name = 'one-19'
> memory  = '2048'
> vcpus  = '1'
> bootloader = "/usr/lib/xen-4.1/bin/pygrub"
> disk = [
>     'tap2:tapdisk:aio:/var/lib/one//datastores/0/19/disk.0,xvda,w',
>     'tap2:tapdisk:aio:/var/lib/one//datastores/0/19/disk.1,xvdb,r',
> ]
> vif = [
>     ' mac=02:00:12:a8:01:0a,ip=192.168.1.10,bridge=br0',
> ]
> vfb = ['type=vnc,vnclisten=0.0.0.0,vncdisplay=19']
> device_model = '/usr/lib/xen-4.1/bin/qemu-dm'
>
> xm list command output:
>
> root at nebula1:/var/log/xen# xm list
> Name                                        ID   Mem VCPUs      State
> Time(s)
> Domain-0                                     0  1023     4     r----- 1194.4
> one-19                                       5  2048     1     -b----    1.7
>
>
> onevm list command output:
>
> oneadmin at nebula0:~$ onevm list
>     ID USER     GROUP    NAME            STAT UCPU    UMEM HOST      TIME
>     19 oneadmin oneadmin deb1            boot    0      2G nebula1  0d 01h05
>
>
> vm log:
>
> Wed Jun  5 08:09:59 2013 [DiM][I]: New VM state is ACTIVE.
> Wed Jun  5 08:09:59 2013 [LCM][I]: New VM state is PROLOG.
> Wed Jun  5 08:13:20 2013 [LCM][E]: monitor_done_action, VM in a wrong state
> Wed Jun  5 08:18:37 2013 [LCM][E]: monitor_done_action, VM in a wrong state
> Wed Jun  5 08:22:26 2013 [TM][I]: clone: Cloning
> nebula0:/var/lib/one/datastores/1/78b6cd5fe55967f183d9eabfd9cd7a28 in
> /var/lib/one/datastores/0/19/disk.0
> Wed Jun  5 08:22:26 2013 [TM][I]: ExitCode: 0
> Wed Jun  5 08:22:27 2013 [TM][I]: context: Generating context block device
> at nebula1:/var/lib/one//datastores/0/19/disk.1
> Wed Jun  5 08:22:27 2013 [TM][I]: ExitCode: 0
> Wed Jun  5 08:22:27 2013 [LCM][I]: New VM state is BOOT
> Wed Jun  5 08:22:27 2013 [VMM][I]: Generating deployment file:
> /var/lib/one/vms/19/deployment.0
> Wed Jun  5 08:22:28 2013 [VMM][I]: ExitCode: 0
> Wed Jun  5 08:22:28 2013 [VMM][I]: Successfully execute network driver
> operation: pre.
> Wed Jun  5 08:22:31 2013 [VMM][D]: deploy: Credits set to 256
> Wed Jun  5 08:22:31 2013 [VMM][I]: ExitCode: 0
> Wed Jun  5 08:22:31 2013 [VMM][I]: Successfully execute virtualization
> driver operation: deploy.
>
> xend.log:
>
> [2013-06-05 08:22:31 2847] DEBUG (XendDomainInfo:103)
> XendDomainInfo.create(['vm', ['name', 'one-19'], ['memory', '2048'],
> ['on_xend_start', 'ignore'], ['on_xend_stop', 'ignore'], ['vcpus', '1'],
> ['oos', 1], ['bootloader', '/usr/lib/xen-4.1/bin/pygrub'],
> ['bootloader_args', '-q'], ['image', ['linux', ['videoram', 4], ['tsc_mode',
> 0], ['nomigrate', 0]]], ['s3_integrity', 1], ['device', ['tap2', ['uname',
> 'tap2:tapdisk:aio:/var/lib/one//datastores/0/19/disk.0'], ['dev', 'xvda'],
> ['mode', 'w']]], ['device', ['tap2', ['uname',
> 'tap2:tapdisk:aio:/var/lib/one//datastores/0/19/disk.1'], ['dev', 'xvdb'],
> ['mode', 'r']]], ['device', ['vif', ['ip', '192.168.1.10'], ['mac',
> '02:00:12:a8:01:0a'], ['bridge', 'br0']]], ['device', ['vkbd']], ['device',
> ['vfb', ['vnc', '1'], ['vnclisten', '0.0.0.0'], ['vncdisplay', '19'],
> ['xauthority', '/root/.Xauthority']]]])
> [2013-06-05 08:22:31 2847] DEBUG (XendDomainInfo:2498)
> XendDomainInfo.constructDomain
> [2013-06-05 08:22:31 2847] DEBUG (balloon:187) Balloon: 3089336 KiB free;
> need 16384; done.
> [2013-06-05 08:22:31 2847] DEBUG (XendDomain:476) Adding Domain: 3
> [2013-06-05 08:22:31 2847] DEBUG (XendDomainInfo:2836)
> XendDomainInfo.initDomain: 3 256
> [2013-06-05 08:22:31 21477] DEBUG (XendBootloader:113) Launching bootloader
> as ['/usr/lib/xen-4.1/bin/pygrub',
> '--output=/var/run/xend/boot/xenbl.11474', '-q',
> '/var/lib/one//datastores/0/19/disk.0'].
> [2013-06-05 08:22:32 2847] DEBUG (image:339) No VNC passwd configured for
> vfb access
> [2013-06-05 08:22:32 2847] DEBUG (XendDomainInfo:2863)
> _initDomain:shadow_memory=0x0, memory_static_max=0x80000000,
> memory_static_min=0x0.
> [2013-06-05 08:22:32 2847] INFO (image:182) buildDomain os=linux dom=3
> vcpus=1
> [2013-06-05 08:22:32 2847] DEBUG (image:721) domid          = 3
> [2013-06-05 08:22:32 2847] DEBUG (image:722) memsize        = 2048
> [2013-06-05 08:22:32 2847] DEBUG (image:723) image          =
> /var/run/xend/boot/boot_kernel.Nu5QrO
> [2013-06-05 08:22:32 2847] DEBUG (image:724) store_evtchn   = 1
> [2013-06-05 08:22:32 2847] DEBUG (image:725) console_evtchn = 2
> [2013-06-05 08:22:32 2847] DEBUG (image:726) cmdline        =
> root=UUID=5309b3f9-2b10-40a4-aa03-0ff45a6dab7f ro  quiet
> [2013-06-05 08:22:32 2847] DEBUG (image:727) ramdisk        =
> /var/run/xend/boot/boot_ramdisk.MvCdMG
> [2013-06-05 08:22:32 2847] DEBUG (image:728) vcpus          = 1
> [2013-06-05 08:22:32 2847] DEBUG (image:729) features       =
> [2013-06-05 08:22:32 2847] DEBUG (image:730) flags          = 0
> [2013-06-05 08:22:32 2847] DEBUG (image:731) superpages     = 0
> [2013-06-05 08:22:32 2847] INFO (XendDomainInfo:2357) createDevice: vkbd :
> {'uuid': '51fad786-2987-9721-5297-2f5b4251f823'}
> [2013-06-05 08:22:32 2847] DEBUG (DevController:95) DevController: writing
> {'protocol': 'x86_64-abi', 'state': '1', 'backend-id': '0', 'backend':
> '/local/domain/0/backend/vkbd/3/0'} to /local/domain/3/device/vkbd/0.
> [2013-06-05 08:22:32 2847] DEBUG (DevController:97) DevController: writing
> {'frontend-id': '3', 'domain': 'one-19', 'frontend':
> '/local/domain/3/device/vkbd/0', 'state': '1', 'online': '1'} to
> /local/domain/0/backend/vkbd/3/0.
> [2013-06-05 08:22:32 2847] INFO (XendDomainInfo:2357) createDevice: vfb :
> {'other_config': {'vnclisten': '0.0.0.0', 'vnc': '1', 'vncdisplay': '19',
> 'xauthority': '/root/.Xauthority'}, 'vnc': '1', 'xauthority':
> '/root/.Xauthority', 'vnclisten': '0.0.0.0', 'vncdisplay': '19', 'uuid':
> '798de277-63b4-ff7a-e166-9e230c9e5934'}
> [2013-06-05 08:22:32 2847] DEBUG (DevController:95) DevController: writing
> {'protocol': 'x86_64-abi', 'state': '1', 'backend-id': '0', 'backend':
> '/local/domain/0/backend/vfb/3/0'} to /local/domain/3/device/vfb/0.
> [2013-06-05 08:22:32 2847] DEBUG (DevController:97) DevController: writing
> {'domain': 'one-19', 'frontend': '/local/domain/3/device/vfb/0', 'uuid':
> '798de277-63b4-ff7a-e166-9e230c9e5934', 'frontend-id': '3', 'vnclisten':
> '0.0.0.0', 'vncdisplay': '19', 'state': '1', 'online': '1', 'vnc': '1',
> 'xauthority': '/root/.Xauthority'} to /local/domain/0/backend/vfb/3/0.
> [2013-06-05 08:22:32 2847] INFO (XendDomainInfo:2357) createDevice: tap2 :
> {'bootable': 1, 'uname':
> 'tap2:tapdisk:aio:/var/lib/one//datastores/0/19/disk.0', 'mode': 'w', 'dev':
> 'xvda', 'uuid': '05ff560d-4e79-1b48-1af8-9885fa82ada7'}
> [2013-06-05 08:22:32 2847] 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/3/51712'} to /local/domain/3/device/vbd/51712.
> [2013-06-05 08:22:32 2847] DEBUG (DevController:97) DevController: writing
> {'domain': 'one-19', 'frontend': '/local/domain/3/device/vbd/51712', 'uuid':
> '05ff560d-4e79-1b48-1af8-9885fa82ada7', 'bootable': '1', 'dev': 'xvda',
> 'state': '1', 'params': '/dev/xen/blktap-2/tapdev0', 'mode': 'w', 'online':
> '1', 'frontend-id': '3', 'type': 'phy', 'tapdisk-params':
> 'tapdisk:aio:/var/lib/one//datastores/0/19/disk.0'} to
> /local/domain/0/backend/vbd/3/51712.
> [2013-06-05 08:22:32 2847] INFO (XendDomainInfo:2357) createDevice: tap2 :
> {'bootable': 0, 'uname':
> 'tap2:tapdisk:aio:/var/lib/one//datastores/0/19/disk.1', 'mode': 'r', 'dev':
> 'xvdb', 'uuid': '29791995-b50e-0d36-d941-c0941ba1c95c'}
> [2013-06-05 08:22:32 2847] 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/3/51728'} to /local/domain/3/device/vbd/51728.
> [2013-06-05 08:22:32 2847] DEBUG (DevController:97) DevController: writing
> {'domain': 'one-19', 'frontend': '/local/domain/3/device/vbd/51728', 'uuid':
> '29791995-b50e-0d36-d941-c0941ba1c95c', 'bootable': '0', 'dev': 'xvdb',
> 'state': '1', 'params': '/dev/xen/blktap-2/tapdev1', 'mode': 'r', 'online':
> '1', 'frontend-id': '3', 'type': 'phy', 'tapdisk-params':
> 'tapdisk:aio:/var/lib/one//datastores/0/19/disk.1'} to
> /local/domain/0/backend/vbd/3/51728.
> [2013-06-05 08:22:32 2847] INFO (XendDomainInfo:2357) createDevice: vif :
> {'ip': '192.168.1.10', 'mac': '02:00:12:a8:01:0a', 'uuid':
> 'a41816d8-c751-72e0-2d0e-98b09fba4212', 'bridge': 'br0'}
> [2013-06-05 08:22:32 2847] DEBUG (DevController:95) DevController: writing
> {'mac': '02:00:12:a8:01:0a', 'handle': '0', 'protocol': 'x86_64-abi',
> 'backend-id': '0', 'state': '1', 'backend':
> '/local/domain/0/backend/vif/3/0'} to /local/domain/3/device/vif/0.
> [2013-06-05 08:22:32 2847] DEBUG (DevController:97) DevController: writing
> {'bridge': 'br0', 'domain': 'one-19', 'handle': '0', 'uuid':
> 'a41816d8-c751-72e0-2d0e-98b09fba4212', 'script':
> '/etc/xen/scripts/vif-openvswitch', 'ip': '192.168.1.10', 'mac':
> '02:00:12:a8:01:0a', 'frontend-id': '3', 'state': '1', 'online': '1',
> 'frontend': '/local/domain/3/device/vif/0'} to
> /local/domain/0/backend/vif/3/0.
> [2013-06-05 08:22:32 2847] INFO (image:418) spawning device models:
> /usr/lib/xen-4.1/bin/qemu-dm ['/usr/lib/xen-4.1/bin/qemu-dm', '-d', '3',
> '-serial', 'pty', '-domain-name', 'one-19', '-videoram', '4', '-vnc',
> '0.0.0.0:19', '-vncunused', '-M', 'xenpv']
> [2013-06-05 08:22:32 2847] INFO (image:467) device model pid: 21522
> [2013-06-05 08:22:32 2847] INFO (image:590) waiting for sentinel_fifo
> [2013-06-05 08:22:32 2847] DEBUG (XendDomainInfo:3420) Storing VM details:
> {'on_xend_stop': 'ignore', 'pool_name': 'Pool-0', 'shadow_memory': '0',
> 'uuid': 'b64f31a0-357e-8ce3-17e9-77ce159d67eb', 'on_reboot': 'restart',
> 'start_time': '1370413352.7', 'on_poweroff': 'destroy', 'bootloader_args':
> '-q', 'on_xend_start': 'ignore', 'on_crash': 'restart',
> 'xend/restart_count': '0', 'vcpus': '1', 'vcpu_avail': '1', 'bootloader':
> '/usr/lib/xen-4.1/bin/pygrub', 'image': "(linux (kernel '') (superpages 0)
> (videoram 4) (pci ()) (nomigrate 0) (tsc_mode 0) (device_model
> /usr/lib/xen-4.1/bin/qemu-dm) (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 18446744071584203264) (XEN_VERSION xen-3.0)))",
> 'name': 'one-19'}
> [2013-06-05 08:22:32 2847] DEBUG (XendDomainInfo:1794) Storing domain
> details: {'console/ring-ref': '799913', 'image/entry':
> '18446744071584203264', 'console/port': '2', 'store/ring-ref': '799914',
> 'image/loader': 'generic', 'vm': '/vm/b64f31a0-357e-8ce3-17e9-77ce159d67eb',
> 'control/platform-feature-multiprocessor-suspend': '1',
> 'image/hv-start-low': '18446603336221196288', 'image/guest-os': 'linux',
> 'image/virt-base': '18446744071562067968', 'memory/target': '2097152',
> 'image/guest-version': '2.6', 'image/pae-mode': 'yes', 'description': '',
> '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': 'ioemu', 'name':
> 'one-19', 'domid': '3', 'image/xen-version': 'xen-3.0', 'store/port': '1'}
> [2013-06-05 08:22:32 2847] DEBUG (DevController:95) DevController: writing
> {'protocol': 'x86_64-abi', 'state': '1', 'backend-id': '0', 'backend':
> '/local/domain/0/backend/console/3/0'} to /local/domain/3/device/console/0.
> [2013-06-05 08:22:32 2847] DEBUG (DevController:97) DevController: writing
> {'domain': 'one-19', 'frontend': '/local/domain/3/device/console/0', 'uuid':
> '1d1d7212-114e-5715-55b0-dd12377f16d1', 'frontend-id': '3', 'state': '1',
> 'location': '2', 'online': '1', 'protocol': 'vt100'} to
> /local/domain/0/backend/console/3/0.
> [2013-06-05 08:22:32 2847] DEBUG (XendDomainInfo:1881)
> XendDomainInfo.handleShutdownWatch
> [2013-06-05 08:22:32 2847] DEBUG (DevController:139) Waiting for devices
> tap2.
> [2013-06-05 08:22:32 2847] DEBUG (DevController:144) Waiting for 51712.
> [2013-06-05 08:22:32 2847] DEBUG (DevController:628) hotplugStatusCallback
> /local/domain/0/backend/vbd/3/51712/hotplug-status.
> [2013-06-05 08:22:33 2847] DEBUG (DevController:628) hotplugStatusCallback
> /local/domain/0/backend/vbd/3/51712/hotplug-status.
> [2013-06-05 08:22:33 2847] DEBUG (DevController:642) hotplugStatusCallback
> 1.
> [2013-06-05 08:22:33 2847] DEBUG (DevController:144) Waiting for 51728.
> [2013-06-05 08:22:33 2847] DEBUG (DevController:628) hotplugStatusCallback
> /local/domain/0/backend/vbd/3/51728/hotplug-status.
> [2013-06-05 08:22:33 2847] DEBUG (DevController:628) hotplugStatusCallback
> /local/domain/0/backend/vbd/3/51728/hotplug-status.
> [2013-06-05 08:22:33 2847] DEBUG (DevController:642) hotplugStatusCallback
> 1.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> vif.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:144) Waiting for 0.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:628) hotplugStatusCallback
> /local/domain/0/backend/vif/3/0/hotplug-status.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:642) hotplugStatusCallback
> 1.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> vkbd.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> ioports.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> tap.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> vif2.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> console.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:144) Waiting for 0.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> vscsi.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> vbd.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> irq.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> vfb.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> pci.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> vusb.
> [2013-06-05 08:22:34 2847] DEBUG (DevController:139) Waiting for devices
> vtpm.
> [2013-06-05 08:22:34 2847] INFO (XendDomain:1225) Domain one-19 (3)
> unpaused.
> [2013-06-05 08:22:34 2847] WARNING (XendDomainInfo:581) Could not unpause
> blktap disk: ('unpause', '-p21487', '-m0') failed (5632  )
>
> Cheers,
> J
>
> --
> Jacek Jarosiewicz
> _______________________________________________
> Users mailing list
> Users at lists.opennebula.org
> http://lists.opennebula.org/listinfo.cgi/users-opennebula.org



-- 
Join us at OpenNebulaConf2013 in Berlin from the 24th to the 26th of
September 2013!

Javier Fontán Muiños
Project Engineer
OpenNebula - The Open Source Toolkit for Data Center Virtualization
www.OpenNebula.org | jfontan at opennebula.org | @OpenNebula



More information about the Users mailing list