[JCLOUDS-1530] azurecompute-arm retry/timeout too aggressive?

• Type: Bug
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Affects Version/s: 2.2.0
• Component/s: jclouds-compute
• Labels: azurecompute-arm
• Assignee: Unassigned
• Reporter: Markus Kuppe
• Created: 27/Nov/19 18:14
• Updated: 15/Mar/21 01:53

Description

Trying to launch an Azure virtual machine (Ubuntu 18.04) fails with:

org.jclouds.compute.RunNodesException: error running 1 node group(azure-b4e90bfc-8f15-4c40-b546-a41f61ee7345) location(eastus) image(Canonical) size(Standard_D14) options({loginPasswordPresent=true, taskName=bootstrap, inboundPorts=[22, 80, 443], scriptPresent=true, securityGroups=[/subscriptions/f1af7595-4102-45e0-8f00-dde13e40f865/resourceGroups/azure-b4e90bfc-8f15-4c40-b546-a41f61ee7345/providers/Microsoft.Network/networkSecurityGroups/jclouds-azure-b4e90bfc-8f15-4c40-b546-a41f61ee7345], userMetadata={jclouds_group=azure-b4e90bfc-8f15-4c40-b546-a41f61ee7345}, resourceGroup=azure-b4e90bfc-8f15-4c40-b546-a41f61ee7345, ipOptions=[IpOptions{subnet=/subscriptions/f1af7595-4102-45e0-8f00-dde13e40f865/resourceGroups/azure-b4e90bfc-8f15-4c40-b546-a41f61ee7345/providers/Microsoft.Network/virtualNetworks/jclouds-azure-b4e90bfc-8f15-4c40-b546-a41f61ee7345/subnets/jclouds-azure-b4e90bfc-8f15-4c40-b546-a41f61ee7345, address=Optional.absent(), allocateNewPublicIp=true, publicIpId=null}]})
Execution failures:0 error[s]
Node failures:1) AuthorizationException on node azure-b4e90bfc-8f15-4c40-b546-a41f61ee7345/azure-b4e90bfc-8f15-4c40-b546-a41f61ee7345-348:
org.jclouds.rest.AuthorizationException: (jclouds:pw[49bc707eedfa33bae83edc98b9a84014]@40.121.182.39:22) (jclouds:pw[49bc707eedfa33bae83edc98b9a84014]@40.121.182.39:22) error acquiring {hostAndPort=40.121.182.39:22, loginUser=jclouds, ssh=null, connectTimeout=60000, sessionTimeout=60000} (not retryable): Exhausted available authentication methods
	at org.jclouds.sshj.SshjSshClient.propagate(SshjSshClient.java:394)
	at org.jclouds.sshj.SshjSshClient.acquire(SshjSshClient.java:215)
	at org.jclouds.sshj.SshjSshClient.connect(SshjSshClient.java:224)
	at org.jclouds.compute.callables.RunScriptOnNodeAsInitScriptUsingSsh.call(RunScriptOnNodeAsInitScriptUsingSsh.java:72)
	at org.jclouds.compute.strategy.CustomizeNodeAndAddToGoodMapOrPutExceptionIntoBadMap.call(CustomizeNodeAndAddToGoodMapOrPutExceptionIntoBadMap.java:123)
	at org.jclouds.compute.strategy.CustomizeNodeAndAddToGoodMapOrPutExceptionIntoBadMap.apply(CustomizeNodeAndAddToGoodMapOrPutExceptionIntoBadMap.java:144)
	at org.jclouds.compute.strategy.CustomizeNodeAndAddToGoodMapOrPutExceptionIntoBadMap.apply(CustomizeNodeAndAddToGoodMapOrPutExceptionIntoBadMap.java:50)
	at com.google.common.util.concurrent.AbstractTransformFuture$TransformFuture.doTransform(AbstractTransformFuture.java:239)
	at com.google.common.util.concurrent.AbstractTransformFuture$TransformFuture.doTransform(AbstractTransformFuture.java:229)
	at com.google.common.util.concurrent.AbstractTransformFuture.run(AbstractTransformFuture.java:130)
	at com.google.common.util.concurrent.MoreExecutors$5$1.run(MoreExecutors.java:952)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: net.schmizz.sshj.userauth.UserAuthException: Exhausted available authentication methods
	at net.schmizz.sshj.SSHClient.auth(SSHClient.java:230)
	at net.schmizz.sshj.SSHClient.auth(SSHClient.java:205)
	at net.schmizz.sshj.SSHClient.authPassword(SSHClient.java:291)
	at net.schmizz.sshj.SSHClient.authPassword(SSHClient.java:261)
	at net.schmizz.sshj.SSHClient.authPassword(SSHClient.java:245)
	at org.jclouds.sshj.SSHClientConnection.create(SSHClientConnection.java:166)
	at org.jclouds.sshj.SSHClientConnection.create(SSHClientConnection.java:50)
	at org.jclouds.sshj.SshjSshClient.acquire(SshjSshClient.java:195)
	... 12 more
1 error[s]
	at org.jclouds.compute.internal.BaseComputeService.createNodesInGroup(BaseComputeService.java:225)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at com.google.inject.internal.DelegatingInvocationHandler.invoke(DelegatingInvocationHandler.java:37)
	at com.sun.proxy.$Proxy74.createNodesInGroup(Unknown Source)
	at org.lamport.tla.toolbox.jcloud.CloudDistributedTLCJob.provisionNodes(CloudDistributedTLCJob.java:543)
	at org.lamport.tla.toolbox.jcloud.CloudDistributedTLCJob.run(CloudDistributedTLCJob.java:210)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)

 

However, when I manually terminate jclouds and wait longer for the VM to provision, I can eventually connect to it with SSH.

 

In another instance, a script failed to execute:

org.jclouds.compute.RunScriptOnNodesException: error runScript on filtered nodes options({wrapInInitScript=false})
Execution failures:0 error[s]
Node failures:1) NullPointerException on node AZURE-F9B72660-D581-4E74-83A2-A9C08475EB15/azure-f9b72660-d581-4e74-83a2-a9c08475eb15-9b9:
java.lang.NullPointerException: no credentials found for node AZURE-F9B72660-D581-4E74-83A2-A9C08475EB15/azure-f9b72660-d581-4e74-83a2-a9c08475eb15-9b9
	at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:811)
	at org.jclouds.compute.functions.CreateSshClientOncePortIsListeningOnNode.apply(CreateSshClientOncePortIsListeningOnNode.java:62)
	at org.jclouds.compute.functions.CreateSshClientOncePortIsListeningOnNode.apply(CreateSshClientOncePortIsListeningOnNode.java:40)
	at org.jclouds.compute.callables.RunScriptOnNodeUsingSsh.init(RunScriptOnNodeUsingSsh.java:99)
	at org.jclouds.compute.strategy.InitializeRunScriptOnNodeOrPlaceInBadMap.call(InitializeRunScriptOnNodeOrPlaceInBadMap.java:61)
	at org.jclouds.compute.strategy.InitializeRunScriptOnNodeOrPlaceInBadMap.call(InitializeRunScriptOnNodeOrPlaceInBadMap.java:34)
	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:111)
	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:58)
	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:75)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)
1 error[s]
	at org.jclouds.compute.internal.BaseComputeService.runScriptOnNodesMatching(BaseComputeService.java:589)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at com.google.inject.internal.DelegatingInvocationHandler.invoke(DelegatingInvocationHandler.java:37)
	at com.sun.proxy.$Proxy74.runScriptOnNodesMatching(Unknown Source)
	at org.lamport.tla.toolbox.jcloud.CloudDistributedTLCJob.provisionNodes(CloudDistributedTLCJob.java:554)
	at org.lamport.tla.toolbox.jcloud.CloudDistributedTLCJob.run(CloudDistributedTLCJob.java:210)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)