brooklyn-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Aled Sage (JIRA)" <j...@apache.org>
Subject [jira] [Created] (BROOKLYN-411) Softlayer VM deletion failed: 500 Internal Server Error from Softlayer API
Date Thu, 15 Dec 2016 16:05:58 GMT
Aled Sage created BROOKLYN-411:
----------------------------------

             Summary: Softlayer VM deletion failed: 500 Internal Server Error from Softlayer
API
                 Key: BROOKLYN-411
                 URL: https://issues.apache.org/jira/browse/BROOKLYN-411
             Project: Brooklyn
          Issue Type: Bug
            Reporter: Aled Sage


Using Brooklyn 0.11.0-SNAPSHOT with jclouds 2.0.0, when deploying to Softlayer (in a brooklyn
live test), it failed to provision (non-deterministic: the other tests worked). 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.}}

{noformat}
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
{noformat}

Looking in the debug log, below is the response details. This was retried 6 times:
{noformat}
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]
{noformat}




--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message