[one-users] Error creation VM

Héctor Sanjuán hsanjuan at opennebula.org
Sat Jul 9 16:46:43 PDT 2011


Hi, it's difficult to debug just from the log, if you can attach VM
template, Image(s) templates if existing that'd be great.

Still, from the log, for VM 29 I cant help noticing:

unable to set user and group to '105:114' on
'/var/lib/one/images/ttylinux/vmlinuz-xen': No such file or directory

does that file exist? Also sounds like youre trying to give a XEN kernel
to a machine supposed to run with KVM. Im not sure that can turn out right.

For VM 30,

internal error process exited while connecting to monitor: open
/dev/kvm: No such file or directory

is KVM loaded and supported by your processor? Does the oneadmin user
have permissions to use it?

Hector



El 09/07/11 21:25, Vincenzo Tilotta escribió:
>  Any Idea ?
> 
> DB=BACKEND=sqlite
> DEBUG_LEVEL=3
> DEFAULT_DEVICE_PREFIX=hd
> DEFAULT_IMAGE_TYPE=OS
> HM_MAD=EXECUTABLE=one_hm
> HOST_MONITORING_INTERVAL=600
> IMAGE_REPOSITORY_PATH=/var/lib/one//images
> IM_MAD=ARGUMENTS=kvm,EXECUTABLE=one_im_ssh,NAME=im_kvm
> MAC_PREFIX=02:00
> MANAGER_TIMER=15
> NETWORK_SIZE=254
> PORT=2633
> SCRIPTS_REMOTE_DIR=/var/tmp/one
> TM_MAD=ARGUMENTS=tm_ssh/tm_ssh.conf,EXECUTABLE=one_tm,NAME=tm_ssh
> VM_DIR=/var/lib/one/
> VM_HOOK=ARGUMENTS=$VMID,COMMAND=image.rb,NAME=image,ON=DONE
> VM_MAD=ARGUMENTS=kvm,DEFAULT=vmm_ssh/vmm_ssh_kvm.conf,EXECUTABLE=one_vmm_ssh,NAME=vmm_kvm,TYPE=kvm
> 
> VM_POLLING_INTERVAL=600
> VNC_BASE_PORT=5900
> ----------------------------------
> Sat Jul  9 20:51:37 2011 [ONE][I]: Bootstraping OpenNebula database.
> Sat Jul  9 20:51:37 2011 [VMM][I]: Starting Virtual Machine Manager...
> Sat Jul  9 20:51:37 2011 [LCM][I]: Starting Life-cycle Manager...
> Sat Jul  9 20:51:37 2011 [InM][I]: Starting Information Manager...
> Sat Jul  9 20:51:37 2011 [TrM][I]: Starting Transfer Manager...
> Sat Jul  9 20:51:37 2011 [DiM][I]: Starting Dispatch Manager...
> Sat Jul  9 20:51:37 2011 [ReM][I]: Starting Request Manager...
> Sat Jul  9 20:51:37 2011 [ReM][I]: Starting XML-RPC server, port 2633 ...
> Sat Jul  9 20:51:37 2011 [HKM][I]: Starting Hook Manager...
> Sat Jul  9 20:51:37 2011 [TrM][I]: Transfer Manager started.
> Sat Jul  9 20:51:37 2011 [DiM][I]: Dispatch Manager started.
> Sat Jul  9 20:51:37 2011 [ReM][I]: Request Manager started.
> Sat Jul  9 20:51:37 2011 [HKM][I]: Hook Manager started.
> Sat Jul  9 20:51:37 2011 [InM][I]: Information Manager started.
> Sat Jul  9 20:51:37 2011 [LCM][I]: Life-cycle Manager started.
> Sat Jul  9 20:51:37 2011 [VMM][I]: Virtual Machine Manager started.
> Sat Jul  9 20:51:39 2011 [VMM][I]: Loading Virtual Machine Manager drivers.
> Sat Jul  9 20:51:39 2011 [VMM][I]:     Loading driver: vmm_kvm (KVM)
> Sat Jul  9 20:51:39 2011 [VMM][I]:     Driver vmm_kvm loaded.
> Sat Jul  9 20:51:39 2011 [InM][I]: Loading Information Manager drivers.
> Sat Jul  9 20:51:39 2011 [InM][I]:     Loading driver: im_kvm
> Sat Jul  9 20:51:39 2011 [InM][I]:     Driver im_kvm loaded
> Sat Jul  9 20:51:39 2011 [TM][I]: Loading Transfer Manager drivers.
> Sat Jul  9 20:51:39 2011 [VMM][I]:     Loading driver: tm_ssh
> Sat Jul  9 20:51:39 2011 [TM][I]:     Driver tm_ssh loaded.
> Sat Jul  9 20:51:39 2011 [HKM][I]: Loading Hook Manager driver.
> Sat Jul  9 20:51:39 2011 [HKM][I]:     Hook Manager loaded
> Sat Jul  9 20:51:41 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:51:53 2011 [ReM][D]: HostInfo method invoked
> Sat Jul  9 20:51:53 2011 [ReM][D]: HostDelete method invoked
> Sat Jul  9 20:51:57 2011 [ReM][D]: HostAllocate method invoked
> Sat Jul  9 20:52:01 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:52:02 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:52:06 2011 [InM][I]: Monitoring host nodo1 (10)
> Sat Jul  9 20:52:08 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:52:08 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:52:12 2011 [InM][D]: Host 10 successfully monitored.
> Sat Jul  9 20:52:33 2011 [ReM][D]: ImageAllocate invoked
> Sat Jul  9 20:52:33 2011 [ReM][D]: ImageInfo method invoked
> Sat Jul  9 20:52:34 2011 [ReM][D]: ImageEnable invoked
> Sat Jul  9 20:52:37 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:52:37 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:52:38 2011 [ReM][D]: ImagePoolInfo method invoked
> Sat Jul  9 20:53:06 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:53:07 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:53:27 2011 [ReM][D]: ImageInfo method invoked
> Sat Jul  9 20:53:36 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:53:37 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:54:06 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:54:07 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:54:36 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:54:37 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:55:06 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:55:07 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:55:36 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:55:37 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:56:06 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:56:07 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:56:24 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:56:28 2011 [ReM][D]: VirtualMachineAction invoked
> Sat Jul  9 20:56:28 2011 [DiM][D]: Finalizing VM 28
> Sat Jul  9 20:56:36 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:56:37 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:56:38 2011 [ReM][D]: VirtualMachineAllocate invoked
> Sat Jul  9 20:56:38 2011 [ONE][E]: Could not get network lease for VM.
> Sat Jul  9 20:56:38 2011 [ReM][E]: [VirtualMachineAllocate] Error trying
> to CREATE VM Could not get network lease for VM.
> Sat Jul  9 20:57:00 2011 [ReM][D]: VirtualMachineAllocate invoked
> Sat Jul  9 20:57:06 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:57:07 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:57:08 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:57:12 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:57:27 2011 [ReM][D]: VirtualMachineDeploy invoked
> Sat Jul  9 20:57:27 2011 [DiM][D]: Deploying VM 29
> Sat Jul  9 20:57:31 2011 [TM][D]: Message received: LOG - 29
> tm_clone.sh:
> master:/var/lib/one//images/8625d68b699fd30e64360471eb2c38fed47fcfb6
> nodo1:/var/lib/one//29/images/disk.0
> 
> Sat Jul  9 20:57:31 2011 [TM][D]: Message received: LOG - 29
> tm_clone.sh: DST: /var/lib/one//29/images/disk.0
> 
> Sat Jul  9 20:57:31 2011 [TM][D]: Message received: LOG - 29
> tm_clone.sh: Creating directory /var/lib/one//29/images
> 
> Sat Jul  9 20:57:31 2011 [TM][D]: Message received: LOG - 29
> tm_clone.sh: Executed "/usr/bin/ssh nodo1 mkdir -p
> /var/lib/one//29/images".
> 
> Sat Jul  9 20:57:31 2011 [TM][D]: Message received: LOG - 29
> tm_clone.sh: Cloning
> master:/var/lib/one//images/8625d68b699fd30e64360471eb2c38fed47fcfb6
> 
> Sat Jul  9 20:57:31 2011 [TM][D]: Message received: LOG - 29
> tm_clone.sh: Executed "/usr/bin/scp
> master:/var/lib/one//images/8625d68b699fd30e64360471eb2c38fed47fcfb6
> nodo1:/var/lib/one//29/images/disk.0".
> 
> Sat Jul  9 20:57:31 2011 [TM][D]: Message received: LOG - 29
> tm_clone.sh: Executed "/usr/bin/ssh nodo1 chmod a+rw
> /var/lib/one//29/images/disk.0".
> 
> Sat Jul  9 20:57:31 2011 [TM][D]: Message received: TRANSFER SUCCESS 29 -
> 
> Sat Jul  9 20:57:33 2011 [VMM][D]: Message received: LOG - 29 Command
> execution fail: 'if [ -x "/var/tmp/one/vmm/kvm/deploy" ]; then
> /var/tmp/one/vmm/kvm/deploy /var/lib/one//29/images/deployment.0;
> else                              exit 42; fi'
> 
> Sat Jul  9 20:57:33 2011 [VMM][D]: Message received: LOG - 29 STDERR
> follows.
> 
> Sat Jul  9 20:57:33 2011 [VMM][D]: Message received: LOG - 29 errore:
> Impossibile creare il dominio da /var/lib/one//29/images/deployment.0
> 
> Sat Jul  9 20:57:33 2011 [VMM][D]: Message received: LOG - 29 errore:
> unable to set user and group to '105:114' on
> '/var/lib/one/images/ttylinux/vmlinuz-xen': No such file or directory
> 
> Sat Jul  9 20:57:33 2011 [VMM][D]: Message received: LOG - 29 ExitCode: 255
> 
> Sat Jul  9 20:57:33 2011 [VMM][D]: Message received: DEPLOY FAILURE 29
> errore: Impossibile creare il dominio da
> /var/lib/one//29/images/deployment.0
> 
> Sat Jul  9 20:57:33 2011 [VMM][D]: Message received: errore: unable to
> set user and group to '105:114' on
> '/var/lib/one/images/ttylinux/vmlinuz-xen': No such file or directory
> 
> Sat Jul  9 20:57:33 2011 [VMM][D]: Message received: ExitCode: 255
> 
> Sat Jul  9 20:57:34 2011 [TM][D]: Message received: LOG - 29
> tm_delete.sh: Deleting /var/lib/one//29/images
> 
> Sat Jul  9 20:57:34 2011 [TM][D]: Message received: LOG - 29
> tm_delete.sh: Executed "/usr/bin/ssh nodo1 rm -rf /var/lib/one//29/images".
> 
> Sat Jul  9 20:57:34 2011 [TM][D]: Message received: TRANSFER SUCCESS 29 -
> 
> Sat Jul  9 20:57:36 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:57:37 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:57:42 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:58:06 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:58:06 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:58:35 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:58:36 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:59:05 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:59:05 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 20:59:34 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 20:59:34 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:00:04 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:00:04 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:00:34 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:00:34 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:00:58 2011 [VMM][I]: --Mark--
> Sat Jul  9 21:01:00 2011 [InM][I]: --Mark--
> Sat Jul  9 21:01:03 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:01:03 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:01:32 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:01:32 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:02:01 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:02:01 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:02:24 2011 [InM][I]: Monitoring host nodo1 (10)
> Sat Jul  9 21:02:29 2011 [InM][D]: Host 10 successfully monitored.
> Sat Jul  9 21:02:30 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:02:30 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:02:59 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:02:59 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:03:28 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:03:28 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:03:57 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:03:58 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:03:58 2011 [ReM][D]: ImagePoolInfo method invoked
> Sat Jul  9 21:04:09 2011 [ReM][D]: ImageInfo method invoked
> Sat Jul  9 21:04:09 2011 [ReM][D]: ImageDelete invoked
> Sat Jul  9 21:04:09 2011 [ReM][E]: [ImageDelete] Error trying to DELETE
> IMAGE [0]. Returned error code [-1].. Reason: VMs might be running on it.
> Sat Jul  9 21:04:19 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:04:26 2011 [ReM][D]: VirtualMachineAction invoked
> Sat Jul  9 21:04:26 2011 [DiM][D]: Finalizing VM 29
> Sat Jul  9 21:04:26 2011 [ReM][D]: VirtualMachineInfo method invoked
> Sat Jul  9 21:04:26 2011 [HKM][D]: Message received: EXECUTE SUCCESS 29
> image
> 
> Sat Jul  9 21:04:27 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:04:27 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:04:32 2011 [ReM][D]: ImageInfo method invoked
> Sat Jul  9 21:04:32 2011 [ReM][D]: ImageDelete invoked
> Sat Jul  9 21:04:46 2011 [ReM][D]: VirtualMachineAllocate invoked
> Sat Jul  9 21:04:54 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:04:57 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:04:58 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:05:13 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:05:27 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:05:28 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:05:40 2011 [ReM][D]: VirtualMachineDeploy invoked
> Sat Jul  9 21:05:40 2011 [ReM][E]: [VirtualMachineDeploy] Error trying
> to MANAGE VM [29]. Returned error code [-1].. Reason: VM in wrong state.
> Sat Jul  9 21:05:57 2011 [ReM][D]: VirtualMachineDeploy invoked
> Sat Jul  9 21:05:57 2011 [DiM][D]: Deploying VM 30
> Sat Jul  9 21:05:57 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:05:57 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:06:01 2011 [TM][D]: Message received: LOG - 30
> tm_clone.sh: master:/var/lib/one/images/ttylinux/ttylinux.img
> nodo1:/var/lib/one//30/images/disk.0
> 
> Sat Jul  9 21:06:01 2011 [TM][D]: Message received: LOG - 30
> tm_clone.sh: DST: /var/lib/one//30/images/disk.0
> 
> Sat Jul  9 21:06:01 2011 [TM][D]: Message received: LOG - 30
> tm_clone.sh: Creating directory /var/lib/one//30/images
> 
> Sat Jul  9 21:06:01 2011 [TM][D]: Message received: LOG - 30
> tm_clone.sh: Executed "/usr/bin/ssh nodo1 mkdir -p
> /var/lib/one//30/images".
> 
> Sat Jul  9 21:06:01 2011 [TM][D]: Message received: LOG - 30
> tm_clone.sh: Cloning master:/var/lib/one/images/ttylinux/ttylinux.img
> 
> Sat Jul  9 21:06:01 2011 [TM][D]: Message received: LOG - 30
> tm_clone.sh: Executed "/usr/bin/scp
> master:/var/lib/one/images/ttylinux/ttylinux.img
> nodo1:/var/lib/one//30/images/disk.0".
> 
> Sat Jul  9 21:06:01 2011 [TM][D]: Message received: LOG - 30
> tm_clone.sh: Executed "/usr/bin/ssh nodo1 chmod a+rw
> /var/lib/one//30/images/disk.0".
> 
> Sat Jul  9 21:06:01 2011 [TM][D]: Message received: TRANSFER SUCCESS 30 -
> 
> Sat Jul  9 21:06:04 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:06:07 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:06:12 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:06:16 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:06:26 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:06:26 2011 [ReM][D]: HostPoolInfo method invoked
> Sat Jul  9 21:06:27 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:06:31 2011 [ReM][D]: VirtualMachinePoolInfo method invoked
> Sat Jul  9 21:06:33 2011 [VMM][D]: Message received: LOG - 30 Command
> execution fail: 'if [ -x "/var/tmp/one/vmm/kvm/deploy" ]; then
> /var/tmp/one/vmm/kvm/deploy /var/lib/one//30/images/deployment.0;
> else                              exit 42; fi'
> 
> Sat Jul  9 21:06:33 2011 [VMM][D]: Message received: LOG - 30 STDERR
> follows.
> 
> Sat Jul  9 21:06:33 2011 [VMM][D]: Message received: LOG - 30 errore:
> Impossibile creare il dominio da /var/lib/one//30/images/deployment.0
> 
> Sat Jul  9 21:06:33 2011 [VMM][D]: Message received: LOG - 30 errore:
> internal error process exited while connecting to monitor: open
> /dev/kvm: No such file or directory
> 
> Sat Jul  9 21:06:33 2011 [VMM][D]: Message received: LOG - 30 failed to
> initialize KVM: Operation not permitted
> 
> Sat Jul  9 21:06:33 2011 [VMM][D]: Message received: LOG - 30
> 
> Sat Jul  9 21:06:33 2011 [VMM][D]: Message received: LOG - 30 ExitCode: 255
> 
> Sat Jul  9 21:06:33 2011 [VMM][D]: Message received: DEPLOY FAILURE 30
> errore: Impossibile creare il dominio da
> /var/lib/one//30/images/deployment.0
> 
> Sat Jul  9 21:06:33 2011 [VMM][D]: Message received: errore: internal
> error process exited while connecting to monitor: open /dev/kvm: No such
> file or directory
> 
> Sat Jul  9 21:06:33 2011 [VMM][D]: Message received: failed to
> initialize KVM: Operation not permitted
> 
> Sat Jul  9 21:06:33 2011 [VMM][D]: Message received:
> 
> Sat Jul  9 21:06:33 2011 [VMM][D]: Message received: ExitCode: 255
> 
> Sat Jul  9 21:06:34 2011 [TM][D]: Message received: LOG - 30
> tm_delete.sh: Deleting /var/lib/one//30/images
> 
> Sat Jul  9 21:06:34 2011 [TM][D]: Message received: LOG - 30
> tm_delete.sh: Executed "/usr/bin/ssh nodo1 rm -rf /var/lib/one//30/images".
> 
> Sat Jul  9 21:06:34 2011 [TM][D]: Message received: TRANSFER SUCCESS 30 -
> _______________________________________________
> Users mailing list
> Users at lists.opennebula.org
> http://lists.opennebula.org/listinfo.cgi/users-opennebula.org
> 


-- 
Héctor Sanjuán
OpenNebula Sunstone Developer



More information about the Users mailing list