# VM Pending to Infinity

**URL:** <https://forum.opennebula.io/t/vm-pending-to-infinity/851>\
**Category:** Product Support\
**Created:** [June 10, 2015, 6:09pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851 "2015-06-10T18:09:13Z")\
**Posts on this page:** 18\
**Page:** 1

<div class="post-metadata">

**Author:** ![todd](https://avatars.discourse-cdn.com/v4/letter/t/fbc32d/32.png) [@todd](https://forum.opennebula.io/u/todd)\
**Post date:** [June 10, 2015, 6:09pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/1 "2015-06-10T18:09:13Z")

</div>

Hi,

It seems I’m having a bit of bad luck. I’ve followed all directions for installing 4.12 on Ubuntu 14.04. I have no problem adding hosts/templates/images. But instantiation of KVM VM’s results in infinite PENDING state - this is repeated in the sched.log over and over - can anyone shed any light on where else to look?:

Wed Jun 10 10:46:32 2015 [Z0][SCHED][I]: Dispatching VMs to hosts. Total time: 7.4057e-05s  
Wed Jun 10 10:47:01 2015 [Z0][SCHED][I]: Getting scheduled actions information. Total time: 0.00196756s  
Wed Jun 10 10:47:02 2015 [Z0][VM][D]: Found 2 pending/rescheduling VMs.  
Wed Jun 10 10:47:02 2015 [Z0][HOST][D]: Discovered 6 enabled hosts.  
Wed Jun 10 10:47:02 2015 [Z0][SCHED][I]: Getting VM and Host information. Total time: 0.00884282s  
Wed Jun 10 10:47:02 2015 [Z0][SCHED][D]: Match Making statistics:  
Number of VMs: 2  
Total time: 0s  
Total Match time: 0.000297604s  
Total Ranking Time: 0.000344431s  
Wed Jun 10 10:47:02 2015 [Z0][SCHED][D]: Dispatching VMs to hosts:  
VMID Host System DS  
-------------------------

---

<div class="post-metadata">

**Author:** ![ruben](https://yyz1.discourse-cdn.com/flex031/user_avatar/forum.opennebula.io/ruben/32/19_2.png) [@ruben](https://forum.opennebula.io/u/ruben)\
**Post date:** [June 10, 2015, 6:17pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/2 "2015-06-10T18:17:38Z")

</div>

is there any message in the vm (like onevm show \<vm\_id\>) look for some  
SCHED\_MESSAGE. double check the capacity required by the VM, that avilable  
in the hosts and any specific REQUIREMENT in the VM…

---

<div class="post-metadata">

**Author:** ![todd](https://avatars.discourse-cdn.com/v4/letter/t/fbc32d/32.png) [@todd](https://forum.opennebula.io/u/todd)\
**Post date:** [June 10, 2015, 6:21pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/3 "2015-06-10T18:21:54Z")

</div>

yes there is and it’s odd that my hosts are not enabled?

SCHED\_MESSAGE=“Wed Jun 10 10:54:32 2015 : No hosts enabled to run VMs”

The entire output is here:

oneadmin@1mgmt1:~$ onevm show 0  
VIRTUAL MACHINE 0 INFORMATION  
ID : 0  
NAME : Trusty-TestVM-0  
USER : oneadmin  
GROUP : oneadmin  
STATE : PENDING  
LCM\_STATE : LCM\_INIT  
RESCHED : No  
START TIME : 06/10 08:25:33  
END TIME : -  
DEPLOY ID : -

VIRTUAL MACHINE MONITORING  
USED MEMORY : 0K  
USED CPU : 0  
NET\_TX : 0K  
NET\_RX : 0K

PERMISSIONS  
OWNER : um-  
GROUP : —  
OTHER : —

VM DISKS  
ID TARGET IMAGE TYPE SAVE SAVE\_AS  
0 hda Trusty\_X86\_65 file NO -

VM NICS  
ID NETWORK VLAN BRIDGE IP MAC  
0 private no br0 192.168.32.100 02:00:c0:a8:20:64

SECURITY

NIC\_ID NETWORK SECURITY\_GROUPS  
0 private 0

SECURITY GROUP TYPE PROTOCOL NETWORK RANGE  
ID NAME VNET START SIZE  
0 default OUTBOUND ALL  
0 default INBOUND ALL

USER TEMPLATE  
SCHED\_MESSAGE=“Wed Jun 10 10:54:32 2015 : No hosts enabled to run VMs”

VIRTUAL MACHINE TEMPLATE  
AUTOMATIC\_REQUIREMENTS="!(PUBLIC\_CLOUD = YES)"  
CONTEXT=[  
DISK\_ID=“1”,  
TARGET=“hdb” ]  
CPU="2"  
GRAPHICS=[  
LISTEN=“0.0.0.0”,  
PORT=“5900”,  
TYPE=“vnc” ]  
MEMORY="2096"  
OS=[  
ARCH=“x86\_64” ]  
TEMPLATE\_ID="0"  
VCPU="2"  
VMID=“0”

---

<div class="post-metadata">

**Author:** ![ruben](https://yyz1.discourse-cdn.com/flex031/user_avatar/forum.opennebula.io/ruben/32/19_2.png) [@ruben](https://forum.opennebula.io/u/ruben)\
**Post date:** [June 10, 2015, 6:37pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/4 "2015-06-10T18:37:57Z")

</div>

Could you paste the output of onehost list -x?

---

<div class="post-metadata">

**Author:** ![todd](https://avatars.discourse-cdn.com/v4/letter/t/fbc32d/32.png) [@todd](https://forum.opennebula.io/u/todd)\
**Post date:** [June 10, 2015, 6:41pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/5 "2015-06-10T18:41:32Z")

</div>

```
 <HOST_POOL>
  <HOST>
    <ID>0</ID>
    <NAME>1cn2.dev.gogii.net</NAME>
    <STATE>1</STATE>
    <IM_MAD><![CDATA[kvm]]></IM_MAD>
    <VM_MAD><![CDATA[kvm]]></VM_MAD>
    <VN_MAD><![CDATA[dummy]]></VN_MAD>
	    <LAST_MON_TIME>1433961653</LAST_MON_TIME>
	    <CLUSTER_ID>100</CLUSTER_ID>
	    <CLUSTER>DevCluster</CLUSTER>
	    <HOST_SHARE>
	      <DISK_USAGE>0</DISK_USAGE>
	      <MEM_USAGE>0</MEM_USAGE>
	      <CPU_USAGE>0</CPU_USAGE>
		      <MAX_DISK>0</MAX_DISK>
		      <MAX_MEM>49454196</MAX_MEM>
		      <MAX_CPU>800</MAX_CPU>
		      <FREE_DISK>0</FREE_DISK>
		      <FREE_MEM>49024420</FREE_MEM>
		      <FREE_CPU>800</FREE_CPU>
		      <USED_DISK>0</USED_DISK>
		      <USED_MEM>429776</USED_MEM>
		      <USED_CPU>0</USED_CPU>
		      <RUNNING_VMS>0</RUNNING_VMS>
		      <DATASTORES/>
		    </HOST_SHARE>
		    <VMS/>
		    <TEMPLATE>
		      <ARCH><![CDATA[x86_64]]></ARCH>
		      <CPUSPEED><![CDATA[1600]]></CPUSPEED>
		      <HOSTNAME><![CDATA[1cn2.dev.gogii.net]]></HOSTNAME>
		      <HYPERVISOR><![CDATA[kvm]]></HYPERVISOR>
		      <MODELNAME><![CDATA[Intel(R) Xeon(R) CPU E5504 @ 2.00GHz]]></MODELNAME>
		      <NETRX><![CDATA[0]]></NETRX>
		      <NETTX><![CDATA[0]]></NETTX>
		      <RESERVED_CPU><![CDATA[]]></RESERVED_CPU>
		      <RESERVED_MEM><![CDATA[]]></RESERVED_MEM>
		    </TEMPLATE>
		  </HOST>
		  <HOST>
		    <ID>1</ID>
		    <NAME>1cn3.dev.gogii.net</NAME>
		    <STATE>2</STATE>
		    <IM_MAD><![CDATA[kvm]]></IM_MAD>
		    <VM_MAD><![CDATA[kvm]]></VM_MAD>
		    <VN_MAD><![CDATA[dummy]]></VN_MAD>
		    <LAST_MON_TIME>1433961642</LAST_MON_TIME>
		    <CLUSTER_ID>100</CLUSTER_ID>
		    <CLUSTER>DevCluster</CLUSTER>
		    <HOST_SHARE>
		      <DISK_USAGE>0</DISK_USAGE>
		      <MEM_USAGE>0</MEM_USAGE>
		      <CPU_USAGE>0</CPU_USAGE>
		      <MAX_DISK>0</MAX_DISK>
		      <MAX_MEM>49454196</MAX_MEM>
		      <MAX_CPU>800</MAX_CPU>
		      <FREE_DISK>0</FREE_DISK>
		      <FREE_MEM>49024940</FREE_MEM>
		      <FREE_CPU>800</FREE_CPU>
		      <USED_DISK>0</USED_DISK>
		      <USED_MEM>429256</USED_MEM>
		      <USED_CPU>0</USED_CPU>
		      <RUNNING_VMS>0</RUNNING_VMS>
		      <DATASTORES/>
		    </HOST_SHARE>
		    <VMS/>
		    <TEMPLATE>
		      <ARCH><![CDATA[x86_64]]></ARCH>
		      <CPUSPEED><![CDATA[1600]]></CPUSPEED>
		      <HOSTNAME><![CDATA[1cn3.dev.gogii.net]]></HOSTNAME>
		      <HYPERVISOR><![CDATA[kvm]]></HYPERVISOR>
		      <MODELNAME><![CDATA[Intel(R) Xeon(R) CPU E5504 @ 2.00GHz]]></MODELNAME>
		      <NETRX><![CDATA[0]]></NETRX>
		      <NETTX><![CDATA[0]]></NETTX>
		      <RESERVED_CPU><![CDATA[]]></RESERVED_CPU>
		      <RESERVED_MEM><![CDATA[]]></RESERVED_MEM>
		    </TEMPLATE>
		  </HOST>
		  <HOST>
		    <ID>2</ID>
		    <NAME>1cn4.dev.gogii.net</NAME>
		    <STATE>1</STATE>
		    <IM_MAD><![CDATA[kvm]]></IM_MAD>
		    <VM_MAD><![CDATA[kvm]]></VM_MAD>
		    <VN_MAD><![CDATA[dummy]]></VN_MAD>
		    <LAST_MON_TIME>1433961654</LAST_MON_TIME>
		    <CLUSTER_ID>100</CLUSTER_ID>
		    <CLUSTER>DevCluster</CLUSTER>
		    <HOST_SHARE>
		      <DISK_USAGE>0</DISK_USAGE>
		      <MEM_USAGE>0</MEM_USAGE>
		      <CPU_USAGE>0</CPU_USAGE>
		      <MAX_DISK>0</MAX_DISK>
		      <MAX_MEM>49454196</MAX_MEM>
		      <MAX_CPU>800</MAX_CPU>
		      <FREE_DISK>0</FREE_DISK>
		      <FREE_MEM>49029152</FREE_MEM>
		      <FREE_CPU>800</FREE_CPU>
		      <USED_DISK>0</USED_DISK>
		      <USED_MEM>425044</USED_MEM>
		      <USED_CPU>0</USED_CPU>
		      <RUNNING_VMS>0</RUNNING_VMS>
		      <DATASTORES/>
		    </HOST_SHARE>
		    <VMS/>
		    <TEMPLATE>
		      <ARCH><![CDATA[x86_64]]></ARCH>
		      <CPUSPEED><![CDATA[1600]]></CPUSPEED>
		      <HOSTNAME><![CDATA[1cn4.dev.gogii.net]]></HOSTNAME>
		      <HYPERVISOR><![CDATA[kvm]]></HYPERVISOR>
		      <MODELNAME><![CDATA[Intel(R) Xeon(R) CPU E5504 @ 2.00GHz]]></MODELNAME>
		      <NETRX><![CDATA[0]]></NETRX>
		      <NETTX><![CDATA[0]]></NETTX>
		      <RESERVED_CPU><![CDATA[]]></RESERVED_CPU>
		      <RESERVED_MEM><![CDATA[]]></RESERVED_MEM>
		    </TEMPLATE>
		  </HOST>
		  <HOST>
		    <ID>3</ID>
		    <NAME>1cn6.dev.gogii.net</NAME>
		    <STATE>1</STATE>
		    <IM_MAD><![CDATA[kvm]]></IM_MAD>
		    <VM_MAD><![CDATA[kvm]]></VM_MAD>
		    <VN_MAD><![CDATA[dummy]]></VN_MAD>
		    <LAST_MON_TIME>1433961654</LAST_MON_TIME>
		    <CLUSTER_ID>100</CLUSTER_ID>
		    <CLUSTER>DevCluster</CLUSTER>
		    <HOST_SHARE>
		      <DISK_USAGE>0</DISK_USAGE>
		      <MEM_USAGE>0</MEM_USAGE>
		      <CPU_USAGE>0</CPU_USAGE>
		      <MAX_DISK>0</MAX_DISK>
		      <MAX_MEM>24681700</MAX_MEM>
		      <MAX_CPU>800</MAX_CPU>
		      <FREE_DISK>0</FREE_DISK>
		      <FREE_MEM>24413236</FREE_MEM>
		      <FREE_CPU>800</FREE_CPU>
		      <USED_DISK>0</USED_DISK>
		      <USED_MEM>268464</USED_MEM>
		      <USED_CPU>0</USED_CPU>
		      <RUNNING_VMS>0</RUNNING_VMS>
		      <DATASTORES/>
		    </HOST_SHARE>
		    <VMS/>
		    <TEMPLATE>
		      <ARCH><![CDATA[x86_64]]></ARCH>
		      <CPUSPEED><![CDATA[1600]]></CPUSPEED>
		      <HOSTNAME><![CDATA[1cn6.dev.gogii.net]]></HOSTNAME>
		      <HYPERVISOR><![CDATA[kvm]]></HYPERVISOR>
		      <MODELNAME><![CDATA[Intel(R) Xeon(R) CPU E5504 @ 2.00GHz]]></MODELNAME>
		      <NETRX><![CDATA[0]]></NETRX>
		      <NETTX><![CDATA[0]]></NETTX>
		      <RESERVED_CPU><![CDATA[]]></RESERVED_CPU>
		      <RESERVED_MEM><![CDATA[]]></RESERVED_MEM>
		    </TEMPLATE>
		  </HOST>
		  <HOST>
		    <ID>4</ID>
		    <NAME>1cn7.dev.gogii.net</NAME>
		    <STATE>2</STATE>
		    <IM_MAD><![CDATA[kvm]]></IM_MAD>
		    <VM_MAD><![CDATA[kvm]]></VM_MAD>
		    <VN_MAD><![CDATA[dummy]]></VN_MAD>
		    <LAST_MON_TIME>1433961599</LAST_MON_TIME>
		    <CLUSTER_ID>100</CLUSTER_ID>
		    <CLUSTER>DevCluster</CLUSTER>
		    <HOST_SHARE>
		      <DISK_USAGE>0</DISK_USAGE>
		      <MEM_USAGE>0</MEM_USAGE>
		      <CPU_USAGE>0</CPU_USAGE>
		      <MAX_DISK>0</MAX_DISK>
		      <MAX_MEM>24681700</MAX_MEM>
		      <MAX_CPU>800</MAX_CPU>
		      <FREE_DISK>0</FREE_DISK>
		      <FREE_MEM>24409532</FREE_MEM>
		      <FREE_CPU>800</FREE_CPU>
		      <USED_DISK>0</USED_DISK>
		      <USED_MEM>272168</USED_MEM>
		      <USED_CPU>0</USED_CPU>
		      <RUNNING_VMS>0</RUNNING_VMS>
		      <DATASTORES/>
		    </HOST_SHARE>
		    <VMS/>
		    <TEMPLATE>
		      <ARCH><![CDATA[x86_64]]></ARCH>
		      <CPUSPEED><![CDATA[1600]]></CPUSPEED>
		      <HOSTNAME><![CDATA[1cn7.dev.gogii.net]]></HOSTNAME>
		      <HYPERVISOR><![CDATA[kvm]]></HYPERVISOR>
		      <MODELNAME><![CDATA[Intel(R) Xeon(R) CPU E5504 @ 2.00GHz]]></MODELNAME>
		      <NETRX><![CDATA[0]]></NETRX>
		      <NETTX><![CDATA[0]]></NETTX>
		      <RESERVED_CPU><![CDATA[]]></RESERVED_CPU>
		      <RESERVED_MEM><![CDATA[]]></RESERVED_MEM>
		    </TEMPLATE>
		  </HOST>
		  <HOST>
		    <ID>5</ID>
		    <NAME>1cn8.dev.gogii.net</NAME>
		    <STATE>2</STATE>
		    <IM_MAD><![CDATA[kvm]]></IM_MAD>
		    <VM_MAD><![CDATA[kvm]]></VM_MAD>
		    <VN_MAD><![CDATA[dummy]]></VN_MAD>
		    <LAST_MON_TIME>1433961599</LAST_MON_TIME>
		    <CLUSTER_ID>100</CLUSTER_ID>
		    <CLUSTER>DevCluster</CLUSTER>
		    <HOST_SHARE>
		      <DISK_USAGE>0</DISK_USAGE>
		      <MEM_USAGE>0</MEM_USAGE>
		      <CPU_USAGE>0</CPU_USAGE>
		      <MAX_DISK>0</MAX_DISK>
		      <MAX_MEM>49453336</MAX_MEM>
		      <MAX_CPU>800</MAX_CPU>
		      <FREE_DISK>0</FREE_DISK>
		      <FREE_MEM>49019980</FREE_MEM>
		      <FREE_CPU>800</FREE_CPU>
		      <USED_DISK>0</USED_DISK>
		      <USED_MEM>433356</USED_MEM>
		      <USED_CPU>0</USED_CPU>
		      <RUNNING_VMS>0</RUNNING_VMS>
		      <DATASTORES/>
		    </HOST_SHARE>
		    <VMS/>
		    <TEMPLATE>
		      <ARCH><![CDATA[x86_64]]></ARCH>
		      <CPUSPEED><![CDATA[1600]]></CPUSPEED>
		      <HOSTNAME><![CDATA[1cn8.dev.gogii.net]]></HOSTNAME>
		      <HYPERVISOR><![CDATA[kvm]]></HYPERVISOR>
		      <MODELNAME><![CDATA[Intel(R) Xeon(R) CPU E5504 @ 2.00GHz]]></MODELNAME>
		      <NETRX><![CDATA[0]]></NETRX>
		      <NETTX><![CDATA[0]]></NETTX>
		      <RESERVED_CPU><![CDATA[]]></RESERVED_CPU>
		      <RESERVED_MEM><![CDATA[]]></RESERVED_MEM>
		    </TEMPLATE>
		  </HOST>
		</HOST_POOL>

```

I don’t see anything out of order here???

---

<div class="post-metadata">

**Author:** ![ruben](https://yyz1.discourse-cdn.com/flex031/user_avatar/forum.opennebula.io/ruben/32/19_2.png) [@ruben](https://forum.opennebula.io/u/ruben)\
**Post date:** [June 10, 2015, 6:55pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/6 "2015-06-10T18:55:20Z")

</div>

no there is nothing wrong here, state is the right one (2 = MONITORED) and the requirements of the VM should fit in the hosts…

---

<div class="post-metadata">

**Author:** ![ruben](https://yyz1.discourse-cdn.com/flex031/user_avatar/forum.opennebula.io/ruben/32/19_2.png) [@ruben](https://forum.opennebula.io/u/ruben)\
**Post date:** [June 10, 2015, 7:03pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/7 "2015-06-10T19:03:08Z")

</div>

So it seems that the messages are not consistent, i.e.

```auto
Wed Jun 10 10:47:02 2015 [Z0][HOST][D]: Discovered 6 enabled hosts.

```

in sched.conf, and:

```auto
SCHED_MESSAGE="Wed Jun 10 10:54:32 2015 : No hosts enabled to run VMs"

```

in vm template (at the code level both messages refer to the same counter) Could you double check the timestamps. i.e what are the sched.log messages at 10:54…

---

<div class="post-metadata">

**Author:** ![todd](https://avatars.discourse-cdn.com/v4/letter/t/fbc32d/32.png) [@todd](https://forum.opennebula.io/u/todd)\
**Post date:** [June 10, 2015, 7:07pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/8 "2015-06-10T19:07:31Z")

</div>

Well I certainly can’t explain the inconsistency seen below.

Wed Jun 10 10:54:01 2015 [Z0][SCHED][I]: Getting scheduled actions information. Total time: 0.00201246s  
Wed Jun 10 10:54:02 2015 [Z0][VM][D]: Found 2 pending/rescheduling VMs.  
Wed Jun 10 10:54:02 2015 [Z0][HOST][D]: Discovered 6 enabled hosts.  
Wed Jun 10 10:54:02 2015 [Z0][SCHED][I]: Getting VM and Host information. Total time: 0.00877915s  
Wed Jun 10 10:54:02 2015 [Z0][SCHED][D]: Match Making statistics:  
Wed Jun 10 10:54:02 2015 [Z0][SCHED][D]: Dispatching VMs to hosts:  
Wed Jun 10 10:54:02 2015 [Z0][SCHED][I]: Dispatching VMs to hosts. Total time: 7.4312e-05s  
Wed Jun 10 10:54:31 2015 [Z0][SCHED][I]: Getting scheduled actions information. Total time: 0.00224268s  
Wed Jun 10 10:54:32 2015 [Z0][VM][D]: Found 2 pending/rescheduling VMs.  
Wed Jun 10 10:54:32 2015 [Z0][HOST][D]: Discovered 0 enabled hosts.  
Wed Jun 10 10:54:32 2015 [Z0][SCHED][I]: Getting VM and Host information. Total time: 0.00798932s  
Wed Jun 10 10:54:32 2015 [Z0][SCHED][D]: Match-making results for VM 0:  
Wed Jun 10 10:54:32 2015 [Z0][SCHED][D]: Match-making results for VM 1:  
Wed Jun 10 10:54:32 2015 [Z0][SCHED][D]: Match Making statistics:  
Wed Jun 10 10:54:32 2015 [Z0][SCHED][D]: Dispatching VMs to hosts:  
Wed Jun 10 10:54:32 2015 [Z0][SCHED][I]: Dispatching VMs to hosts. Total time: 4.1428e-05s

---

<div class="post-metadata">

**Author:** ![ruben](https://yyz1.discourse-cdn.com/flex031/user_avatar/forum.opennebula.io/ruben/32/19_2.png) [@ruben](https://forum.opennebula.io/u/ruben)\
**Post date:** [June 10, 2015, 7:10pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/9 "2015-06-10T19:10:30Z")

</div>

> [@todd](#):
>
> Wed Jun 10 10:54:32 2015 [Z0][HOST][D]: Discovered 0 enabled hosts.

So the VM and sched.logs are consistent for that point 0 hosts and messages.

The problem is the previous scheduling step, 6 enabled hosts and no VM dispatched. The sched messages are overwritten in the VM. So, is there any chance to get the system state to that point 6 hosts up and monitored and no scheduled VM, and check if there is a message in the VM?

---

<div class="post-metadata">

**Author:** ![todd](https://avatars.discourse-cdn.com/v4/letter/t/fbc32d/32.png) [@todd](https://forum.opennebula.io/u/todd)\
**Post date:** [June 10, 2015, 7:12pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/10 "2015-06-10T19:12:14Z")

</div>

sorry Ruben I don’t follow? What do you mean?

---

<div class="post-metadata">

**Author:** ![ruben](https://yyz1.discourse-cdn.com/flex031/user_avatar/forum.opennebula.io/ruben/32/19_2.png) [@ruben](https://forum.opennebula.io/u/ruben)\
**Post date:** [June 10, 2015, 7:18pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/11 "2015-06-10T19:18:32Z")

</div>

It seems that the last messages there are no hosts enabled (or they are in  
error state)

Wed Jun 10 10:54:32 2015 [Z0][HOST][D]: Discovered 0 enabled hosts.

Could you bring them back, and see if there are new information in the  
onevm show output?

---

<div class="post-metadata">

**Author:** ![todd](https://avatars.discourse-cdn.com/v4/letter/t/fbc32d/32.png) [@todd](https://forum.opennebula.io/u/todd)\
**Post date:** [June 10, 2015, 7:24pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/12 "2015-06-10T19:24:21Z")

</div>

I actually tried to instantiate a new vm:

I see this in the sched.log:

## Wed Jun 10 12:20:24 2015 [Z0][VM][D]: Found 1 pending/rescheduling VMs. Wed Jun 10 12:20:24 2015 [Z0][HOST][D]: Discovered 6 enabled hosts. Wed Jun 10 12:20:24 2015 [Z0][SCHED][I]: Getting VM and Host information. Total time: 0.00865405s Wed Jun 10 12:20:24 2015 [Z0][SCHED][D]: Match Making statistics: Wed Jun 10 12:20:24 2015 [Z0][SCHED][D]: Dispatching VMs to hosts: Wed Jun 10 12:20:24 2015 [Z0][SCHED][I]: Dispatching VMs to hosts. Total time: 5.6926e-05s Wed Jun 10 12:20:53 2015 [Z0][SCHED][I]: Getting scheduled actions information. Total time: 0.00205205s Wed Jun 10 12:20:54 2015 [Z0][VM][D]: Found 1 pending/rescheduling VMs. Wed Jun 10 12:20:54 2015 [Z0][HOST][D]: Discovered 6 enabled hosts. Wed Jun 10 12:20:54 2015 [Z0][SCHED][I]: Getting VM and Host information. Total time: 0.00829487s Wed Jun 10 12:20:54 2015 [Z0][SCHED][D]: Match Making statistics: Wed Jun 10 12:20:54 2015 [Z0][SCHED][D]: Dispatching VMs to hosts: Wed Jun 10 12:20:54 2015 [Z0][SCHED][I]: Dispatching VMs to hosts. Total time: 6.0501e-05s Wed Jun 10 12:21:23 2015 [Z0][SCHED][I]: Getting scheduled actions information. Total time: 0.00189272s Wed Jun 10 12:21:23 2015 [Z0][VM][D]: Found 1 pending/rescheduling VMs. Wed Jun 10 12:21:24 2015 [Z0][HOST][D]: Discovered 6 enabled hosts. Wed Jun 10 12:21:24 2015 [Z0][SCHED][I]: Getting VM and Host information. Total time: 0.00841761s Wed Jun 10 12:21:24 2015 [Z0][SCHED][D]: Match Making statistics: Wed Jun 10 12:21:24 2015 [Z0][SCHED][D]: Dispatching VMs to hosts: Wed Jun 10 12:21:24 2015 [Z0][SCHED][I]: Dispatching VMs to hosts. Total time: 7.133e-05s Wed Jun 10 12:21:53 2015 [Z0][SCHED][I]: Getting scheduled actions information. Total time: 0.00217081s Wed Jun 10 12:21:53 2015 [Z0][VM][D]: Found 1 pending/rescheduling VMs. Wed Jun 10 12:21:54 2015 [Z0][HOST][D]: Discovered 6 enabled hosts. Wed Jun 10 12:21:54 2015 [Z0][SCHED][I]: Getting VM and Host information. Total time: 0.00829147s Wed Jun 10 12:21:54 2015 [Z0][SCHED][D]: Match Making statistics: Wed Jun 10 12:21:54 2015 [Z0][SCHED][D]: Dispatching VMs to hosts: Wed Jun 10 12:21:54 2015 [Z0][SCHED][I]: Dispatching VMs to hosts. Total time: 6.1349e-05s Wed Jun 10 12:22:23 2015 [Z0][SCHED][I]: Getting scheduled actions information. Total time: 0.00194499s Wed Jun 10 12:22:23 2015 [Z0][VM][D]: Found 1 pending/rescheduling VMs. Wed Jun 10 12:22:24 2015 [Z0][HOST][D]: Discovered 6 enabled hosts. Wed Jun 10 12:22:24 2015 [Z0][SCHED][I]: Getting VM and Host information. Total time: 0.00840124s Wed Jun 10 12:22:24 2015 [Z0][SCHED][D]: Match Making statistics: Wed Jun 10 12:22:24 2015 [Z0][SCHED][D]: Dispatching VMs to hosts: Wed Jun 10 12:22:24 2015 [Z0][SCHED][I]: Dispatching VMs to hosts. Total time: 6.1971e-05s Wed Jun 10 12:22:53 2015 [Z0][SCHED][I]: Getting scheduled actions information. Total time: 0.00224552s Wed Jun 10 12:22:54 2015 [Z0][VM][D]: Found 1 pending/rescheduling VMs. Wed Jun 10 12:22:54 2015 [Z0][HOST][D]: Discovered 6 enabled hosts. Wed Jun 10 12:22:54 2015 [Z0][SCHED][I]: Getting VM and Host information. Total time: 0.00827975s Wed Jun 10 12:22:54 2015 [Z0][SCHED][D]: Match Making statistics: Wed Jun 10 12:22:54 2015 [Z0][SCHED][D]: Dispatching VMs to hosts: Wed Jun 10 12:22:54 2015 [Z0][SCHED][I]: Dispatching VMs to hosts. Total time: 6.0428e-05s Wed Jun 10 12:23:23 2015 [Z0][SCHED][I]: Getting scheduled actions information. Total time: 0.00191932s Wed Jun 10 12:23:24 2015 [Z0][VM][D]: Found 1 pending/rescheduling VMs. Wed Jun 10 12:23:24 2015 [Z0][HOST][D]: Discovered 6 enabled hosts. Wed Jun 10 12:23:24 2015 [Z0][SCHED][I]: Getting VM and Host information. Total time: 0.00888487s Wed Jun 10 12:23:24 2015 [Z0][SCHED][D]: Match Making statistics: Wed Jun 10 12:23:24 2015 [Z0][SCHED][D]: Dispatching VMs to hosts: Wed Jun 10 12:23:24 2015 [Z0][SCHED][I]: Dispatching VMs to hosts. Total time: 5.6282e-05s

VIRTUAL MACHINE 2 INFORMATION  
ID : 2  
NAME : Todds\_1204  
USER : oneadmin  
GROUP : oneadmin  
STATE : PENDING  
LCM\_STATE : LCM\_INIT  
RESCHED : No  
START TIME : 06/10 12:20:02  
END TIME : -  
DEPLOY ID : -

VIRTUAL MACHINE MONITORING  
USED MEMORY : 0K  
USED CPU : 0  
NET\_TX : 0K  
NET\_RX : 0K

PERMISSIONS  
OWNER : um-  
GROUP : —  
OTHER : —

VM DISKS  
ID TARGET IMAGE TYPE SAVE SAVE\_AS  
0 hda Precise\_X86\_64 cdro NO -

VM NICS  
ID NETWORK VLAN BRIDGE IP MAC  
0 private no br0 192.168.32.101 02:00:c0:a8:20:65

SECURITY

NIC\_ID NETWORK SECURITY\_GROUPS  
0 private 0

SECURITY GROUP TYPE PROTOCOL NETWORK RANGE  
ID NAME VNET START SIZE  
0 default OUTBOUND ALL  
0 default INBOUND ALL

VIRTUAL MACHINE TEMPLATE  
AUTOMATIC\_REQUIREMENTS="!(PUBLIC\_CLOUD = YES)"  
CONTEXT=[  
DISK\_ID=“1”,  
TARGET=“hdb” ]  
CPU="2"  
GRAPHICS=[  
LISTEN=“0.0.0.0”,  
PORT=“5902”,  
TYPE=“vnc” ]  
MEMORY="2096"  
OS=[  
ARCH=“x86\_64” ]  
TEMPLATE\_ID="1"  
VCPU="2"  
VMID=“2”

---

<div class="post-metadata">

**Author:** ![ruben](https://yyz1.discourse-cdn.com/flex031/user_avatar/forum.opennebula.io/ruben/32/19_2.png) [@ruben](https://forum.opennebula.io/u/ruben)\
**Post date:** [June 10, 2015, 7:30pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/13 "2015-06-10T19:30:21Z")

</div>

Do not see anything wrong there (maybe missing some messages). Do you see anything in oned.log, is any deploy message?

---

<div class="post-metadata">

**Author:** ![todd](https://avatars.discourse-cdn.com/v4/letter/t/fbc32d/32.png) [@todd](https://forum.opennebula.io/u/todd)\
**Post date:** [June 10, 2015, 7:34pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/14 "2015-06-10T19:34:10Z")

</div>

I don’t see any errors here?

oned.log for 12:20:

Wed Jun 10 12:20:02 2015 [Z0][ReM][D]: Req:1040 UID:0 TemplateInfo invoked , 1  
Wed Jun 10 12:20:02 2015 [Z0][ReM][D]: Req:1040 UID:0 TemplateInfo result SUCCESS, "1\</I…"  
Wed Jun 10 12:20:02 2015 [Z0][ReM][D]: Req:8000 UID:0 TemplateInstantiate invoked , 1, “Todds\_1204”, false, ""  
Wed Jun 10 12:20:03 2015 [Z0][ReM][D]: Req:8000 UID:0 TemplateInstantiate result SUCCESS, 2  
Wed Jun 10 12:20:04 2015 [Z0][InM][D]: Monitoring host [1cn7.dev.gogii.net](http://1cn7.dev.gogii.net) (4)  
Wed Jun 10 12:20:05 2015 [Z0][InM][D]: Monitoring host [1cn8.dev.gogii.net](http://1cn8.dev.gogii.net) (5)  
Wed Jun 10 12:20:08 2015 [Z0][InM][D]: Host [1cn7.dev.gogii.net](http://1cn7.dev.gogii.net) (4) successfully monitored.  
Wed Jun 10 12:20:08 2015 [Z0][InM][D]: Host [1cn8.dev.gogii.net](http://1cn8.dev.gogii.net) (5) successfully monitored.  
Wed Jun 10 12:20:09 2015 [Z0][ReM][D]: Req:1088 UID:0 VirtualMachinePoolInfo invoked , -2, 0, -2000, -1  
Wed Jun 10 12:20:09 2015 [Z0][ReM][D]: Req:1088 UID:0 VirtualMachinePoolInfo result SUCCESS, "\<VM\_POOL\>2\</…"  
Wed Jun 10 12:20:11 2015 [Z0][ReM][D]: Req:8208 UID:0 VirtualMachineInfo invoked , 2  
Wed Jun 10 12:20:11 2015 [Z0][ReM][D]: Req:8208 UID:0 VirtualMachineInfo result SUCCESS, "20…"  
Wed Jun 10 12:20:18 2015 [Z0][ReM][D]: Req:1264 UID:0 VirtualMachineInfo invoked , 2  
Wed Jun 10 12:20:18 2015 [Z0][ReM][D]: Req:1264 UID:0 VirtualMachineInfo result SUCCESS, "20…"  
Wed Jun 10 12:20:23 2015 [Z0][ReM][D]: Req:6624 UID:0 VirtualMachinePoolInfo invoked , -2, -1, -1, -1  
Wed Jun 10 12:20:23 2015 [Z0][ReM][D]: Req:6624 UID:0 VirtualMachinePoolInfo result SUCCESS, "\<VM\_POOL\>2\</…"  
Wed Jun 10 12:20:23 2015 [Z0][ReM][D]: Req:528 UID:0 VirtualMachinePoolInfo invoked , -2, -1, -1, -1  
Wed Jun 10 12:20:23 2015 [Z0][ReM][D]: Req:528 UID:0 VirtualMachinePoolInfo result SUCCESS, "\<VM\_POOL\>2\</…"  
Wed Jun 10 12:20:24 2015 [Z0][ReM][D]: Req:7456 UID:0 DatastorePoolInfo invoked  
Wed Jun 10 12:20:24 2015 [Z0][ReM][D]: Req:7456 UID:0 DatastorePoolInfo result SUCCESS, "\<DATASTORE\_POOL\>\<DAT…"  
Wed Jun 10 12:20:24 2015 [Z0][ReM][D]: Req:9888 UID:0 DatastorePoolInfo invoked  
Wed Jun 10 12:20:24 2015 [Z0][ReM][D]: Req:9888 UID:0 DatastorePoolInfo result SUCCESS, "\<DATASTORE\_POOL\>\<DAT…"  
Wed Jun 10 12:20:24 2015 [Z0][ReM][D]: Req:2080 UID:0 HostPoolInfo invoked  
Wed Jun 10 12:20:24 2015 [Z0][ReM][D]: Req:2080 UID:0 HostPoolInfo result SUCCESS, "\<HOST\_POOL\>\<ID…"  
Wed Jun 10 12:20:24 2015 [Z0][ReM][D]: Req:8416 UID:0 ClusterPoolInfo invoked  
Wed Jun 10 12:20:24 2015 [Z0][ReM][D]: Req:8416 UID:0 ClusterPoolInfo result SUCCESS, "\<CLUSTER\_POOL\>\<CLUST…"  
Wed Jun 10 12:20:24 2015 [Z0][ReM][D]: Req:9824 UID:0 AclInfo invoked  
Wed Jun 10 12:20:24 2015 [Z0][ReM][D]: Req:9824 UID:0 AclInfo result SUCCESS, "\<ACL\_POOL\>0…"  
Wed Jun 10 12:20:27 2015 [Z0][InM][D]: Monitoring datastore default (1)  
Wed Jun 10 12:20:27 2015 [Z0][InM][D]: Monitoring datastore files (2)  
Wed Jun 10 12:20:28 2015 [Z0][ImM][D]: Datastore default (1) successfully monitored.  
Wed Jun 10 12:20:28 2015 [Z0][ImM][D]: Datastore files (2) successfully monitored.  
Wed Jun 10 12:20:45 2015 [Z0][AuM][D]: Message received: AUTHENTICATE SUCCESS 70 -

Wed Jun 10 12:20:45 2015 [Z0][ReM][D]: Req:9120 UID:0 VirtualMachineInfo invoked , 2  
Wed Jun 10 12:20:45 2015 [Z0][ReM][D]: Req:9120 UID:0 VirtualMachineInfo result SUCCESS, "20…"  
Wed Jun 10 12:20:45 2015 [Z0][ReM][D]: Req:816 UID:0 VirtualMachineInfo invoked , 2  
Wed Jun 10 12:20:45 2015 [Z0][ReM][D]: Req:816 UID:0 VirtualMachineInfo result SUCCESS, "20…"  
Wed Jun 10 12:20:47 2015 [Z0][InM][D]: Monitoring host [1cn3.dev.gogii.net](http://1cn3.dev.gogii.net) (1)  
Wed Jun 10 12:20:51 2015 [Z0][ReM][D]: Req:288 UID:0 VirtualMachineInfo invoked , 2  
Wed Jun 10 12:20:51 2015 [Z0][ReM][D]: Req:288 UID:0 VirtualMachineInfo result SUCCESS, "20…"  
Wed Jun 10 12:20:51 2015 [Z0][InM][D]: Host [1cn3.dev.gogii.net](http://1cn3.dev.gogii.net) (1) successfully monitored.  
Wed Jun 10 12:20:53 2015 [Z0][ReM][D]: Req:4112 UID:0 VirtualMachinePoolInfo invoked , -2, -1, -1, -1  
Wed Jun 10 12:20:53 2015 [Z0][ReM][D]: Req:4112 UID:0 VirtualMachinePoolInfo result SUCCESS, "\<VM\_POOL\>2\</…"  
Wed Jun 10 12:20:53 2015 [Z0][ReM][D]: Req:2000 UID:0 VirtualMachinePoolInfo invoked , -2, -1, -1, -1  
Wed Jun 10 12:20:53 2015 [Z0][ReM][D]: Req:2000 UID:0 VirtualMachinePoolInfo result SUCCESS, "\<VM\_POOL\>2\</…"  
Wed Jun 10 12:20:54 2015 [Z0][ReM][D]: Req:9232 UID:0 DatastorePoolInfo invoked  
Wed Jun 10 12:20:54 2015 [Z0][ReM][D]: Req:9232 UID:0 DatastorePoolInfo result SUCCESS, "\<DATASTORE\_POOL\>\<DAT…"  
Wed Jun 10 12:20:54 2015 [Z0][ReM][D]: Req:6880 UID:0 DatastorePoolInfo invoked  
Wed Jun 10 12:20:54 2015 [Z0][ReM][D]: Req:6880 UID:0 DatastorePoolInfo result SUCCESS, "\<DATASTORE\_POOL\>\<DAT…"  
Wed Jun 10 12:20:54 2015 [Z0][ReM][D]: Req:6528 UID:0 HostPoolInfo invoked  
Wed Jun 10 12:20:54 2015 [Z0][ReM][D]: Req:6528 UID:0 HostPoolInfo result SUCCESS, "\<HOST\_POOL\>\<ID…"  
Wed Jun 10 12:20:54 2015 [Z0][ReM][D]: Req:7136 UID:0 ClusterPoolInfo invoked  
Wed Jun 10 12:20:54 2015 [Z0][ReM][D]: Req:7136 UID:0 ClusterPoolInfo result SUCCESS, "\<CLUSTER\_POOL\>\<CLUST…"  
Wed Jun 10 12:20:54 2015 [Z0][ReM][D]: Req:1824 UID:0 AclInfo invoked  
Wed Jun 10 12:20:54 2015 [Z0][ReM][D]: Req:1824 UID:0 AclInfo result SUCCESS, "\<ACL\_POOL\>0…"  
Wed Jun 10 12:21:02 2015 [Z0][InM][D]: Monitoring host [1cn2.dev.gogii.net](http://1cn2.dev.gogii.net) (0)  
Wed Jun 10 12:21:03 2015 [Z0][InM][D]: Monitoring host [1cn4.dev.gogii.net](http://1cn4.dev.gogii.net) (2)  
Wed Jun 10 12:21:03 2015 [Z0][InM][D]: Monitoring host [1cn6.dev.gogii.net](http://1cn6.dev.gogii.net) (3)  
Wed Jun 10 12:21:06 2015 [Z0][InM][D]: Host [1cn2.dev.gogii.net](http://1cn2.dev.gogii.net) (0) successfully monitored.  
Wed Jun 10 12:21:07 2015 [Z0][InM][D]: Host [1cn4.dev.gogii.net](http://1cn4.dev.gogii.net) (2) successfully monitored.  
Wed Jun 10 12:21:07 2015 [Z0][InM][D]: Host [1cn6.dev.gogii.net](http://1cn6.dev.gogii.net) (3) successfully monitored.  
Wed Jun 10 12:21:17 2015 [Z0][InM][D]: Monitoring host [1cn7.dev.gogii.net](http://1cn7.dev.gogii.net) (4)  
Wed Jun 10 12:21:18 2015 [Z0][InM][D]: Monitoring host [1cn8.dev.gogii.net](http://1cn8.dev.gogii.net) (5)  
Wed Jun 10 12:21:21 2015 [Z0][AuM][D]: Message received: AUTHENTICATE SUCCESS 71 -

---

<div class="post-metadata">

**Author:** ![ruben](https://yyz1.discourse-cdn.com/flex031/user_avatar/forum.opennebula.io/ruben/32/19_2.png) [@ruben](https://forum.opennebula.io/u/ruben)\
**Post date:** [June 10, 2015, 7:38pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/15 "2015-06-10T19:38:04Z")

</div>

is there any output for:

```auto
 grep -i deploy -5 oned.log*

```

---

<div class="post-metadata">

**Author:** ![todd](https://avatars.discourse-cdn.com/v4/letter/t/fbc32d/32.png) [@todd](https://forum.opennebula.io/u/todd)\
**Post date:** [June 10, 2015, 8:37pm UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/16 "2015-06-10T20:37:39Z")

</div>

I only see this from earlier?

oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/kvm/migrate\_local: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/kvm/kvmrc: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/kvm/poll: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/kvm/detach\_nic: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/kvm/snapshot\_delete: Permission denied  
oned.log:Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/kvm/deploy: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/kvm/save: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/kvm/shutdown: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/kvm/reboot: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/kvm/cancel: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/kvm/migrate: Permission denied

oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/ec2: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/az: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/vmware/poll: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/vmware/detach\_nic: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/vmware/snapshot\_delete: Permission denied  
oned.log:Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/vmware/deploy: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/vmware/save: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/vmware/shutdown: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/vmware/reboot: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/vmware/vmware\_driver.rb: Permission denied  
oned.log-Wed Jun 10 08:10:33 2015 [Z0][InM][I]: scp: /var/tmp/one/./vmm/vmware/cancel: Permission denied

---

<div class="post-metadata">

**Author:** ![todd](https://avatars.discourse-cdn.com/v4/letter/t/fbc32d/32.png) [@todd](https://forum.opennebula.io/u/todd)\
**Post date:** [June 11, 2015, 1:09am UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/17 "2015-06-11T01:09:42Z")

</div>

I’ve solved this by completely re-installing all boxes… Thank you for your help Ruben!

---

<div class="post-metadata">

**Author:** ![ruben](https://yyz1.discourse-cdn.com/flex031/user_avatar/forum.opennebula.io/ruben/32/19_2.png) [@ruben](https://forum.opennebula.io/u/ruben)\
**Post date:** [June 11, 2015, 9:41am UTC](https://forum.opennebula.io/t/vm-pending-to-infinity/851/18 "2015-06-11T09:41:43Z")

</div>

Great! I was totally puzzled