Created
December 13, 2016 14:19
-
-
Save aledsage/816460d719bf463f03672b72dc370d4a to your computer and use it in GitHub Desktop.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
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