VMware Cloud Community
tivs
Enthusiast
Enthusiast
‎12-21-2012 11:38 AM

After VCD 5.1.1 upgrade from VCD1.5, the vCenter 5.1 is not communicating to the VCD5.1.1

Hi All,

     I upgraded the VCD1.5 to VCD5.1.1, after upgrading the vCenter 5.1 is unable to communicate to VCD5.1.1.

vCenter is :- 5.1.0-880146

   vShield:- 5.1.1-848085

  VCD:- 5.1.1-868405

ESXi:- 5.1.0-799733

The error message is as below:-

2012-12-18 14:31:56,221 | DEBUG    | ActiveMQ Session Task     | WaitHandle                     | Skipping update for task [moref=task-10449, state=SUCCESS, taskName=ShutdownGuest, progress=null, entityName=xxxxx-vshield5] as it is in complete state. |

2012-12-18 14:31:56,226 | DEBUG    | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | InventoryServiceImpl           | Handling update      ObjectUpdate of kind => 'leave', type => 'HostSystem' for object => 'host-1200 |

2012-12-18 14:31:56,226 | DEBUG    | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | InventoryServiceImpl           | Handling update      ObjectUpdate of kind => 'leave', type => 'ClusterComputeResource' for object => 'domain-c1204 |

2012-12-18 14:31:56,226 | DEBUG    | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | InventoryServiceImpl           | Handling update      ObjectUpdate of kind => 'leave', type => 'Datastore' for object => 'datastore-1201 |

2012-12-18 14:31:56,227 | DEBUG    | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | InventoryServiceImpl           | Handling update      ObjectUpdate of kind => 'leave', type => 'ResourcePool' for object => 'resgroup-1205 |

2012-12-18 14:31:56,230 | DEBUG    | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | Conversation                   | Closing Hibernate session although it has not been flushed. |

2012-12-18 14:31:56,230 | INFO     | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | Conversation                   | Transaction rolled back; session has been closed |

2012-12-18 14:31:56,230 | ERROR    | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | VcUpdateListenerImpl           | Break on Unrecoverable error in Outer WFU Loop |

java.lang.NullPointerException

        at com.vmware.vcloud.inventory.impl.ResourcePoolInventoryRecordImpl.isCpuReservationExpandable(ResourcePoolInventoryRecordImpl.java:114)

        at com.vmware.vcloud.inventory.impl.ResourcePoolInventoryRecordImpl.getInfo(ResourcePoolInventoryRecordImpl.java:138)

        at com.vmware.vcloud.inventory.impl.ResourcePoolInventoryRecordImpl.getInfo(ResourcePoolInventoryRecordImpl.java:36)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.processUpdate(InventoryServiceImpl.java:1050)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.processUpdateSet(InventoryServiceImpl.java:953)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.access$300(InventoryServiceImpl.java:145)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl$5.run(InventoryServiceImpl.java:860)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl$5.run(InventoryServiceImpl.java:826)

        at com.vmware.vcloud.common.persist.ConversationContextExecutor.execute(ConversationContextExecutor.java:46)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.processAndBatchUpdates(InventoryServiceImpl.java:826)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.handleUpdate(InventoryServiceImpl.java:799)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.onSyncCompleted(InventoryServiceImpl.java:1752)

        at sun.reflect.GeneratedMethodAccessor2496.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)

        at java.lang.reflect.Method.invoke(Unknown Source)

        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)

        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)

        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)

        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)

        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)

        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)

        at $Proxy187.onSyncCompleted(Unknown Source)

        at com.vmware.vcloud.vimproxy.internal.impl.VcUpdateListenerImpl.innerWaitForUpdatesLoop(VcUpdateListenerImpl.java:921)

        at com.vmware.vcloud.vimproxy.internal.impl.VcUpdateListenerImpl.outerWaitForUpdatesLoop(VcUpdateListenerImpl.java:594)

        at com.vmware.vcloud.vimproxy.internal.impl.VcUpdateListenerImpl.run(VcUpdateListenerImpl.java:343)

2012-12-18 14:31:56,231 | DEBUG    | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | VcUpdateListenerImpl           | VC 82701e3b-31bb-4b40-b849-1562963f0b4c: dispatchVcConnectionDownEvent |

2012-12-18 14:31:56,231 | DEBUG    | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | EventManagerImpl               | Dispatching event VirtualCenterConnectionChangedEvent(82701e3b-31bb-4b40-b849-1562963f0b4c, true, com.vmware.vcloud.api.presentation.service.InternalServerErrorException: Internal Server Error)... |

2012-12-18 14:31:56,231 | INFO     | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | VirtualCenterListener          | VC connection state event 82701e3b-31bb-4b40-b849-1562963f0b4c. Changing state to DISCONNECTED |

2012-12-18 14:31:56,231 | INFO     | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | VirtualCenterListener          | Disconnected from virtual center 82701e3b-31bb-4b40-b849-1562963f0b4c |

2012-12-18 14:31:56,244 | DEBUG    | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | JobManager                     | **** Add activity log: <JOB_VC_START_CONNECTION> <abc.abc.com(com.vmware.vcloud.entity.vimserver:82701e3b-31bb-4b40-b849-1562963f0b4c)> |

2012-12-18 14:31:56,244 | DEBUG    | 2701e3b-31bb-4b40-b849-1562963f0b4cListener (1354) | CJob                           | updateFailedJob(com.vmware.vcloud.api.presentation.service.InternalServerErrorException) with locale=null |

com.vmware.vcloud.api.presentation.service.InternalServerErrorException: Internal Server Error

        at com.vmware.vcloud.vimproxy.internal.impl.VcUpdateListenerImpl.onOuterLoopBreakWithException(VcUpdateListenerImpl.java:721)

        at com.vmware.vcloud.vimproxy.internal.impl.VcUpdateListenerImpl.outerWaitForUpdatesLoop(VcUpdateListenerImpl.java:633)

        at com.vmware.vcloud.vimproxy.internal.impl.VcUpdateListenerImpl.run(VcUpdateListenerImpl.java:343)

Caused by: java.lang.NullPointerException

        at com.vmware.vcloud.inventory.impl.ResourcePoolInventoryRecordImpl.isCpuReservationExpandable(ResourcePoolInventoryRecordImpl.java:114)

        at com.vmware.vcloud.inventory.impl.ResourcePoolInventoryRecordImpl.getInfo(ResourcePoolInventoryRecordImpl.java:138)

        at com.vmware.vcloud.inventory.impl.ResourcePoolInventoryRecordImpl.getInfo(ResourcePoolInventoryRecordImpl.java:36)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.processUpdate(InventoryServiceImpl.java:1050)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.processUpdateSet(InventoryServiceImpl.java:953)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.access$300(InventoryServiceImpl.java:145)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl$5.run(InventoryServiceImpl.java:860)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl$5.run(InventoryServiceImpl.java:826)

        at com.vmware.vcloud.common.persist.ConversationContextExecutor.execute(ConversationContextExecutor.java:46)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.processAndBatchUpdates(InventoryServiceImpl.java:826)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.handleUpdate(InventoryServiceImpl.java:799)

        at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.onSyncCompleted(InventoryServiceImpl.java:1752)

        at sun.reflect.GeneratedMethodAccessor2496.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)

        at java.lang.reflect.Method.invoke(Unknown Source)

        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)

        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)

        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)

        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)

        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)

        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)

        at $Proxy187.onSyncCompleted(Unknown Source)

        at com.vmware.vcloud.vimproxy.internal.impl.VcUpdateListenerImpl.innerWaitForUpdatesLoop(VcUpdateListenerImpl.java:921)

        at com.vmware.vcloud.vimproxy.internal.impl.VcUpdateListenerImpl.outerWaitForUpdatesLoop(VcUpdateListenerImpl.java:594)

        ... 1 more

3 Replies
acruizu
Enthusiast
Enthusiast
‎05-22-2013 03:58 PM

I'm getting the same error after a database issue:

2013-05-22 17:54:09,113 | ERROR    | 23b4fe43-1f29-4c6f-adc1-1048b2a8845cListener (391) | VcUpdateListenerImpl           | Break on Unrecoverable error in Outer WFU Loop |

java.lang.reflect.UndeclaredThrowableException

  at com.vmware.ssdc.util.ExceptionUtil.rethrow(ExceptionUtil.java:45)

  at com.vmware.vcloud.inventory.cache.InventoryCacheEntryImpl.fromByteArray(InventoryCacheEntryImpl.java:113)

  at com.vmware.vcloud.inventory.cache.InventoryCacheEntryImpl.<init>(InventoryCacheEntryImpl.java:75)

  at com.vmware.vcloud.inventory.cache.InventoryCacheManagerImpl.bulkGetInternal(InventoryCacheManagerImpl.java:424)

  at com.vmware.vcloud.inventory.cache.InventoryCacheManagerImpl.bulkGet(InventoryCacheManagerImpl.java:549)

  at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.processUpdateSet(InventoryServiceImpl.java:931)

  at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.access$300(InventoryServiceImpl.java:145)

  at com.vmware.vcloud.inventory.impl.InventoryServiceImpl$5.run(InventoryServiceImpl.java:860)

  at com.vmware.vcloud.inventory.impl.InventoryServiceImpl$5.run(InventoryServiceImpl.java:826)

  at com.vmware.vcloud.common.persist.ConversationContextExecutor.execute(ConversationContextExecutor.java:46)

  at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.processAndBatchUpdates(InventoryServiceImpl.java:826)

  at com.vmware.vcloud.inventory.impl.InventoryServiceImpl.handleUpdate(InventoryServiceImpl.java:799)

  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

  at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)

  at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)

  at java.lang.reflect.Method.invoke(Unknown Source)

  at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)

  at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)

  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)

  at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)

  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)

  at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)

  at $Proxy187.handleUpdate(Unknown Source)

  at com.vmware.vcloud.vimproxy.internal.impl.VcUpdateListenerImpl.dispatchUpdates(VcUpdateListenerImpl.java:1080)

  at com.vmware.vcloud.vimproxy.internal.impl.VcUpdateListenerImpl.innerWaitForUpdatesLoop(VcUpdateListenerImpl.java:925)

  at com.vmware.vcloud.vimproxy.internal.impl.VcUpdateListenerImpl.outerWaitForUpdatesLoop(VcUpdateListenerImpl.java:594)

  at com.vmware.vcloud.vimproxy.internal.impl.VcUpdateListenerImpl.run(VcUpdateListenerImpl.java:343)

Caused by: java.io.IOException: Error reading data from inventory cache: [vcId=23b4fe43-1f29-4c6f-adc1-1048b2a8845c, moref=vm-3313, moType=11, age=137129, validAge=137144]

  ... 26 more

Caused by: java.io.EOFException

  at java.io.ObjectInputStream$PeekInputStream.readFully(Unknown Source)

  at java.io.ObjectInputStream$BlockDataInputStream.readShort(Unknown Source)

  at java.io.ObjectInputStream.readStreamHeader(Unknown Source)

  at java.io.ObjectInputStream.<init>(Unknown Source)

  at com.vmware.vcloud.inventory.cache.InventoryCacheEntryImpl.fromByteArray(InventoryCacheEntryImpl.java:110)

  ... 25 more

2013-05-22 17:54:09,115 | INFO     | 23b4fe43-1f29-4c6f-adc1-1048b2a8845cListener (391) | VirtualCenterListener          | VC connection state event 23b4fe43-1f29-4c6f-adc1-1048b2a8845c. Changing state to DISCONNECTED |

2013-05-22 17:54:09,115 | INFO     | 23b4fe43-1f29-4c6f-adc1-1048b2a8845cListener (391) | VirtualCenterListener          | Disconnected from virtual center 23b4fe43-1f29-4c6f-adc1-1048b2a8845c |

2013-05-22 17:54:09,371 | INFO     | 23b4fe43-1f29-4c6f-adc1-1048b2a8845cListener (391) | InventoryServiceImpl           | Received listener stopped for VC 23b4fe43-1f29-4c6f-adc1-1048b2a8845c |

2013-05-22 17:54:09,371 | WARN     | 23b4fe43-1f29-4c6f-adc1-1048b2a8845cListener (391) | InventoryRecordPurger          | Inventory records purger for 23b4fe43-1f29-4c6f-adc1-1048b2a8845c is not active |

2013-05-22 17:54:09,371 | INFO     | 23b4fe43-1f29-4c6f-adc1-1048b2a8845cListener (391) | VcUpdateListenerImpl           | Releasing the ownership of VC proxy 23b4fe43-1f29-4c6f-adc1-1048b2a8845c |

2013-05-22 17:54:09,371 | INFO     | 23b4fe43-1f29-4c6f-adc1-1048b2a8845cListener (391) | VcUpdateListenerImpl           | trying to clear cell instance id on vc 23b4fe43-1f29-4c6f-adc1-1048b2a8845c (current number of retries 0). |

2013-05-22 17:54:09,372 | INFO     | 23b4fe43-1f29-4c6f-adc1-1048b2a8845cListener (391) | VcUpdateListenerImpl           | VC 23b4fe43-1f29-4c6f-adc1-1048b2a8845c: Attempt to set cell instance id from 108 to 0 |

2013-05-22 17:54:09,398 | INFO     | ectionCleanup-23b4fe43-1f29-4c6f-adc1-1048b2a8845c | VcUpdateListenerImpl           | VC 23b4fe43-1f29-4c6f-adc1-1048b2a8845c: Ignoring exception null while unregistering filters |

2013-05-22 17:54:09,419 | INFO     | 23b4fe43-1f29-4c6f-adc1-1048b2a8845cListener (391) | VcUpdateListenerImpl           | VC 23b4fe43-1f29-4c6f-adc1-1048b2a8845c: Successfully set cell instance id to 0 |

2013-05-22 17:54:09,420 | INFO     | 23b4fe43-1f29-4c6f-adc1-1048b2a8845cListener (391) | VcUpdateListenerImpl           | correctly released ownership of vc proxy 23b4fe43-1f29-4c6f-adc1-1048b2a8845c |

0 Kudos
IamTHEvilONE
Immortal
Immortal
‎05-27-2013 01:34 PM

You're failing on reading data about a specific vm in inventory, moref=vm-3313.

I think you should be able to delete that specific vm from vm_inv table and the property map table.  as with any database work, stop all cells, backup db, perform queries, start services, validate error state has changed.

IamTHEvilONE
Immortal
Immortal
‎05-27-2013 01:36 PM

I think your failure is on reading the inventory cache on a resource pool moref=resgroup-1205.

I think you should be able to delete the entry from resource_pool_inv, then delete the entry from property_map table.  as with any database work, stop all cells, backup db, perform queries, start services, validate error state has changed.