Skip to content

Instantly share code, notes, and snippets.

@aledsage
Created December 13, 2016 14:19
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save aledsage/816460d719bf463f03672b72dc370d4a to your computer and use it in GitHub Desktop.
Save aledsage/816460d719bf463f03672b72dc370d4a to your computer and use it in GitHub Desktop.
When deploying to Softlayer (in a brooklyn live test), it failed to provision. There were two separate problems (shown in the log snippets below):
1. failed to login to the VM: `doesn't have login details within 3600000ms`
2. failed to delete the VM, when discarding it: softlayer sent back a 500 Internal Server Error `This cancellation could not be processed please contact support.This cancellation could not be processed. Please contact support. There is currently an active transaction.`
```
2016-12-13 12:45:23,293 INFO Creating VM null in JcloudsLocation[softlayer:software-development@pl9nu7srsh]
2016-12-13 12:45:32,963 INFO ignoring auto-generate-keypairs(false) in VM creation because not supported for cloud/type ({})
...
2016-12-13 13:45:42,538 WARN VirtualGuest(VirtualGuest{accountId=278918, createDate=Tue Dec 13 12:45:38 GMT 2016, domain=local.brooklyncentral.org, fullyQualifiedDomainName=brooklyn-oi4jfn-aled-366.local.brooklyncentral.org, hostname=brooklyn-oi4jfn-aled-366, id=26769559, lastVerifiedDate=null, maxCpu=1, maxCpuUnits=CORE, maxMemory=1024, metricPollDate=null, modifyDate=null, notes=null, startCpus=1, statusId=1001, uuid=4581fc07-2752-4ae5-9cde-22e6177b62bf, primaryBackendIpAddress=null, primaryIpAddress=null, billingItemId=0, operatingSystem=null, operatingSystemReferenceCode=null, datacenter=null, powerState=null, softwareLicense=null, activeTransactionCount=0, blockDevices=null, hourlyBillingFlag=false, localDiskFlag=false, dedicatedAccountHostOnlyFlag=false, privateNetworkOnlyFlag=false, blockDeviceTemplateGroup=null, networkComponents=null, tagReferences=null, primaryNetworkComponent=null, primaryBackendNetworkComponent=null, postInstallScriptUri=null, virtualGuestAttribute=null, sshKeys=null}) doesn't have login details within 3600000ms so it will be destroyed.
2016-12-13 13:46:17,673 ERROR Cannot retry after server error, command has exceeded retry limit 6: [method=org.jclouds.softlayer.features.VirtualGuestApi.public abstract boolean org.jclouds.softlayer.features.VirtualGuestApi.deleteVirtualGuest(long)[26769559], request=GET https://api.softlayer.com/rest/v3/SoftLayer_Virtual_Guest/26769559/deleteObject HTTP/1.1]
2016-12-13 13:46:17,678 ERROR createNodesInGroup(brooklyn-oi4jfn-aled), completed: 0/1, errors: 1, rate: 3642580ms/op
java.util.concurrent.ExecutionException: java.lang.IllegalStateException: {"error":"This cancellation could not be processed please contact support.This cancellation could not be processed. Please contact support. There is currently an active transaction.","code":"SoftLayer_Exception_Public"}
at com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:299) ~[guava-18.0.jar:na]
java.lang.IllegalStateException: {"error":"This cancellation could not be processed please contact support.This cancellation could not be processed. Please contact support. There is currently an active transaction.","code":"SoftLayer_Exception_Public"}
at org.jclouds.softlayer.handlers.SoftLayerErrorHandler.handleError(SoftLayerErrorHandler.java:63) ~[softlayer-2.0.0.jar:2.0.0]
org.jclouds.http.HttpResponseException: command: GET https://api.softlayer.com/rest/v3/SoftLayer_Virtual_Guest/26769559/deleteObject HTTP/1.1 failed with response: HTTP/1.1 500 Internal Server Error; content: [{"error":"This cancellation could not be processed please contact support.This cancellation could not be processed. Please contact support. There is currently an active transaction.","code":"SoftLayer_Exception_Public"}]
at org.jclouds.softlayer.handlers.SoftLayerErrorHandler.handleError(SoftLayerErrorHandler.java:43) ~[softlayer-2.0.0.jar:2.0.0]
2016-12-13 13:46:17,679 ERROR createNodesInGroup(brooklyn-oi4jfn-aled), completed: 0/1, errors: 1, rate: 3642582ms/op
java.lang.RuntimeException: createNodesInGroup(brooklyn-oi4jfn-aled), completed: 0/1, errors: 1, rate: 3642582ms/op
at org.jclouds.concurrent.FutureIterables.awaitCompletion(FutureIterables.java:153) ~[jclouds-core-2.0.0.jar:2.0.0]
2016-12-13 13:46:17,681 ERROR Failed to start VM for null after 1h 54s (semaphore obtained in 0ms; template built in 9.68s;): error running 1 node group(brooklyn-oi4jfn-aled) location(dal09) image(CENTOS_6_64) size(cpu=1,memory=1024,disk=25,type=LOCAL) options({scriptPresent=true, tags=[Name:brooklyn-oi4jfn-aled-yoqq, brooklyn-user:aled], userMetadata={Name=brooklyn-oi4jfn-aled-yoqq, brooklyn-user=aled, notes=User Metadata
=============
* Name: brooklyn-oi4jfn-aled-yoqq
* brooklyn-user: aled}})
Execution failures:
1) ExecutionException on brooklyn-oi4jfn-aled-366:
java.util.concurrent.ExecutionException: java.lang.IllegalStateException: {"error":"This cancellation could not be processed please contact support.This cancellation could not be processed. Please contact support. There is currently an active transaction.","code":"SoftLayer_Exception_Public"}
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.IllegalStateException: {"error":"This cancellation could not be processed please contact support.This cancellation could not be processed. Please contact support. There is currently an active transaction.","code":"SoftLayer_Exception_Public"}
at org.jclouds.softlayer.handlers.SoftLayerErrorHandler.handleError(SoftLayerErrorHandler.java:63)
at org.jclouds.http.handlers.DelegatingErrorHandler.handleError(DelegatingErrorHandler.java:67)
at org.jclouds.http.internal.BaseHttpCommandExecutorService.shouldContinue(BaseHttpCommandExecutorService.java:140)
at org.jclouds.http.internal.BaseHttpCommandExecutorService.invoke(BaseHttpCommandExecutorService.java:109)
at org.jclouds.rest.internal.InvokeHttpMethod.invoke(InvokeHttpMethod.java:90)
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.$Proxy68.deleteVirtualGuest(Unknown Source)
at org.jclouds.softlayer.compute.strategy.SoftLayerComputeServiceAdapter.createNodeWithGroupEncodedIntoName(SoftLayerComputeServiceAdapter.java:238)
at org.jclouds.compute.strategy.impl.AdaptingComputeServiceStrategies.createNodeWithGroupEncodedIntoName(AdaptingComputeServiceStrategies.java:196)
at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet$AddNode.call(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:81)
at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet$AddNode.call(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:64)
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:169)
at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet.execute(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:124)
at org.jclouds.compute.internal.BaseComputeService.createNodesInGroup(BaseComputeService.java:217)
at org.apache.brooklyn.location.jclouds.JcloudsLocation.obtainOnce(JcloudsLocation.java:740)
at org.apache.brooklyn.location.jclouds.JcloudsLocation.obtain(JcloudsLocation.java:628)
at org.apache.brooklyn.location.jclouds.provider.AbstractJcloudsLocationTest.obtainMachine(AbstractJcloudsLocationTest.java:188)
at org.apache.brooklyn.location.jclouds.provider.AbstractJcloudsLocationTest.testProvisionVmUsingImageId(AbstractJcloudsLocationTest.java:161)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:86)
at org.testng.internal.Invoker.invokeMethod(Invoker.java:643)
at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:820)
at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1128)
at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:112)
at org.testng.TestRunner.privateRun(TestRunner.java:782)
at org.testng.TestRunner.run(TestRunner.java:632)
at org.testng.SuiteRunner.runTest(SuiteRunner.java:366)
at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:361)
at org.testng.SuiteRunner.privateRun(SuiteRunner.java:319)
at org.testng.SuiteRunner.run(SuiteRunner.java:268)
at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
at org.testng.TestNG.runSuitesSequentially(TestNG.java:1244)
at org.testng.TestNG.runSuitesLocally(TestNG.java:1169)
at org.testng.TestNG.run(TestNG.java:1064)
at org.testng.remote.AbstractRemoteTestNG.run(AbstractRemoteTestNG.java:132)
at org.testng.remote.RemoteTestNG.initAndRun(RemoteTestNG.java:236)
at org.testng.remote.RemoteTestNG.main(RemoteTestNG.java:81)
Caused by: org.jclouds.http.HttpResponseException: command: GET https://api.softlayer.com/rest/v3/SoftLayer_Virtual_Guest/26769559/deleteObject HTTP/1.1 failed with response: HTTP/1.1 500 Internal Server Error; content: [{"error":"This cancellation could not be processed please contact support.This cancellation could not be processed. Please contact support. There is currently an active transaction.","code":"SoftLayer_Exception_Public"}]
at org.jclouds.softlayer.handlers.SoftLayerErrorHandler.handleError(SoftLayerErrorHandler.java:43)
at org.jclouds.http.handlers.DelegatingErrorHandler.handleError(DelegatingErrorHandler.java:67)
at org.jclouds.http.internal.BaseHttpCommandExecutorService.shouldContinue(BaseHttpCommandExecutorService.java:140)
at org.jclouds.http.internal.BaseHttpCommandExecutorService.invoke(BaseHttpCommandExecutorService.java:109)
at org.jclouds.rest.internal.InvokeHttpMethod.invoke(InvokeHttpMethod.java:90)
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.$Proxy68.deleteVirtualGuest(Unknown Source)
at org.jclouds.softlayer.compute.strategy.SoftLayerComputeServiceAdapter.createNodeWithGroupEncodedIntoName(SoftLayerComputeServiceAdapter.java:238)
at org.jclouds.compute.strategy.impl.AdaptingComputeServiceStrategies.createNodeWithGroupEncodedIntoName(AdaptingComputeServiceStrategies.java:196)
at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet$AddNode.call(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:81)
at org.jclouds.compute.strategy.impl.CreateNodesWithGroupEncodedIntoNameThenAddToSet$AddNode.call(CreateNodesWithGroupEncodedIntoNameThenAddToSet.java:64)
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)
1 error[s]
Node failures:
0 error[s]
2016-12-13 13:46:17,684 WARN Attempt #1/2 to obtain machine threw error: org.apache.brooklyn.util.exceptions.PropagatedRuntimeException: RunNodesException: error running 1 node group(brooklyn-oi4jfn-aled) location(dal09) image(CENTOS_6_64) size(cpu=1,memory=1024,disk=25,type=LOCAL) options({scriptPresent=true, tags=[Name:brooklyn-oi4jfn-aled-yoqq, brooklyn-user:aled], userMetadata={Name=brooklyn-oi4jfn-aled-yoqq, brooklyn-user=aled, notes=User Metadata
```
Looking in the debug log, below is the response details. This was retried 6 times:
```
2016-12-13 13:45:42,539 DEBUG o.j.r.i.InvokeHttpMethod [user thread 1]: >> invoking VirtualGuests:delete
2016-12-13 13:45:42,539 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user thread 1]: Sending request -1185878952: GET https://api.softlayer.com/rest/v3/SoftLayer_Virtual_Guest/26769559/deleteObject HTTP/1.1
2016-12-13 13:45:42,539 DEBUG jclouds.headers [user thread 1]: >> GET https://api.softlayer.com/rest/v3/SoftLayer_Virtual_Guest/26769559/deleteObject HTTP/1.1
2016-12-13 13:45:42,539 DEBUG jclouds.headers [user thread 1]: >> Accept: application/json
2016-12-13 13:45:42,540 DEBUG jclouds.headers [user thread 1]: >> Authorization: Basic xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
2016-12-13 13:45:44,362 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user thread 1]: Receiving response -1185878952: HTTP/1.1 500 Internal Server Error
2016-12-13 13:45:44,363 DEBUG jclouds.headers [user thread 1]: << HTTP/1.1 500 Internal Server Error
2016-12-13 13:45:44,363 DEBUG jclouds.headers [user thread 1]: << X-Frame-Options: SAMEORIGIN
2016-12-13 13:45:44,363 DEBUG jclouds.headers [user thread 1]: << Vary: Accept-Encoding
2016-12-13 13:45:44,363 DEBUG jclouds.headers [user thread 1]: << Date: Tue, 13 Dec 2016 13:45:43 GMT
2016-12-13 13:45:44,363 DEBUG jclouds.headers [user thread 1]: << Connection: close
2016-12-13 13:45:44,363 DEBUG jclouds.headers [user thread 1]: << Server: Apache
2016-12-13 13:45:44,363 DEBUG jclouds.headers [user thread 1]: << Content-Type: application/json
2016-12-13 13:45:44,363 DEBUG jclouds.headers [user thread 1]: << Content-Length: 219
...
2016-12-13 13:46:17,673 ERROR o.j.h.h.BackoffLimitedRetryHandler [user thread 1]: Cannot retry after server error, command has exceeded retry limit 6: [method=org.jclouds.softlayer.features.VirtualGuestApi.public abstract boolean org.jclouds.softlayer.features.VirtualGuestApi.deleteVirtualGuest(long)[26769559], request=GET https://api.softlayer.com/rest/v3/SoftLayer_Virtual_Guest/26769559/deleteObject HTTP/1.1]
```
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment