Failure terminating VM in vCloud Air (InvalidCacheLoadException when looking up the VM)

[aledsage]

When Brooklyn was stopping a VM (running jboss6 on vCloud Air), it failed with the InvalidCacheLoadException shown below:

Failed after 8m 38s: com.google.common.cache.CacheLoader$InvalidCacheLoadException: CacheLoader returned null for key urn:vcloud:vm:a087e4bd-b9aa-4989-9014-65f13aa91e8a.

com.google.common.cache.CacheLoader$InvalidCacheLoadException: CacheLoader returned null for key urn:vcloud:vm:a087e4bd-b9aa-4989-9014-65f13aa91e8a.
    at com.google.common.cache.LocalCache$Segment.getAndRecordStats(LocalCache.java:2348)
    at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2318)
    at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2280)
    at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2195)
    at com.google.common.cache.LocalCache.get(LocalCache.java:3934)
    at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3938)
    at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4821)
    at com.google.common.cache.LocalCache$LocalLoadingCache.getUnchecked(LocalCache.java:4827)
    at org.jclouds.vcloud.director.v1_5.functions.URNToHref.apply(URNToHref.java:49)
    at org.jclouds.vcloud.director.v1_5.functions.URNToHref.apply(URNToHref.java:37)
    at org.jclouds.rest.internal.RestAnnotationProcessor.getEndpointInParametersOrNull(RestAnnotationProcessor.java:495)
    at org.jclouds.rest.internal.RestAnnotationProcessor.getEndpointFor(RestAnnotationProcessor.java:518)
    at org.jclouds.rest.internal.RestAnnotationProcessor.findEndpoint(RestAnnotationProcessor.java:370)
    at org.jclouds.rest.internal.RestAnnotationProcessor.apply(RestAnnotationProcessor.java:192)
    at org.jclouds.rest.internal.RestAnnotationProcessor.apply(RestAnnotationProcessor.java:129)
    at org.jclouds.rest.internal.InvokeHttpMethod.toCommand(InvokeHttpMethod.java:188)
    at org.jclouds.rest.internal.InvokeHttpMethod.invoke(InvokeHttpMethod.java:84)
    at org.jclouds.rest.internal.InvokeHttpMethod.apply(InvokeHttpMethod.java:73)
    at org.jclouds.rest.internal.InvokeHttpMethod.apply(InvokeHttpMethod.java:44)
    at org.jclouds.reflect.FunctionalReflection$FunctionalInvocationHandler.handleInvocation(FunctionalReflection.java:117)
    at com.google.common.reflect.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:87)
    at com.sun.proxy.$Proxy208.get(Unknown Source)
    at org.jclouds.vcloud.director.v1_5.compute.strategy.VCloudDirectorComputeServiceAdapter.getNode(VCloudDirectorComputeServiceAdapter.java:387)
    at org.jclouds.vcloud.director.v1_5.compute.strategy.VCloudDirectorComputeServiceAdapter.getNode(VCloudDirectorComputeServiceAdapter.java:89)
    at org.jclouds.compute.strategy.impl.AdaptingComputeServiceStrategies.getNode(AdaptingComputeServiceStrategies.java:137)
    at org.jclouds.compute.predicates.AtomicNodeTerminated.refreshOrNull(AtomicNodeTerminated.java:42)
    at org.jclouds.compute.predicates.AtomicNodeTerminated.refreshOrNull(AtomicNodeTerminated.java:28)
    at org.jclouds.compute.predicates.internal.TrueIfNullOrDeletedRefreshAndDoubleCheckOnFalse.apply(TrueIfNullOrDeletedRefreshAndDoubleCheckOnFalse.java:46)
    at org.jclouds.compute.predicates.internal.TrueIfNullOrDeletedRefreshAndDoubleCheckOnFalse.apply(TrueIfNullOrDeletedRefreshAndDoubleCheckOnFalse.java:31)
    at org.jclouds.util.Predicates2$RetryablePredicate.apply(Predicates2.java:117)
    at org.jclouds.compute.internal.BaseComputeService.doDestroyNode(BaseComputeService.java:302)
    at org.jclouds.compute.internal.BaseComputeService.destroyNode(BaseComputeService.java:243)
    at brooklyn.location.jclouds.JcloudsLocation.releaseNode(JcloudsLocation.java:2189)
    at brooklyn.location.jclouds.JcloudsLocation.release(JcloudsLocation.java:2139)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks.stopAnyProvisionedMachines(MachineLifecycleEffectorTasks.java:758)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$15.call(MachineLifecycleEffectorTasks.java:587)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$15.call(MachineLifecycleEffectorTasks.java:585)
    at brooklyn.util.task.DynamicSequentialTask$DstJob.call(DynamicSequentialTask.java:337)
    at brooklyn.util.task.BasicExecutionManager$SubmissionCallable.call(BasicExecutionManager.java:469)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

This was on the entity AQGBB2zF. The details of the task are:

Name: stopping (machine) 
ID: LSmGYxzJ
Submitted: 15 Jun 2015 13:54:39.899   4 hours ago
Started: 15 Jun 2015 13:54:39.899   4 hours ago
Finished: 15 Jun 2015 14:03:18.071   

[aledsage]

I was able to reproduce this. The vApp had already been deleted via vCloud Director. I then attempted to destroyNode.

I had also restarted Brooklyn, so it was a fresh jclouds ComputeService (rather than the one used to provision the VM in the first place).

Below is the latest exception with 1.9.1-20151022.1606:

Failed after 12m 16s: Error invoking stop at JBoss6ServerImpl{id=TrW9wFy4}: com.google.common.cache.CacheLoader$InvalidCacheLoadException: CacheLoader returned null for key urn:vcloud:vm:f3beacc4-99c1-43a9-baef-3b4a0fb6c080.

org.apache.brooklyn.util.exceptions.PropagatedRuntimeException: Error invoking stop at JBoss6ServerImpl{id=TrW9wFy4}: com.google.common.cache.CacheLoader$InvalidCacheLoadException: CacheLoader returned null for key urn:vcloud:vm:f3beacc4-99c1-43a9-baef-3b4a0fb6c080.
    at org.apache.brooklyn.core.mgmt.internal.EffectorUtils.handleEffectorException(EffectorUtils.java:270)
    at org.apache.brooklyn.core.effector.EffectorTasks$EffectorBodyTaskFactory$2.handleException(EffectorTasks.java:90)
    at org.apache.brooklyn.util.core.task.DynamicSequentialTask.handleException(DynamicSequentialTask.java:452)
    at org.apache.brooklyn.util.core.task.DynamicSequentialTask$DstJob.call(DynamicSequentialTask.java:400)
    at org.apache.brooklyn.util.core.task.BasicExecutionManager$SubmissionCallable.call(BasicExecutionManager.java:468)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.brooklyn.util.exceptions.PropagatedRuntimeException: com.google.common.cache.CacheLoader$InvalidCacheLoadException: CacheLoader returned null for key urn:vcloud:vm:f3beacc4-99c1-43a9-baef-3b4a0fb6c080.
    at org.apache.brooklyn.util.exceptions.Exceptions.propagate(Exceptions.java:103)
    at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks.doStop(MachineLifecycleEffectorTasks.java:765)
    at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks.stop(MachineLifecycleEffectorTasks.java:690)
    at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$StopEffectorBody.call(MachineLifecycleEffectorTasks.java:265)
    at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$StopEffectorBody.call(MachineLifecycleEffectorTasks.java:262)
    at org.apache.brooklyn.core.effector.EffectorTasks$EffectorBodyTaskFactory$1.call(EffectorTasks.java:82)
    at org.apache.brooklyn.util.core.task.DynamicSequentialTask$DstJob.call(DynamicSequentialTask.java:342)
    ... 5 more
Caused by: java.util.concurrent.ExecutionException: com.google.common.cache.CacheLoader$InvalidCacheLoadException: CacheLoader returned null for key urn:vcloud:vm:f3beacc4-99c1-43a9-baef-3b4a0fb6c080.
    at java.util.concurrent.FutureTask.report(FutureTask.java:122)
    at java.util.concurrent.FutureTask.get(FutureTask.java:188)
    at com.google.common.util.concurrent.ForwardingFuture.get(ForwardingFuture.java:63)
    at org.apache.brooklyn.util.core.task.BasicTask.get(BasicTask.java:342)
    at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks.doStop(MachineLifecycleEffectorTasks.java:753)
    ... 10 more
Caused by: com.google.common.cache.CacheLoader$InvalidCacheLoadException: CacheLoader returned null for key urn:vcloud:vm:f3beacc4-99c1-43a9-baef-3b4a0fb6c080.
    at com.google.common.cache.LocalCache$Segment.getAndRecordStats(LocalCache.java:2348)
    at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2318)
    at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2280)
    at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2195)
    at com.google.common.cache.LocalCache.get(LocalCache.java:3934)
    at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3938)
    at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4821)
    at com.google.common.cache.LocalCache$LocalLoadingCache.getUnchecked(LocalCache.java:4827)
    at org.jclouds.vcloud.director.v1_5.functions.URNToHref.apply(URNToHref.java:49)
    at org.jclouds.vcloud.director.v1_5.functions.URNToHref.apply(URNToHref.java:37)
    at org.jclouds.rest.internal.RestAnnotationProcessor.getEndpointInParametersOrNull(RestAnnotationProcessor.java:495)
    at org.jclouds.rest.internal.RestAnnotationProcessor.getEndpointFor(RestAnnotationProcessor.java:518)
    at org.jclouds.rest.internal.RestAnnotationProcessor.findEndpoint(RestAnnotationProcessor.java:370)
    at org.jclouds.rest.internal.RestAnnotationProcessor.apply(RestAnnotationProcessor.java:192)
    at org.jclouds.rest.internal.RestAnnotationProcessor.apply(RestAnnotationProcessor.java:129)
    at org.jclouds.rest.internal.InvokeHttpMethod.toCommand(InvokeHttpMethod.java:188)
    at org.jclouds.rest.internal.InvokeHttpMethod.invoke(InvokeHttpMethod.java:84)
    at org.jclouds.rest.internal.InvokeHttpMethod.apply(InvokeHttpMethod.java:73)
    at org.jclouds.rest.internal.InvokeHttpMethod.apply(InvokeHttpMethod.java:44)
    at org.jclouds.reflect.FunctionalReflection$FunctionalInvocationHandler.handleInvocation(FunctionalReflection.java:117)
    at com.google.common.reflect.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:87)
    at com.sun.proxy.$Proxy206.get(Unknown Source)
    at org.jclouds.vcloud.director.v1_5.compute.strategy.VCloudDirectorComputeServiceAdapter.getNode(VCloudDirectorComputeServiceAdapter.java:469)
    at org.jclouds.vcloud.director.v1_5.compute.strategy.VCloudDirectorComputeServiceAdapter.getNode(VCloudDirectorComputeServiceAdapter.java:102)
    at org.jclouds.compute.strategy.impl.AdaptingComputeServiceStrategies.getNode(AdaptingComputeServiceStrategies.java:137)
    at org.jclouds.compute.strategy.impl.AdaptingComputeServiceStrategies.destroyNode(AdaptingComputeServiceStrategies.java:178)
    at org.jclouds.compute.internal.BaseComputeService$2.apply(BaseComputeService.java:291)
    at org.jclouds.compute.internal.BaseComputeService$2.apply(BaseComputeService.java:288)
    at org.jclouds.util.Predicates2$RetryablePredicate.apply(Predicates2.java:117)
    at org.jclouds.compute.internal.BaseComputeService.doDestroyNode(BaseComputeService.java:302)
    at org.jclouds.compute.internal.BaseComputeService.destroyNode(BaseComputeService.java:243)
    at org.apache.brooklyn.location.jclouds.JcloudsLocation.releaseNode(JcloudsLocation.java:2369)
    at org.apache.brooklyn.location.jclouds.JcloudsLocation.release(JcloudsLocation.java:2319)
    at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks.stopAnyProvisionedMachines(MachineLifecycleEffectorTasks.java:912)
    at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$StopAnyProvisionedMachinesTask.call(MachineLifecycleEffectorTasks.java:777)
    at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$StopAnyProvisionedMachinesTask.call(MachineLifecycleEffectorTasks.java:775)
    ... 6 more