NullPointerException provisioning Windows VM in private vCloud Director

[aledsage]

On a customer's private vCloud Director environment, deploying a Windows VM, we hit the NullPointerException shown below.

This was with the version vcloud-director-1.9.0-rc3.jar (i.e. the 1.9.x branch), so I presume it was on the line below:

Vm vm = Iterables.getOnlyElement(api.getVAppApi().get(vApp.getHref()).getChildren().getVms());

The full error was:

Failed after 14m 19s: org.jclouds.compute.RunNodesException: error running 1 node group(brooklyn-ajeo-amp-auto-qa-7zip-rdsm-7zip-oxcr) location(https://svdc.it-solutions.atos.net/api/vdc/56fc1a0a-81dc-468f-bf60-c2d50e21dc6c) image(urn:vcloud:vapptemplate:d5c14365-45b3-4b21-b08a-c4c089334d37) size(micro) options({inboundPorts=[5985, 3389, 1433], userMetadata={Name=brooklyn-ajeo-amp-auto-qa-7zip-rdsm-7zip-oxcr-qkmp, brooklyn-user=amp, brooklyn-app-id=rDsMC2hP, brooklyn-app-name=(auto-qa) 7zip @ Canopy_TAI_TEST_WIN, brooklyn-entity-id=OxcrVsys, brooklyn-entity-name=7zip, brooklyn-server-creation-date=2015-06-15-1700}, networks=[Deployment_Network_01], guestCustomizationScript=[statements=[winrm quickconfig -q & winrm set winrm/config/service/auth @{Basic="true"} & winrm set winrm/config/service/auth @{CredSSP="true"} & winrm set winrm/config/client/auth @{CredSSP="true"} & winrm set winrm/config/client @{AllowUnencrypted="true"} & winrm set winrm/config/service @{AllowUnencrypted="true"} & winrm set winrm/config/winrs @{MaxConcurrentUsers="100"} & winrm set winrm/config/winrs @{MaxMemoryPerShellMB="0"} & winrm set winrm/config/winrs @{MaxProcessesPerShell="0"} & winrm set winrm/config/winrs @{MaxShellsPerUser="0"} & netsh advfirewall firewall add rule name=RDP dir=in protocol=tcp localport=3389 action=allow profile=any & netsh advfirewall firewall add rule name=WinRM dir=in protocol=tcp localport=5985 action=allow profile=any & powershell -EncodedCommand JABSAEQAUAAgAD0AIABHAGUAdAAtAFcAbQBpAE8AYgBqAGUAYwB0ACAALQBDAGwAYQBzAHMAIABXAGkAbgAzADIAXwBUAGUAcgBtAGkAbgBhAGwAUwBlAHIAdgBpAGMAZQBTAGUAdAB0AGkAbgBnACAALQBDAG8AbQBwAHUAdABlAHIATgBhAG0AZQAgACQAZQBuAHYAOgBjAG8AbQBwAHUAdABlAHIAbgBhAG0AZQAgAC0ATgBhAG0AZQBzAHAAYQBjAGUAIAByAG8AbwB0AFwAQwBJAE0AVgAyAFwAVABlAHIAbQBpAG4AYQBsAFMAZQByAHYAaQBjAGUAcwAgAC0AQQB1AHQAaABlAG4AdABpAGMAYQB0AGkAbwBuACAAUABhAGMAawBlAHQAUAByAGkAdgBhAGMAeQANAAoAJABSAEQAUAAuAFMAZQB0AEEAbABsAG8AdwBUAFMAQwBvAG4AbgBlAGMAdABpAG8AbgBzACgAMQAsADEAKQANAAoAUwBlAHQALQBFAHgAZQBjAHUAdABpAG8AbgBQAG8AbABpAGMAeQAgAFUAbgByAGUAcwB0AHIAaQBjAHQAZQBkACAALQBGAG8AcgBjAGUADQAKAFMAZQB0AC0ASQB0AGUAbQAgAFcAUwBNAGEAbgA6AFwAbABvAGMAYQBsAGgAbwBzAHQAXABTAGgAZQBsAGwAXABNAGEAeABDAG8AbgBjAHUAcgByAGUAbgB0AFUAcwBlAHIAcwAgADEAMAAwAA0ACgBTAGUAdAAtAEkAdABlAG0AIABXAFMATQBhAG4AOgBcAGwAbwBjAGEAbABoAG8AcwB0AFwAUwBoAGUAbABsAFwATQBhAHgATQBlAG0AbwByAHkAUABlAHIAUwBoAGUAbABsAE0AQgAgADAADQAKAFMAZQB0AC0ASQB0AGUAbQAgAFcAUwBNAGEAbgA6AFwAbABvAGMAYQBsAGgAbwBzAHQAXABTAGgAZQBsAGwAXABNAGEAeABQAHIAbwBjAGUAcwBzAGUAcwBQAGUAcgBTAGgAZQBsAGwAIAAwAA0ACgBTAGUAdAAtAEkAdABlAG0AIABXAFMATQBhAG4AOgBcAGwAbwBjAGEAbABoAG8AcwB0AFwAUwBoAGUAbABsAFwATQBhAHgAUwBoAGUAbABsAHMAUABlAHIAVQBzAGUAcgAgADAADQAKAE4AZQB3AC0ASQB0AGUAbQBQAHIAbwBwAGUAcgB0AHkAIAAiAEgASwBMAE0AOgBcAFMAeQBzAHQAZQBtAFwAQwB1AHIAcgBlAG4AdABDAG8AbgB0AHIAbwBsAFMAZQB0AFwAQwBvAG4AdAByAG8AbABcAEwAUwBBACIAIAAtAE4AYQBtAGUAIAAiAFMAdQBwAHAAcgBlAHMAcwBFAHgAdABlAG4AZABlAGQAUAByAG8AdABlAGMAdABpAG8AbgAiACAALQBWAGEAbAB1AGUAIAAxACAALQBQAHIAbwBwAGUAcgB0AHkAVAB5AHAAZQAgACIARABXAG8AcgBkACIADQAKACQAYQBsAGwAbwB3AGUAZAAgAD0AIABAACgAJwBXAFMATQBBAE4ALwAqACcAKQANAAoAJABrAGUAeQAgAD0AIAAnAGgAawBsAG0AOgBcAFMATwBGAFQAVwBBAFIARQBcAFAAbwBsAGkAYwBpAGUAcwBcAE0AaQBjAHIAbwBzAG8AZgB0AFwAVwBpAG4AZABvAHcAcwBcAEMAcgBlAGQAZQBuAHQAaQBhAGwAcwBEAGUAbABlAGcAYQB0AGkAbwBuACcADQAKAGkAZgAgACgAIQAoAFQAZQBzAHQALQBQAGEAdABoACAAJABrAGUAeQApACkAIAB7AA0ACgAgACAAIAAgAG0AZAAgACQAawBlAHkADQAKAH0ADQAKAE4AZQB3AC0ASQB0AGUAbQBQAHIAbwBwAGUAcgB0AHkAIAAtAFAAYQB0AGgAIAAkAGsAZQB5ACAALQBOAGEAbQBlACAAQQBsAGwAbwB3AEYAcgBlAHMAaABDAHIAZQBkAGUAbgB0AGkAYQBsAHMAIAAtAFYAYQBsAHUAZQAgADEAIAAtAFAAcgBvAHAAZQByAHQAeQBUAHkAcABlACAARAB3AG8AcgBkACAALQBGAG8AcgBjAGUADQAKAE4AZQB3AC0ASQB0AGUAbQBQAHIAbwBwAGUAcgB0AHkAIAAtAFAAYQB0AGgAIAAkAGsAZQB5ACAALQBOAGEAbQBlACAAQQBsAGwAbwB3AEYAcgBlAHMAaABDAHIAZQBkAGUAbgB0AGkAYQBsAHMAVwBoAGUAbgBOAFQATABNAE8AbgBsAHkAIAAtAFYAYQBsAHUAZQAgADEAIAAtAFAAcgBvAHAAZQByAHQAeQBUAHkAcABlACAARAB3AG8AcgBkACAALQBGAG8AcgBjAGUADQAKACQAYwByAGUAZABLAGUAeQAgAD0AIABKAG8AaQBuAC0AUABhAHQAaAAgACQAawBlAHkAIAAnAEEAbABsAG8AdwBGAHIAZQBzAGgAQwByAGUAZABlAG4AdABpAGEAbABzACcADQAKAGkAZgAgACgAIQAoAFQAZQBzAHQALQBQAGEAdABoACAAJABjAHIAZQBkAEsAZQB5ACkAKQAgAHsADQAKACAAIAAgACAAbQBkACAAJABjAHIAZQBkAGsAZQB5AA0ACgB9AA0ACgAkAG4AdABsAG0ASwBlAHkAIAA9ACAASgBvAGkAbgAtAFAAYQB0AGgAIAAkAGsAZQB5ACAAJwBBAGwAbABvAHcARgByAGUAcwBoAEMAcgBlAGQAZQBuAHQAaQBhAGwAcwBXAGgAZQBuAE4AVABMAE0ATwBuAGwAeQAnAA0ACgBpAGYAIAAoACEAKABUAGUAcwB0AC0AUABhAHQAaAAgACQAbgB0AGwAbQBLAGUAeQApACkAIAB7AA0ACgAgACAAIAAgAG0AZAAgACQAbgB0AGwAbQBLAGUAeQANAAoAfQANAAoAJABpACAAPQAgADEADQAKACQAYQBsAGwAbwB3AGUAZAAgAHwAJQAgAHsADQAKACAAIAAgACAAIwAgAFMAYwByAGkAcAB0ACAAZABvAGUAcwAgAG4AbwB0ACAAdABhAGsAZQAgAGkAbgB0AG8AIABhAGMAYwBvAHUAbgB0ACAAZQB4AGkAcwB0AGkAbgBnACAAZQBuAHQAcgBpAGUAcwAgAGkAbgAgAHQAaABpAHMAIABrAGUAeQANAAoAIAAgACAAIABOAGUAdwAtAEkAdABlAG0AUAByAG8AcABlAHIAdAB5ACAALQBQAGEAdABoACAAJABjAHIAZQBkAEsAZQB5ACAALQBOAGEAbQBlACAAJABpACAALQBWAGEAbAB1AGUAIAAkAF8AIAAtAFAAcgBvAHAAZQByAHQAeQBUAHkAcABlACAAUwB0AHIAaQBuAGcAIAAtAEYAbwByAGMAZQANAAoAIAAgACAAIABOAGUAdwAtAEkAdABlAG0AUAByAG8AcABlAHIAdAB5ACAALQBQAGEAdABoACAAJABuAHQAbABtAEsAZQB5ACAALQBOAGEAbQBlACAAJABpACAALQBWAGEAbAB1AGUAIAAkAF8AIAAtAFAAcgBvAHAAZQByAHQAeQBUAHkAcABlACAAUwB0AHIAaQBuAGcAIAAtAEYAbwByAGMAZQANAAoAIAAgACAAIAAkAGkAKwArAA0ACgB9AA=={lf}]]})
Execution failures:

1) ExecutionException on brooklyn-ajeo-amp-auto-qa-7zip-rdsm-7zip-oxcr-25b:
java.util.concurrent.ExecutionException: java.lang.NullPointerException
    at com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:299)
    at com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:286)
    at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:116)
    at org.jclouds.concurrent.FutureIterables$1.run(FutureIterables.java:123)
    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: java.lang.NullPointerException
    at org.jclouds.vcloud.director.v1_5.compute.strategy.VCloudDirectorComputeServiceAdapter.createNodeWithGroupEncodedIntoName(VCloudDirectorComputeServiceAdapter.java:175)
    at org.jclouds.compute.strategy.impl.AdaptingComputeServiceStrategies.createNodeWithGroupEncodedIntoName(AdaptingComputeServiceStrategies.java:195)
    at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet$AddNode.call(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:79)
    at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet$AddNode.call(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:63)
    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)
    at java.lang.Thread.getStackTrace(Thread.java:1589)
    at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet.createNodeInGroupWithNameAndTemplate(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:167)
    at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet.execute(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:122)
    at org.jclouds.compute.internal.BaseComputeService.createNodesInGroup(BaseComputeService.java:210)
    at brooklyn.location.jclouds.JcloudsLocation.obtainOnce(JcloudsLocation.java:686)
    at brooklyn.location.jclouds.JcloudsLocation.obtain(JcloudsLocation.java:581)
    at brooklyn.networking.portforwarding.subnet.JcloudsPortforwardingSubnetLocation.obtain(JcloudsPortforwardingSubnetLocation.java:119)
    at brooklyn.networking.portforwarding.subnet.JcloudsPortforwardingSubnetLocation.obtain(JcloudsPortforwardingSubnetLocation.java:57)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5$1.call(MachineLifecycleEffectorTasks.java:287)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5$1.call(MachineLifecycleEffectorTasks.java:285)
    at brooklyn.util.task.Tasks.withBlockingDetails(Tasks.java:99)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5.call(MachineLifecycleEffectorTasks.java:285)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5.call(MachineLifecycleEffectorTasks.java:275)
    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)
    ... 3 more


1 error[s]
Node failures:

0 error[s]

brooklyn.util.exceptions.PropagatedRuntimeException: org.jclouds.compute.RunNodesException: error running 1 node group(brooklyn-ajeo-amp-auto-qa-7zip-rdsm-7zip-oxcr) location(https://svdc.it-solutions.atos.net/api/vdc/56fc1a0a-81dc-468f-bf60-c2d50e21dc6c) image(urn:vcloud:vapptemplate:d5c14365-45b3-4b21-b08a-c4c089334d37) size(micro) options({inboundPorts=[5985, 3389, 1433], userMetadata={Name=brooklyn-ajeo-amp-auto-qa-7zip-rdsm-7zip-oxcr-qkmp, brooklyn-user=amp, brooklyn-app-id=rDsMC2hP, brooklyn-app-name=(auto-qa) 7zip @ Canopy_TAI_TEST_WIN, brooklyn-entity-id=OxcrVsys, brooklyn-entity-name=7zip, brooklyn-server-creation-date=2015-06-15-1700}, networks=[Deployment_Network_01], guestCustomizationScript=[statements=[winrm quickconfig -q & winrm set winrm/config/service/auth @{Basic="true"} & winrm set winrm/config/service/auth @{CredSSP="true"} & winrm set winrm/config/client/auth @{CredSSP="true"} & winrm set winrm/config/client @{AllowUnencrypted="true"} & winrm set winrm/config/service @{AllowUnencrypted="true"} & winrm set winrm/config/winrs @{MaxConcurrentUsers="100"} & winrm set winrm/config/winrs @{MaxMemoryPerShellMB="0"} & winrm set winrm/config/winrs @{MaxProcessesPerShell="0"} & winrm set winrm/config/winrs @{MaxShellsPerUser="0"} & netsh advfirewall firewall add rule name=RDP dir=in protocol=tcp localport=3389 action=allow profile=any & netsh advfirewall firewall add rule name=WinRM dir=in protocol=tcp localport=5985 action=allow profile=any & powershell -EncodedCommand JABSAEQAUAAgAD0AIABHAGUAdAAtAFcAbQBpAE8AYgBqAGUAYwB0ACAALQBDAGwAYQBzAHMAIABXAGkAbgAzADIAXwBUAGUAcgBtAGkAbgBhAGwAUwBlAHIAdgBpAGMAZQBTAGUAdAB0AGkAbgBnACAALQBDAG8AbQBwAHUAdABlAHIATgBhAG0AZQAgACQAZQBuAHYAOgBjAG8AbQBwAHUAdABlAHIAbgBhAG0AZQAgAC0ATgBhAG0AZQBzAHAAYQBjAGUAIAByAG8AbwB0AFwAQwBJAE0AVgAyAFwAVABlAHIAbQBpAG4AYQBsAFMAZQByAHYAaQBjAGUAcwAgAC0AQQB1AHQAaABlAG4AdABpAGMAYQB0AGkAbwBuACAAUABhAGMAawBlAHQAUAByAGkAdgBhAGMAeQANAAoAJABSAEQAUAAuAFMAZQB0AEEAbABsAG8AdwBUAFMAQwBvAG4AbgBlAGMAdABpAG8AbgBzACgAMQAsADEAKQANAAoAUwBlAHQALQBFAHgAZQBjAHUAdABpAG8AbgBQAG8AbABpAGMAeQAgAFUAbgByAGUAcwB0AHIAaQBjAHQAZQBkACAALQBGAG8AcgBjAGUADQAKAFMAZQB0AC0ASQB0AGUAbQAgAFcAUwBNAGEAbgA6AFwAbABvAGMAYQBsAGgAbwBzAHQAXABTAGgAZQBsAGwAXABNAGEAeABDAG8AbgBjAHUAcgByAGUAbgB0AFUAcwBlAHIAcwAgADEAMAAwAA0ACgBTAGUAdAAtAEkAdABlAG0AIABXAFMATQBhAG4AOgBcAGwAbwBjAGEAbABoAG8AcwB0AFwAUwBoAGUAbABsAFwATQBhAHgATQBlAG0AbwByAHkAUABlAHIAUwBoAGUAbABsAE0AQgAgADAADQAKAFMAZQB0AC0ASQB0AGUAbQAgAFcAUwBNAGEAbgA6AFwAbABvAGMAYQBsAGgAbwBzAHQAXABTAGgAZQBsAGwAXABNAGEAeABQAHIAbwBjAGUAcwBzAGUAcwBQAGUAcgBTAGgAZQBsAGwAIAAwAA0ACgBTAGUAdAAtAEkAdABlAG0AIABXAFMATQBhAG4AOgBcAGwAbwBjAGEAbABoAG8AcwB0AFwAUwBoAGUAbABsAFwATQBhAHgAUwBoAGUAbABsAHMAUABlAHIAVQBzAGUAcgAgADAADQAKAE4AZQB3AC0ASQB0AGUAbQBQAHIAbwBwAGUAcgB0AHkAIAAiAEgASwBMAE0AOgBcAFMAeQBzAHQAZQBtAFwAQwB1AHIAcgBlAG4AdABDAG8AbgB0AHIAbwBsAFMAZQB0AFwAQwBvAG4AdAByAG8AbABcAEwAUwBBACIAIAAtAE4AYQBtAGUAIAAiAFMAdQBwAHAAcgBlAHMAcwBFAHgAdABlAG4AZABlAGQAUAByAG8AdABlAGMAdABpAG8AbgAiACAALQBWAGEAbAB1AGUAIAAxACAALQBQAHIAbwBwAGUAcgB0AHkAVAB5AHAAZQAgACIARABXAG8AcgBkACIADQAKACQAYQBsAGwAbwB3AGUAZAAgAD0AIABAACgAJwBXAFMATQBBAE4ALwAqACcAKQANAAoAJABrAGUAeQAgAD0AIAAnAGgAawBsAG0AOgBcAFMATwBGAFQAVwBBAFIARQBcAFAAbwBsAGkAYwBpAGUAcwBcAE0AaQBjAHIAbwBzAG8AZgB0AFwAVwBpAG4AZABvAHcAcwBcAEMAcgBlAGQAZQBuAHQAaQBhAGwAcwBEAGUAbABlAGcAYQB0AGkAbwBuACcADQAKAGkAZgAgACgAIQAoAFQAZQBzAHQALQBQAGEAdABoACAAJABrAGUAeQApACkAIAB7AA0ACgAgACAAIAAgAG0AZAAgACQAawBlAHkADQAKAH0ADQAKAE4AZQB3AC0ASQB0AGUAbQBQAHIAbwBwAGUAcgB0AHkAIAAtAFAAYQB0AGgAIAAkAGsAZQB5ACAALQBOAGEAbQBlACAAQQBsAGwAbwB3AEYAcgBlAHMAaABDAHIAZQBkAGUAbgB0AGkAYQBsAHMAIAAtAFYAYQBsAHUAZQAgADEAIAAtAFAAcgBvAHAAZQByAHQAeQBUAHkAcABlACAARAB3AG8AcgBkACAALQBGAG8AcgBjAGUADQAKAE4AZQB3AC0ASQB0AGUAbQBQAHIAbwBwAGUAcgB0AHkAIAAtAFAAYQB0AGgAIAAkAGsAZQB5ACAALQBOAGEAbQBlACAAQQBsAGwAbwB3AEYAcgBlAHMAaABDAHIAZQBkAGUAbgB0AGkAYQBsAHMAVwBoAGUAbgBOAFQATABNAE8AbgBsAHkAIAAtAFYAYQBsAHUAZQAgADEAIAAtAFAAcgBvAHAAZQByAHQAeQBUAHkAcABlACAARAB3AG8AcgBkACAALQBGAG8AcgBjAGUADQAKACQAYwByAGUAZABLAGUAeQAgAD0AIABKAG8AaQBuAC0AUABhAHQAaAAgACQAawBlAHkAIAAnAEEAbABsAG8AdwBGAHIAZQBzAGgAQwByAGUAZABlAG4AdABpAGEAbABzACcADQAKAGkAZgAgACgAIQAoAFQAZQBzAHQALQBQAGEAdABoACAAJABjAHIAZQBkAEsAZQB5ACkAKQAgAHsADQAKACAAIAAgACAAbQBkACAAJABjAHIAZQBkAGsAZQB5AA0ACgB9AA0ACgAkAG4AdABsAG0ASwBlAHkAIAA9ACAASgBvAGkAbgAtAFAAYQB0AGgAIAAkAGsAZQB5ACAAJwBBAGwAbABvAHcARgByAGUAcwBoAEMAcgBlAGQAZQBuAHQAaQBhAGwAcwBXAGgAZQBuAE4AVABMAE0ATwBuAGwAeQAnAA0ACgBpAGYAIAAoACEAKABUAGUAcwB0AC0AUABhAHQAaAAgACQAbgB0AGwAbQBLAGUAeQApACkAIAB7AA0ACgAgACAAIAAgAG0AZAAgACQAbgB0AGwAbQBLAGUAeQANAAoAfQANAAoAJABpACAAPQAgADEADQAKACQAYQBsAGwAbwB3AGUAZAAgAHwAJQAgAHsADQAKACAAIAAgACAAIwAgAFMAYwByAGkAcAB0ACAAZABvAGUAcwAgAG4AbwB0ACAAdABhAGsAZQAgAGkAbgB0AG8AIABhAGMAYwBvAHUAbgB0ACAAZQB4AGkAcwB0AGkAbgBnACAAZQBuAHQAcgBpAGUAcwAgAGkAbgAgAHQAaABpAHMAIABrAGUAeQANAAoAIAAgACAAIABOAGUAdwAtAEkAdABlAG0AUAByAG8AcABlAHIAdAB5ACAALQBQAGEAdABoACAAJABjAHIAZQBkAEsAZQB5ACAALQBOAGEAbQBlACAAJABpACAALQBWAGEAbAB1AGUAIAAkAF8AIAAtAFAAcgBvAHAAZQByAHQAeQBUAHkAcABlACAAUwB0AHIAaQBuAGcAIAAtAEYAbwByAGMAZQANAAoAIAAgACAAIABOAGUAdwAtAEkAdABlAG0AUAByAG8AcABlAHIAdAB5ACAALQBQAGEAdABoACAAJABuAHQAbABtAEsAZQB5ACAALQBOAGEAbQBlACAAJABpACAALQBWAGEAbAB1AGUAIAAkAF8AIAAtAFAAcgBvAHAAZQByAHQAeQBUAHkAcABlACAAUwB0AHIAaQBuAGcAIAAtAEYAbwByAGMAZQANAAoAIAAgACAAIAAkAGkAKwArAA0ACgB9AA=={lf}]]})
Execution failures:

1) ExecutionException on brooklyn-ajeo-amp-auto-qa-7zip-rdsm-7zip-oxcr-25b:
java.util.concurrent.ExecutionException: java.lang.NullPointerException
    at com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:299)
    at com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:286)
    at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:116)
    at org.jclouds.concurrent.FutureIterables$1.run(FutureIterables.java:123)
    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: java.lang.NullPointerException
    at org.jclouds.vcloud.director.v1_5.compute.strategy.VCloudDirectorComputeServiceAdapter.createNodeWithGroupEncodedIntoName(VCloudDirectorComputeServiceAdapter.java:175)
    at org.jclouds.compute.strategy.impl.AdaptingComputeServiceStrategies.createNodeWithGroupEncodedIntoName(AdaptingComputeServiceStrategies.java:195)
    at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet$AddNode.call(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:79)
    at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet$AddNode.call(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:63)
    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)
    at java.lang.Thread.getStackTrace(Thread.java:1589)
    at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet.createNodeInGroupWithNameAndTemplate(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:167)
    at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet.execute(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:122)
    at org.jclouds.compute.internal.BaseComputeService.createNodesInGroup(BaseComputeService.java:210)
    at brooklyn.location.jclouds.JcloudsLocation.obtainOnce(JcloudsLocation.java:686)
    at brooklyn.location.jclouds.JcloudsLocation.obtain(JcloudsLocation.java:581)
    at brooklyn.networking.portforwarding.subnet.JcloudsPortforwardingSubnetLocation.obtain(JcloudsPortforwardingSubnetLocation.java:119)
    at brooklyn.networking.portforwarding.subnet.JcloudsPortforwardingSubnetLocation.obtain(JcloudsPortforwardingSubnetLocation.java:57)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5$1.call(MachineLifecycleEffectorTasks.java:287)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5$1.call(MachineLifecycleEffectorTasks.java:285)
    at brooklyn.util.task.Tasks.withBlockingDetails(Tasks.java:99)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5.call(MachineLifecycleEffectorTasks.java:285)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5.call(MachineLifecycleEffectorTasks.java:275)
    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)
    ... 3 more


1 error[s]
Node failures:

0 error[s]
    at brooklyn.util.exceptions.Exceptions.propagate(Exceptions.java:97)
    at brooklyn.location.jclouds.JcloudsLocation.obtainOnce(JcloudsLocation.java:969)
    at brooklyn.location.jclouds.JcloudsLocation.obtain(JcloudsLocation.java:581)
    at brooklyn.networking.portforwarding.subnet.JcloudsPortforwardingSubnetLocation.obtain(JcloudsPortforwardingSubnetLocation.java:119)
    at brooklyn.networking.portforwarding.subnet.JcloudsPortforwardingSubnetLocation.obtain(JcloudsPortforwardingSubnetLocation.java:57)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5$1.call(MachineLifecycleEffectorTasks.java:287)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5$1.call(MachineLifecycleEffectorTasks.java:285)
    at brooklyn.util.task.Tasks.withBlockingDetails(Tasks.java:99)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5.call(MachineLifecycleEffectorTasks.java:285)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5.call(MachineLifecycleEffectorTasks.java:275)
    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)
Caused by: org.jclouds.compute.RunNodesException: error running 1 node group(brooklyn-ajeo-amp-auto-qa-7zip-rdsm-7zip-oxcr) location(https://svdc.it-solutions.atos.net/api/vdc/56fc1a0a-81dc-468f-bf60-c2d50e21dc6c) image(urn:vcloud:vapptemplate:d5c14365-45b3-4b21-b08a-c4c089334d37) size(micro) options({inboundPorts=[5985, 3389, 1433], userMetadata={Name=brooklyn-ajeo-amp-auto-qa-7zip-rdsm-7zip-oxcr-qkmp, brooklyn-user=amp, brooklyn-app-id=rDsMC2hP, brooklyn-app-name=(auto-qa) 7zip @ Canopy_TAI_TEST_WIN, brooklyn-entity-id=OxcrVsys, brooklyn-entity-name=7zip, brooklyn-server-creation-date=2015-06-15-1700}, networks=[Deployment_Network_01], guestCustomizationScript=[statements=[winrm quickconfig -q & winrm set winrm/config/service/auth @{Basic="true"} & winrm set winrm/config/service/auth @{CredSSP="true"} & winrm set winrm/config/client/auth @{CredSSP="true"} & winrm set winrm/config/client @{AllowUnencrypted="true"} & winrm set winrm/config/service @{AllowUnencrypted="true"} & winrm set winrm/config/winrs @{MaxConcurrentUsers="100"} & winrm set winrm/config/winrs @{MaxMemoryPerShellMB="0"} & winrm set winrm/config/winrs @{MaxProcessesPerShell="0"} & winrm set winrm/config/winrs @{MaxShellsPerUser="0"} & netsh advfirewall firewall add rule name=RDP dir=in protocol=tcp localport=3389 action=allow profile=any & netsh advfirewall firewall add rule name=WinRM dir=in protocol=tcp localport=5985 action=allow profile=any & powershell -EncodedCommand JABSAEQAUAAgAD0AIABHAGUAdAAtAFcAbQBpAE8AYgBqAGUAYwB0ACAALQBDAGwAYQBzAHMAIABXAGkAbgAzADIAXwBUAGUAcgBtAGkAbgBhAGwAUwBlAHIAdgBpAGMAZQBTAGUAdAB0AGkAbgBnACAALQBDAG8AbQBwAHUAdABlAHIATgBhAG0AZQAgACQAZQBuAHYAOgBjAG8AbQBwAHUAdABlAHIAbgBhAG0AZQAgAC0ATgBhAG0AZQBzAHAAYQBjAGUAIAByAG8AbwB0AFwAQwBJAE0AVgAyAFwAVABlAHIAbQBpAG4AYQBsAFMAZQByAHYAaQBjAGUAcwAgAC0AQQB1AHQAaABlAG4AdABpAGMAYQB0AGkAbwBuACAAUABhAGMAawBlAHQAUAByAGkAdgBhAGMAeQANAAoAJABSAEQAUAAuAFMAZQB0AEEAbABsAG8AdwBUAFMAQwBvAG4AbgBlAGMAdABpAG8AbgBzACgAMQAsADEAKQANAAoAUwBlAHQALQBFAHgAZQBjAHUAdABpAG8AbgBQAG8AbABpAGMAeQAgAFUAbgByAGUAcwB0AHIAaQBjAHQAZQBkACAALQBGAG8AcgBjAGUADQAKAFMAZQB0AC0ASQB0AGUAbQAgAFcAUwBNAGEAbgA6AFwAbABvAGMAYQBsAGgAbwBzAHQAXABTAGgAZQBsAGwAXABNAGEAeABDAG8AbgBjAHUAcgByAGUAbgB0AFUAcwBlAHIAcwAgADEAMAAwAA0ACgBTAGUAdAAtAEkAdABlAG0AIABXAFMATQBhAG4AOgBcAGwAbwBjAGEAbABoAG8AcwB0AFwAUwBoAGUAbABsAFwATQBhAHgATQBlAG0AbwByAHkAUABlAHIAUwBoAGUAbABsAE0AQgAgADAADQAKAFMAZQB0AC0ASQB0AGUAbQAgAFcAUwBNAGEAbgA6AFwAbABvAGMAYQBsAGgAbwBzAHQAXABTAGgAZQBsAGwAXABNAGEAeABQAHIAbwBjAGUAcwBzAGUAcwBQAGUAcgBTAGgAZQBsAGwAIAAwAA0ACgBTAGUAdAAtAEkAdABlAG0AIABXAFMATQBhAG4AOgBcAGwAbwBjAGEAbABoAG8AcwB0AFwAUwBoAGUAbABsAFwATQBhAHgAUwBoAGUAbABsAHMAUABlAHIAVQBzAGUAcgAgADAADQAKAE4AZQB3AC0ASQB0AGUAbQBQAHIAbwBwAGUAcgB0AHkAIAAiAEgASwBMAE0AOgBcAFMAeQBzAHQAZQBtAFwAQwB1AHIAcgBlAG4AdABDAG8AbgB0AHIAbwBsAFMAZQB0AFwAQwBvAG4AdAByAG8AbABcAEwAUwBBACIAIAAtAE4AYQBtAGUAIAAiAFMAdQBwAHAAcgBlAHMAcwBFAHgAdABlAG4AZABlAGQAUAByAG8AdABlAGMAdABpAG8AbgAiACAALQBWAGEAbAB1AGUAIAAxACAALQBQAHIAbwBwAGUAcgB0AHkAVAB5AHAAZQAgACIARABXAG8AcgBkACIADQAKACQAYQBsAGwAbwB3AGUAZAAgAD0AIABAACgAJwBXAFMATQBBAE4ALwAqACcAKQANAAoAJABrAGUAeQAgAD0AIAAnAGgAawBsAG0AOgBcAFMATwBGAFQAVwBBAFIARQBcAFAAbwBsAGkAYwBpAGUAcwBcAE0AaQBjAHIAbwBzAG8AZgB0AFwAVwBpAG4AZABvAHcAcwBcAEMAcgBlAGQAZQBuAHQAaQBhAGwAcwBEAGUAbABlAGcAYQB0AGkAbwBuACcADQAKAGkAZgAgACgAIQAoAFQAZQBzAHQALQBQAGEAdABoACAAJABrAGUAeQApACkAIAB7AA0ACgAgACAAIAAgAG0AZAAgACQAawBlAHkADQAKAH0ADQAKAE4AZQB3AC0ASQB0AGUAbQBQAHIAbwBwAGUAcgB0AHkAIAAtAFAAYQB0AGgAIAAkAGsAZQB5ACAALQBOAGEAbQBlACAAQQBsAGwAbwB3AEYAcgBlAHMAaABDAHIAZQBkAGUAbgB0AGkAYQBsAHMAIAAtAFYAYQBsAHUAZQAgADEAIAAtAFAAcgBvAHAAZQByAHQAeQBUAHkAcABlACAARAB3AG8AcgBkACAALQBGAG8AcgBjAGUADQAKAE4AZQB3AC0ASQB0AGUAbQBQAHIAbwBwAGUAcgB0AHkAIAAtAFAAYQB0AGgAIAAkAGsAZQB5ACAALQBOAGEAbQBlACAAQQBsAGwAbwB3AEYAcgBlAHMAaABDAHIAZQBkAGUAbgB0AGkAYQBsAHMAVwBoAGUAbgBOAFQATABNAE8AbgBsAHkAIAAtAFYAYQBsAHUAZQAgADEAIAAtAFAAcgBvAHAAZQByAHQAeQBUAHkAcABlACAARAB3AG8AcgBkACAALQBGAG8AcgBjAGUADQAKACQAYwByAGUAZABLAGUAeQAgAD0AIABKAG8AaQBuAC0AUABhAHQAaAAgACQAawBlAHkAIAAnAEEAbABsAG8AdwBGAHIAZQBzAGgAQwByAGUAZABlAG4AdABpAGEAbABzACcADQAKAGkAZgAgACgAIQAoAFQAZQBzAHQALQBQAGEAdABoACAAJABjAHIAZQBkAEsAZQB5ACkAKQAgAHsADQAKACAAIAAgACAAbQBkACAAJABjAHIAZQBkAGsAZQB5AA0ACgB9AA0ACgAkAG4AdABsAG0ASwBlAHkAIAA9ACAASgBvAGkAbgAtAFAAYQB0AGgAIAAkAGsAZQB5ACAAJwBBAGwAbABvAHcARgByAGUAcwBoAEMAcgBlAGQAZQBuAHQAaQBhAGwAcwBXAGgAZQBuAE4AVABMAE0ATwBuAGwAeQAnAA0ACgBpAGYAIAAoACEAKABUAGUAcwB0AC0AUABhAHQAaAAgACQAbgB0AGwAbQBLAGUAeQApACkAIAB7AA0ACgAgACAAIAAgAG0AZAAgACQAbgB0AGwAbQBLAGUAeQANAAoAfQANAAoAJABpACAAPQAgADEADQAKACQAYQBsAGwAbwB3AGUAZAAgAHwAJQAgAHsADQAKACAAIAAgACAAIwAgAFMAYwByAGkAcAB0ACAAZABvAGUAcwAgAG4AbwB0ACAAdABhAGsAZQAgAGkAbgB0AG8AIABhAGMAYwBvAHUAbgB0ACAAZQB4AGkAcwB0AGkAbgBnACAAZQBuAHQAcgBpAGUAcwAgAGkAbgAgAHQAaABpAHMAIABrAGUAeQANAAoAIAAgACAAIABOAGUAdwAtAEkAdABlAG0AUAByAG8AcABlAHIAdAB5ACAALQBQAGEAdABoACAAJABjAHIAZQBkAEsAZQB5ACAALQBOAGEAbQBlACAAJABpACAALQBWAGEAbAB1AGUAIAAkAF8AIAAtAFAAcgBvAHAAZQByAHQAeQBUAHkAcABlACAAUwB0AHIAaQBuAGcAIAAtAEYAbwByAGMAZQANAAoAIAAgACAAIABOAGUAdwAtAEkAdABlAG0AUAByAG8AcABlAHIAdAB5ACAALQBQAGEAdABoACAAJABuAHQAbABtAEsAZQB5ACAALQBOAGEAbQBlACAAJABpACAALQBWAGEAbAB1AGUAIAAkAF8AIAAtAFAAcgBvAHAAZQByAHQAeQBUAHkAcABlACAAUwB0AHIAaQBuAGcAIAAtAEYAbwByAGMAZQANAAoAIAAgACAAIAAkAGkAKwArAA0ACgB9AA=={lf}]]})
Execution failures:

1) ExecutionException on brooklyn-ajeo-amp-auto-qa-7zip-rdsm-7zip-oxcr-25b:
java.util.concurrent.ExecutionException: java.lang.NullPointerException
    at com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:299)
    at com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:286)
    at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:116)
    at org.jclouds.concurrent.FutureIterables$1.run(FutureIterables.java:123)
    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: java.lang.NullPointerException
    at org.jclouds.vcloud.director.v1_5.compute.strategy.VCloudDirectorComputeServiceAdapter.createNodeWithGroupEncodedIntoName(VCloudDirectorComputeServiceAdapter.java:175)
    at org.jclouds.compute.strategy.impl.AdaptingComputeServiceStrategies.createNodeWithGroupEncodedIntoName(AdaptingComputeServiceStrategies.java:195)
    at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet$AddNode.call(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:79)
    at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet$AddNode.call(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:63)
    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)
    at java.lang.Thread.getStackTrace(Thread.java:1589)
    at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet.createNodeInGroupWithNameAndTemplate(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:167)
    at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet.execute(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:122)
    at org.jclouds.compute.internal.BaseComputeService.createNodesInGroup(BaseComputeService.java:210)
    at brooklyn.location.jclouds.JcloudsLocation.obtainOnce(JcloudsLocation.java:686)
    at brooklyn.location.jclouds.JcloudsLocation.obtain(JcloudsLocation.java:581)
    at brooklyn.networking.portforwarding.subnet.JcloudsPortforwardingSubnetLocation.obtain(JcloudsPortforwardingSubnetLocation.java:119)
    at brooklyn.networking.portforwarding.subnet.JcloudsPortforwardingSubnetLocation.obtain(JcloudsPortforwardingSubnetLocation.java:57)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5$1.call(MachineLifecycleEffectorTasks.java:287)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5$1.call(MachineLifecycleEffectorTasks.java:285)
    at brooklyn.util.task.Tasks.withBlockingDetails(Tasks.java:99)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5.call(MachineLifecycleEffectorTasks.java:285)
    at brooklyn.entity.software.MachineLifecycleEffectorTasks$5.call(MachineLifecycleEffectorTasks.java:275)
    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)
    ... 3 more


1 error[s]
Node failures:

0 error[s]
    at org.jclouds.compute.internal.BaseComputeService.createNodesInGroup(BaseComputeService.java:222)
    at brooklyn.location.jclouds.JcloudsLocation.obtainOnce(JcloudsLocation.java:686)
    ... 14 more

[andreaturli]

@aledsage, thanks for reporting this issue.

Unfortunately, I can't reproduce it using release/1.9.0-rc3 version. Thoughts?

[aledsage]

Fixed in #13

[aledsage]

We hit this error again. We got a nicer message (from the fix in #13) but fundamentally the same problem:

2015-10-23 10:08:28,491 ERROR jclouds.compute [user thread 0]: createNodesInGroup(brooklyn-nwo0mh-amp-auto-qa-7zip-s-jwvf-7zip-puzi), completed: 0/1, errors: 1, rate: 604397ms/op
java.util.concurrent.ExecutionException: java.lang.NullPointerException: composedVApp urn:vcloud:vapp:430df933-6baf-470f-a27a-b27a8f0cd74b must not have null children
        at com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:299) ~[guava-16.0.1.jar:na]
        at com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:286) ~[guava-16.0.1.jar:na]
        at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:116) ~[guava-16.0.1.jar:na]
        at org.jclouds.concurrent.FutureIterables$1.run(FutureIterables.java:123) ~[jclouds-core-1.9.1.jar:1.9.1]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_71]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_71]
        at java.lang.Thread.run(Thread.java:745) [na:1.7.0_71]
Caused by: java.lang.NullPointerException: composedVApp urn:vcloud:vapp:430df933-6baf-470f-a27a-b27a8f0cd74b must not have null children
        at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:229) ~[guava-16.0.1.jar:na]
        at org.jclouds.vcloud.director.v1_5.compute.strategy.VCloudDirectorComputeServiceAdapter.createNodeWithGroupEncodedIntoName(VCloudDirectorComputeServiceAdapter.java:191) ~[vcloud-director-1.9.1-20151022.1606.jar:1.9.1-20151022.1606]
        at org.jclouds.compute.strategy.impl.AdaptingComputeServiceStrategies.createNodeWithGroupEncodedIntoName(AdaptingComputeServiceStrategies.java:195) ~[jclouds-compute-1.9.1.jar:1.9.1]
        at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet$AddNode.call(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:79) ~[jclouds-compute-1.9.1.jar:1.9.1]
        at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet$AddNode.call(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:63) ~[jclouds-compute-1.9.1.jar:1.9.1]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_71]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_71]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_71]
        at java.lang.Thread.run(Thread.java:745) [na:1.7.0_71]
        at java.lang.Thread.getStackTrace(Thread.java:1589) [na:1.7.0_71]
        at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet.createNodeInGroupWithNameAndTemplate(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:167) ~[jclouds-compute-1.9.1.jar:1.9.1]
        at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet.execute(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:122) ~[jclouds-compute-1.9.1.jar:1.9.1]
        at org.jclouds.compute.internal.BaseComputeService.createNodesInGroup(BaseComputeService.java:210) ~[jclouds-compute-1.9.1.jar:1.9.1]
        at org.apache.brooklyn.location.jclouds.JcloudsLocation.obtainOnce(JcloudsLocation.java:712) ~[brooklyn-locations-jclouds-0.9.0-20151023.0054.jar:0.9.0-20151023.0054]
        at org.apache.brooklyn.location.jclouds.JcloudsLocation.obtain(JcloudsLocation.java:607) ~[brooklyn-locations-jclouds-0.9.0-20151023.0054.jar:0.9.0-20151023.0054]
        at brooklyn.networking.portforwarding.subnet.JcloudsPortforwardingSubnetLocation.obtain(JcloudsPortforwardingSubnetLocation.java:121) ~[brooklyn-networking-portforwarding-0.9.0-20151023.0054.jar:0.9.0-20151023.0054]
        at brooklyn.networking.portforwarding.subnet.JcloudsPortforwardingSubnetLocation.obtain(JcloudsPortforwardingSubnetLocation.java:59) ~[brooklyn-networking-portforwarding-0.9.0-20151023.0054.jar:0.9.0-20151023.0054]
        at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$ObtainLocationTask.call(MachineLifecycleEffectorTasks.java:406) ~[brooklyn-software-base-0.9.0-20151023.0054.jar:0.9.0-20151023.0054]
        at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$ObtainLocationTask.call(MachineLifecycleEffectorTasks.java:396) ~[brooklyn-software-base-0.9.0-20151023.0054.jar:0.9.0-20151023.0054]
        at org.apache.brooklyn.util.core.task.Tasks.withBlockingDetails(Tasks.java:98) ~[brooklyn-core-0.9.0-20151023.0054.jar:0.9.0-20151023.0054]
        at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$ProvisionMachineTask.call(MachineLifecycleEffectorTasks.java:380) ~[brooklyn-software-base-0.9.0-20151023.0054.jar:0.9.0-20151023.0054]
        at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$ProvisionMachineTask.call(MachineLifecycleEffectorTasks.java:364) ~[brooklyn-software-base-0.9.0-20151023.0054.jar:0.9.0-20151023.0054]
        at org.apache.brooklyn.util.core.task.DynamicSequentialTask$DstJob.call(DynamicSequentialTask.java:342) ~[brooklyn-core-0.9.0-20151023.0054.jar:0.9.0-20151023.0054]
        at org.apache.brooklyn.util.core.task.BasicExecutionManager$SubmissionCallable.call(BasicExecutionManager.java:468) ~[brooklyn-core-0.9.0-20151023.0054.jar:0.9.0-20151023.0054]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_71]
        ... 3 common frames omitted

[aledsage]

We provisioned a VM, and then polled for exactly 10 minutes for the task's completion (it was still in-progress at that time). We then got the vApp, and threw an exception because it had no children.

Are we timing out the task-polling after 10 minutes, and then just assuming it was successful, rather than checking?!

The VCloudDirectorComputeServiceAdapter.retryTaskSuccess has a timeout of 5 minutes. We have a for loop to wait for each task of the vApp. If it had 2 tasks that hadn't finished, we'd continue after 10 minutes as though the task had completed (logging at trace whether the predicate returned true or false, but we don't capture trace by default).

2015-10-23 09:58:26,376 DEBUG jclouds.headers [user thread 0]: >> POST https:// acme.net/api/vdc/56fc1a0a-81dc-468f-bf60-c2d50e21dc6c/action/composeVApp HTTP/1.1
2015-10-23 09:58:28,079 DEBUG jclouds.headers [user thread 0]: >> GET https:// acme.net/api/task/11994fa3-3ee9-4192-8695-26fa967bf7c2 HTTP/1.1
2015-10-23 09:58:28,219 DEBUG jclouds.headers [user thread 0]: >> GET https:// acme.net/api/task/11994fa3-3ee9-4192-8695-26fa967bf7c2 HTTP/1.1
2015-10-23 09:58:28,350 DEBUG jclouds.headers [user thread 0]: >> GET https:// acme.net/api/task/11994fa3-3ee9-4192-8695-26fa967bf7c2 HTTP/1.1
...
2015-10-23 10:08:27,836 DEBUG jclouds.headers [user thread 0]: >> GET https:// acme.net/api/task/11994fa3-3ee9-4192-8695-26fa967bf7c2 HTTP/1.1
2015-10-23 10:08:28,143 DEBUG jclouds.headers [user thread 0]: >> GET https:// acme.net/api/task/11994fa3-3ee9-4192-8695-26fa967bf7c2 HTTP/1.1
2015-10-23 10:08:28,195 DEBUG jclouds.headers [user thread 0]: >> GET https:// acme.net/api/vApp/vapp-430df933-6baf-470f-a27a-b27a8f0cd74b HTTP/1.1

Here are details of the last GET task, and GET vApp calls (the other task retrievals also showed Progress as "1":

2015-10-23 10:08:28,143 DEBUG o.j.r.i.InvokeHttpMethod [user thread 0]: >> invoking TaskApi.get
2015-10-23 10:08:28,143 DEBUG o.j.h.o.OkHttpCommandExecutorService [user thread 0]: Sending request -238933703: GET https:// acme.net/api/task/11994fa3-3ee9-4192-8695-26fa967bf7c2 HTTP/1.1
2015-10-23 10:08:28,143 DEBUG jclouds.headers [user thread 0]: >> GET https:// acme.net/api/task/11994fa3-3ee9-4192-8695-26fa967bf7c2 HTTP/1.1
2015-10-23 10:08:28,143 DEBUG jclouds.headers [user thread 0]: >> x-vcloud-authorization: 2lvImEM8MaKm17EA3ppnJSNFnQY0NZ1lZlYNOAAivbU=
2015-10-23 10:08:28,143 DEBUG jclouds.headers [user thread 0]: >> Cookie: vcloud-token=2lvImEM8MaKm17EA3ppnJSNFnQY0NZ1lZlYNOAAivbU=
2015-10-23 10:08:28,144 DEBUG jclouds.headers [user thread 0]: >> Accept: application/*+xml;version=1.5
2015-10-23 10:08:28,180 DEBUG o.j.h.o.OkHttpCommandExecutorService [user thread 0]: Receiving response -238933703: HTTP/1.1 200 OK
2015-10-23 10:08:28,180 DEBUG jclouds.headers [user thread 0]: << HTTP/1.1 200 OK
2015-10-23 10:08:28,180 DEBUG jclouds.headers [user thread 0]: << Date: Fri, 23 Oct 2015 09:08:28 GMT
2015-10-23 10:08:28,180 DEBUG jclouds.headers [user thread 0]: << Date: Fri, 23 Oct 2015 09:08:28 GMT
2015-10-23 10:08:28,180 DEBUG jclouds.headers [user thread 0]: << OkHttp-Received-Millis: 1445591308180
2015-10-23 10:08:28,180 DEBUG jclouds.headers [user thread 0]: << OkHttp-Selected-Protocol: http/1.1
2015-10-23 10:08:28,180 DEBUG jclouds.headers [user thread 0]: << OkHttp-Sent-Millis: 1445591308144
2015-10-23 10:08:28,180 DEBUG jclouds.headers [user thread 0]: << Vary: Accept-Encoding
2015-10-23 10:08:28,181 DEBUG jclouds.headers [user thread 0]: << Content-Type: application/vnd.vmware.vcloud.task+xml;version=1.5
2015-10-23 10:08:28,181 DEBUG jclouds.wire [user thread 0]: << "<?xml version="1.0" encoding="UTF-8"?>[\n]"
2015-10-23 10:08:28,181 DEBUG jclouds.wire [user thread 0]: << "<Task xmlns="http://www.vmware.com/vcloud/v1.5" status="running" startTime="2015-10-23T10:58:27.397+02:00" operationName="vdcComposeVapp" operation="Composing Virtual Application brooklyn-nwo0mh-amp-auto-qa-7zip-s-jwvf-7zip-puzi-cad(430df933-6baf-470f-a27a-b27a8f0cd74b)" expiryTime="2016-01-21T10:58:27.397+01:00" name="task" id="urn:vcloud:task:11994fa3-3ee9-4192-8695-26fa967bf7c2" type="application/vnd.vmware.vcloud.task+xml" href="https:// acme.net/api/task/11994fa3-3ee9-4192-8695-26fa967bf7c2" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://www.vmware.com/vcloud/v1.5 http:// acme.net/api/v1.5/schema/master.xsd">[\n]"
2015-10-23 10:08:28,181 DEBUG jclouds.wire [user thread 0]: << "    <Link rel="task:cancel" href="https:// acme.net/api/task/11994fa3-3ee9-4192-8695-26fa967bf7c2/action/cancel"/>[\n]"
2015-10-23 10:08:28,181 DEBUG jclouds.wire [user thread 0]: << "    <Owner type="application/vnd.vmware.vcloud.vApp+xml" name="brooklyn-nwo0mh-amp-auto-qa-7zip-s-jwvf-7zip-puzi-cad" href="https:// acme.net/api/vApp/vapp-430df933-6baf-470f-a27a-b27a8f0cd74b"/>[\n]"
2015-10-23 10:08:28,181 DEBUG jclouds.wire [user thread 0]: << "    <User type="application/vnd.vmware.admin.user+xml" name="martin" href="https:// acme.net/api/admin/user/6c26165c-9ec1-4a6a-92c5-7e3e33af4c1d"/>[\n]"
2015-10-23 10:08:28,182 DEBUG jclouds.wire [user thread 0]: << "    <Organization type="application/vnd.vmware.vcloud.org+xml" name="acme-2_01" href="https:// acme.net/api/org/e49fb225-454e-4ef0-8fb8-f89f5491a499"/>[\n]"
2015-10-23 10:08:28,182 DEBUG jclouds.wire [user thread 0]: << "    <Progress>1</Progress>[\n]"
2015-10-23 10:08:28,182 DEBUG jclouds.wire [user thread 0]: << "</Task>[\n]"

2015-10-23 10:08:28,195 DEBUG o.j.h.o.OkHttpCommandExecutorService [user thread 0]: Sending request -1878204081: GET https:// acme.net/api/vApp/vapp-430df933-6baf-470f-a27a-b27a8f0cd74b HTTP/1.1
2015-10-23 10:08:28,195 DEBUG jclouds.headers [user thread 0]: >> GET https:// acme.net/api/vApp/vapp-430df933-6baf-470f-a27a-b27a8f0cd74b HTTP/1.1
2015-10-23 10:08:28,195 DEBUG jclouds.headers [user thread 0]: >> x-vcloud-authorization: 2lvImEM8MaKm17EA3ppnJSNFnQY0NZ1lZlYNOAAivbU=
2015-10-23 10:08:28,195 DEBUG jclouds.headers [user thread 0]: >> Cookie: vcloud-token=2lvImEM8MaKm17EA3ppnJSNFnQY0NZ1lZlYNOAAivbU=
2015-10-23 10:08:28,195 DEBUG jclouds.headers [user thread 0]: >> Accept: application/*+xml;version=1.5
2015-10-23 10:08:28,353 DEBUG o.j.h.o.OkHttpCommandExecutorService [user thread 0]: Receiving response -1878204081: HTTP/1.1 200 OK
2015-10-23 10:08:28,353 DEBUG jclouds.headers [user thread 0]: << HTTP/1.1 200 OK
2015-10-23 10:08:28,353 DEBUG jclouds.headers [user thread 0]: << Date: Fri, 23 Oct 2015 09:08:28 GMT
2015-10-23 10:08:28,353 DEBUG jclouds.headers [user thread 0]: << Date: Fri, 23 Oct 2015 09:08:28 GMT
2015-10-23 10:08:28,353 DEBUG jclouds.headers [user thread 0]: << OkHttp-Received-Millis: 1445591308353
2015-10-23 10:08:28,353 DEBUG jclouds.headers [user thread 0]: << OkHttp-Selected-Protocol: http/1.1
2015-10-23 10:08:28,353 DEBUG jclouds.headers [user thread 0]: << OkHttp-Sent-Millis: 1445591308196
2015-10-23 10:08:28,353 DEBUG jclouds.headers [user thread 0]: << Vary: Accept-Encoding
2015-10-23 10:08:28,353 DEBUG jclouds.headers [user thread 0]: << Content-Type: application/vnd.vmware.vcloud.vApp+xml;version=1.5
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "<?xml version="1.0" encoding="UTF-8"?>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "<VApp xmlns="http://www.vmware.com/vcloud/v1.5" ovfDescriptorUploaded="true" deployed="false" status="0" name="brooklyn-nwo0mh-amp-auto-qa-7zip-s-jwvf-7zip-puzi-cad" id="urn:vcloud:vapp:430df933-6baf-470f-a27a-b27a8f0cd74b" type="application/vnd.vmware.vcloud.vApp+xml" href="https:// acme.net/api/vApp/vapp-430df933-6baf-470f-a27a-b27a8f0cd74b" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://www.vmware.com/vcloud/v1.5 http:// acme.net/api/v1.5/schema/master.xsd">[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "    <Link rel="down" type="application/vnd.vmware.vcloud.vAppNetwork+xml" name="Deployment_Network_01" href="https:// acme.net/api/network/322ffc9b-6958-48c0-9aea-328ca2835341"/>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "    <Link rel="down" type="application/vnd.vmware.vcloud.controlAccess+xml" href="https:// acme.net/api/vApp/vapp-430df933-6baf-470f-a27a-b27a8f0cd74b/controlAccess/"/>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "    <Link rel="up" type="application/vnd.vmware.vcloud.vdc+xml" href="https:// acme.net/api/vdc/56fc1a0a-81dc-468f-bf60-c2d50e21dc6c"/>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "    <Link rel="down" type="application/vnd.vmware.vcloud.owner+xml" href="https:// acme.net/api/vApp/vapp-430df933-6baf-470f-a27a-b27a8f0cd74b/owner"/>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "    <Link rel="down" type="application/vnd.vmware.vcloud.metadata+xml" href="https:// acme.net/api/vApp/vapp-430df933-6baf-470f-a27a-b27a8f0cd74b/metadata"/>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "    <Tasks>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "        <Task status="running" startTime="2015-10-23T10:58:27.397+02:00" operationName="vdcComposeVapp" operation="Composing Virtual Application brooklyn-nwo0mh-amp-auto-qa-7zip-s-jwvf-7zip-puzi-cad(430df933-6baf-470f-a27a-b27a8f0cd74b)" expiryTime="2016-01-21T10:58:27.397+01:00" name="task" id="urn:vcloud:task:11994fa3-3ee9-4192-8695-26fa967bf7c2" type="application/vnd.vmware.vcloud.task+xml" href="https:// acme.net/api/task/11994fa3-3ee9-4192-8695-26fa967bf7c2">[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "            <Link rel="task:cancel" href="https:// acme.net/api/task/11994fa3-3ee9-4192-8695-26fa967bf7c2/action/cancel"/>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "            <Owner type="application/vnd.vmware.vcloud.vApp+xml" name="brooklyn-nwo0mh-amp-auto-qa-7zip-s-jwvf-7zip-puzi-cad" href="https:// acme.net/api/vApp/vapp-430df933-6baf-470f-a27a-b27a8f0cd74b"/>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "            <User type="application/vnd.vmware.admin.user+xml" name="martin" href="https:// acme.net/api/admin/user/6c26165c-9ec1-4a6a-92c5-7e3e33af4c1d"/>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "            <Organization type="application/vnd.vmware.vcloud.org+xml" name="acme-2_01" href="https:// acme.net/api/org/e49fb225-454e-4ef0-8fb8-f89f5491a499"/>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "            <Progress>1</Progress>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "        </Task>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "    </Tasks>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "    <Owner type="application/vnd.vmware.vcloud.owner+xml">[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "        <User type="application/vnd.vmware.admin.user+xml" name="martin" href="https:// acme.net/api/admin/user/6c26165c-9ec1-4a6a-92c5-7e3e33af4c1d"/>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "    </Owner>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "    <InMaintenanceMode>false</InMaintenanceMode>[\n]"
2015-10-23 10:08:28,394 DEBUG jclouds.wire [user thread 0]: << "</VApp>[\n]"

[ygy]

Most probably the problem is reproducible during Azure deployments too.
cloudsoft/jclouds-labs#1