Details
-
Bug
-
Status: Resolved
-
Major
-
Resolution: Fixed
-
2.0.2
Description
Using jclouds 2.0.2, when attempting to provision a VM in GCE it failed with the exception shown below. However, my retry immediately after this did succeed.
com.google.common.util.concurrent.UncheckedExecutionException: java.util.concurrent.ExecutionException: could not find image for disk https://www.googleapis.com/compute/v1/projects/cloudsoft-qa/zones/europe-west1-b/disks/qa-kubernetes-xlgv2n5qsb-312: null at com.google.common.cache.LocalCache$LocalLoadingCache.getUnchecked(LocalCache.java:4832) at org.jclouds.googlecomputeengine.compute.functions.InstanceToNodeMetadata.apply(InstanceToNodeMetadata.java:80) at org.jclouds.googlecomputeengine.compute.functions.InstanceToNodeMetadata.apply(InstanceToNodeMetadata.java:44) at com.google.common.base.Functions$FunctionComposition.apply(Functions.java:216) at com.google.common.collect.Iterators$8.transform(Iterators.java:799) at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48) at com.google.common.collect.Iterators$7.computeNext(Iterators.java:651) at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143) at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138) at com.google.common.collect.Iterators.indexOf(Iterators.java:776) at com.google.common.collect.Iterators.any(Iterators.java:684) at com.google.common.collect.Iterables.any(Iterables.java:623) at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet.getNextNames(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:199) at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet.execute(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:123) at org.jclouds.googlecomputeengine.compute.strategy.CreateNodesWithGroupEncodedIntoNameThenAddToSet.execute(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:130) at org.jclouds.compute.internal.BaseComputeService.createNodesInGroup(BaseComputeService.java:217) at org.apache.brooklyn.location.jclouds.JcloudsLocation.obtainOnce(JcloudsLocation.java:756) at org.apache.brooklyn.location.jclouds.JcloudsLocation.obtain(JcloudsLocation.java:614) at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$ObtainLocationTask.call(MachineLifecycleEffectorTasks.java:451) at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$ObtainLocationTask.call(MachineLifecycleEffectorTasks.java:440) at org.apache.brooklyn.util.core.task.Tasks.withBlockingDetails(Tasks.java:113) at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$ProvisionMachineTask.call(MachineLifecycleEffectorTasks.java:421) at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$ProvisionMachineTask.call(MachineLifecycleEffectorTasks.java:396) at org.apache.brooklyn.util.core.task.DynamicSequentialTask$DstJob.call(DynamicSequentialTask.java:364) at org.apache.brooklyn.util.core.task.BasicExecutionManager$SubmissionCallable.call(BasicExecutionManager.java:565) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Caused by: java.util.concurrent.ExecutionException: could not find image for disk https://www.googleapis.com/compute/v1/projects/cloudsoft-qa/zones/europe-west1-b/disks/qa-kubernetes-xlgv2n5qsb-312: null at org.jclouds.googlecomputeengine.compute.loaders.DiskURIToImage.load(DiskURIToImage.java:53) at org.jclouds.googlecomputeengine.compute.loaders.DiskURIToImage.load(DiskURIToImage.java:33) at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3527) at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2319) at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2282) at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2197) at com.google.common.cache.LocalCache.get(LocalCache.java:3937) at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3941) at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4824) at com.google.common.cache.LocalCache$LocalLoadingCache.getUnchecked(LocalCache.java:4830) ... 28 more Caused by: java.lang.NullPointerException at org.jclouds.googlecomputeengine.compute.loaders.DiskURIToImage.load(DiskURIToImage.java:49) ... 37 more
Prior to that error, the log showed:
2018-02-14T03:55:46.381Z : \{"timeMillis":1518580546373,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"org.jclouds.rest.internal.InvokeHttpMethod","message":">> invoking Disks:get","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.382Z : \{"timeMillis":1518580546376,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"jclouds.headers","message":">> Accept: application/json","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.382Z : \{"timeMillis":1518580546376,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"jclouds.headers","message":">> Authorization: Bearer <snip>","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.677Z : \{"timeMillis":1518580546677,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"org.jclouds.http.internal.JavaUrlHttpCommandExecutorService","message":"Receiving response -414675134: HTTP/1.1 404 Not Found","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.678Z : \{"timeMillis":1518580546678,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"jclouds.headers","message":"<< HTTP/1.1 404 Not Found","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.680Z : \{"timeMillis":1518580546679,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"jclouds.headers","message":"<< Server: GSE","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.680Z : \{"timeMillis":1518580546680,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"jclouds.headers","message":"<< Accept-Ranges: none","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.680Z : \{"timeMillis":1518580546680,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"jclouds.headers","message":"<< X-Content-Type-Options: nosniff","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.680Z : \{"timeMillis":1518580546681,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"jclouds.headers","message":"<< X-Frame-Options: SAMEORIGIN","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.681Z : \{"timeMillis":1518580546681,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"jclouds.headers","message":"<< Vary: Origin,Accept-Encoding","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.681Z : \{"timeMillis":1518580546681,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"jclouds.headers","message":"<< Vary: X-Origin","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.691Z : \{"timeMillis":1518580546682,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"jclouds.headers","message":"<< Cache-Control: private, max-age=0","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.693Z : \{"timeMillis":1518580546682,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"jclouds.headers","message":"<< Content-Type: application/json; charset=UTF-8","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5} 2018-02-14T03:55:46.693Z : \{"timeMillis":1518580546683,"thread":"brooklyn-execmanager-y6R1SdqQ-52","level":"DEBUG","loggerName":"jclouds.headers","message":"<< Expires: Wed Feb 14 03:55:46 GMT 2018","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":195,"threadPriority":5}
Not that 4 VMs were being provisioned at approximately the same time (only one per call to createNodesInGroup).
We should guard against org.jclouds.googlecomputeengine.compute.functions.Resources.disk(key) returning null when called in DiskURIToImage.load(key). The load method returns an Optional<Image> anyway, so should be easy to change.