[one-users] VMs hang in pending state

[Sander Klous]

Hi,

My VMs are hanging in pending state. When I force a deploy, they are 
going directly from 'pending' to 'failed' state. The files are created 
in the correct location (/opt/opennebula/var/<NR>). Running the 
deployment script in that directory by hand works fine with the line 
found in vm.log (changing \&\& into &&):

sudo /usr/sbin/xm create /opt/opennebula/var//11/images/deployment.0 && 
sudo /usr/sbin/xm sched-cred -d one-11 -w 256

Here are some details:
- opennebula runs on a centos-5 system.
- one machine serves 3 purposes:
  * opennebula head node
  * VM image repository
  * VM host, with xen-3.0

Scripts/log files below this mail.
Any ideas?
Thanks,
Sander

This is the deployment.0 script

name = 'one-11'
#O CPU_CREDITS = 256
memory  = '128'
kernel = '/xen/centos-5.i386/vmlinuz-2.6.18-128.1.16.el5xen'
ramdisk = '/xen/centos-5.i386/initrd-2.6.18-128.1.16.el5xen-custom.img'
root = '/dev/sda2'
disk = [
    'tap:aio:/opt/opennebula/var//11/images/disk.0,sda1,w',
    'tap:aio:/opt/opennebula/var//11/images/disk.1,sda2,w',
]
vif = [
    'mac=00:16:3e:ab:60:3a,bridge=xenbr0',
]

The relevant part of the oned.log, followed by the vm.log:
--------------------------------------------------
Tue Jul 21 12:35:01 2009 [TM][D]: Message received: LOG - 11 
tm_mkswap.sh: Creating 512Mb image in /opt/opennebula/var//11/images/disk.0

Tue Jul 21 12:35:01 2009 [TM][D]: Message received: LOG - 11 
tm_mkswap.sh: Executed "ssh aulnes mkdir -p /opt/opennebula/var//11/images".

Tue Jul 21 12:35:01 2009 [TM][D]: Message received: LOG - 11 
tm_mkswap.sh: Executed "ssh aulnes dd if=/dev/zero 
of=/opt/opennebula/var//11/images/disk.0 bs=1
 count=1 seek=512M".

Tue Jul 21 12:35:01 2009 [TM][D]: Message received: LOG - 11 
tm_mkswap.sh: Initializing swap space

Tue Jul 21 12:35:01 2009 [TM][D]: Message received: LOG - 11 
tm_mkswap.sh: Executed "ssh aulnes /sbin/mkswap 
/opt/opennebula/var//11/images/disk.0".

Tue Jul 21 12:35:01 2009 [TM][D]: Message received: LOG - 11 
tm_mkswap.sh: Executed "ssh aulnes chmod a+w 
/opt/opennebula/var//11/images/disk.0".

Tue Jul 21 12:35:02 2009 [InM][I]: Monitoring host arrone (0)
Tue Jul 21 12:35:02 2009 [TM][D]: Message received: LOG - 11 
tm_clone.sh: aulnes.nikhef.nl:/opt/opennebula/images/centos-5.i386.img 
aulnes:/opt/opennebula/va
r//11/images/disk.1

Tue Jul 21 12:35:02 2009 [TM][D]: Message received: LOG - 11 
tm_clone.sh: DST: /opt/opennebula/var//11/images/disk.1

Tue Jul 21 12:35:02 2009 [TM][D]: Message received: LOG - 11 
tm_clone.sh: Creating directory /opt/opennebula/var//11/images

Tue Jul 21 12:35:02 2009 [InM][I]: Monitoring host aulnes (1)
Tue Jul 21 12:35:02 2009 [TM][D]: Message received: LOG - 11 
tm_clone.sh: Executed "ssh aulnes mkdir -p /opt/opennebula/var//11/images".

Tue Jul 21 12:35:02 2009 [TM][D]: Message received: LOG - 11 
tm_clone.sh: Cloning 
aulnes.nikhef.nl:/opt/opennebula/images/centos-5.i386.img
-------------------------------------------------
Tue Jul 21 12:35:01 2009 [DiM][I]: New VM state is ACTIVE.
Tue Jul 21 12:35:01 2009 [LCM][I]: New VM state is PROLOG.
Tue Jul 21 12:35:01 2009 [TM][I]: tm_mkswap.sh: Creating 512Mb image in 
/opt/opennebula/var//11/images/disk.0
Tue Jul 21 12:35:01 2009 [TM][I]: tm_mkswap.sh: Executed "ssh aulnes 
mkdir -p /opt/opennebula/var//11/images".
Tue Jul 21 12:35:01 2009 [TM][I]: tm_mkswap.sh: Executed "ssh aulnes dd 
if=/dev/zero of=/opt/opennebula/var//11/images/disk.0 bs=1 count=1 
seek=512M".
Tue Jul 21 12:35:01 2009 [TM][I]: tm_mkswap.sh: Initializing swap space
Tue Jul 21 12:35:01 2009 [TM][I]: tm_mkswap.sh: Executed "ssh aulnes 
/sbin/mkswap /opt/opennebula/var//11/images/disk.0".
Tue Jul 21 12:35:01 2009 [TM][I]: tm_mkswap.sh: Executed "ssh aulnes 
chmod a+w /opt/opennebula/var//11/images/disk.0".
Tue Jul 21 12:35:02 2009 [TM][I]: tm_clone.sh: 
aulnes.nikhef.nl:/opt/opennebula/images/centos-5.i386.img 
aulnes:/opt/opennebula/var//11/images/disk.1
Tue Jul 21 12:35:02 2009 [TM][I]: tm_clone.sh: DST: 
/opt/opennebula/var//11/images/disk.1
Tue Jul 21 12:35:02 2009 [TM][I]: tm_clone.sh: Creating directory 
/opt/opennebula/var//11/images
Tue Jul 21 12:35:02 2009 [TM][I]: tm_clone.sh: Executed "ssh aulnes 
mkdir -p /opt/opennebula/var//11/images".
Tue Jul 21 12:35:02 2009 [TM][I]: tm_clone.sh: Cloning 
aulnes.nikhef.nl:/opt/opennebula/images/centos-5.i386.img
Tue Jul 21 12:35:39 2009 [TM][I]: tm_clone.sh: Executed "scp 
aulnes.nikhef.nl:/opt/opennebula/images/centos-5.i386.img 
aulnes:/opt/opennebula/var//11/images/disk.1".
Tue Jul 21 12:35:39 2009 [TM][I]: tm_clone.sh: Executed "ssh aulnes 
chmod a+w /opt/opennebula/var//11/images/disk.1".
Tue Jul 21 12:35:39 2009 [LCM][I]: New VM state is BOOT
Tue Jul 21 12:35:39 2009 [VMM][I]: Generating deployment file: 
/opt/opennebula/var/11/deployment.0
Tue Jul 21 12:35:39 2009 [VMM][I]: Command: scp 
/opt/opennebula/var/11/deployment.0 
aulnes:/opt/opennebula/var//11/images/deployment.0
Tue Jul 21 12:35:40 2009 [VMM][I]: Copy success
Tue Jul 21 12:35:40 2009 [VMM][I]: Setting credits for the VM
Tue Jul 21 12:35:40 2009 [VMM][I]: Command: sudo /usr/sbin/xm create 
/opt/opennebula/var//11/images/deployment.0 \&\& sudo /usr/sbin/xm 
sched-cred -d one-11 -w 256
Tue Jul 21 12:35:40 2009 [VMM][E]: Error deploying virtual machine: 
Unknown error
Tue Jul 21 12:35:40 2009 [LCM][I]: Fail to boot VM.
Tue Jul 21 12:35:40 2009 [DiM][I]: New VM state is FAILED