jclouds-notifications mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Aled Sage (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (JCLOUDS-1229) Azure ARM - No retry is the rate limit is exceeded
Date Wed, 25 Jan 2017 15:41:27 GMT

    [ https://issues.apache.org/jira/browse/JCLOUDS-1229?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15837926#comment-15837926
] 

Aled Sage commented on JCLOUDS-1229:
------------------------------------

[~nacx] My personal preference would be for the default in jclouds to be "to work, even if
a little slowly". Retrying when rate-limited sounds like a good default.

We saw 17 seconds as the rate-limit time, which is surprisingly high!

There's config for {{jclouds.max-ratelimit-wait}} (defaulting to 2 minutes) to try to avoid
things taking crazy-long. But then if you're rate-limited for 17 seconds every few requests,
and jclouds executes approx 390 requests, then I do agree that can add up to considerable
delays.

It would be nice to reduce the number of API calls if at all possible (e.g. can we get details
of multiple images in a single api call?).

> Azure ARM - No retry is the rate limit is exceeded
> --------------------------------------------------
>
>                 Key: JCLOUDS-1229
>                 URL: https://issues.apache.org/jira/browse/JCLOUDS-1229
>             Project: jclouds
>          Issue Type: Bug
>          Components: jclouds-compute, jclouds-labs
>    Affects Versions: 2.0.0
>            Reporter: Thomas Bouron
>              Labels: azurecompute-arm
>
> Trying to provision a VM in Azure ARM. My deployment failed because of the rate limit
exceeded with the stacktrace below.
> I was expecting jclouds to perform a back-off retry as it does for other clouds but does
not seem to be the case (See {{AzureRateLimitRetryHandler}} - is that wired in correctly,
and does it correctly handle 429 response code)?
> There were 390 API calls made in 2mins 22 secs before getting this exception.
> {noformat}
> 2017-01-25 11:57:04,702 DEBUG 106 o.j.r.i.InvokeHttpMethod [nager-XBhutgvo-4] >>
invoking resourcegroup:list
> 2017-01-25 11:57:04,702 DEBUG 106 o.j.h.o.OkHttpCommandExecutorService [nager-XBhutgvo-4]
Sending request 300674855: GET https://management.azure.com/subscriptions/341751b0-xxxx-45ce-9498-xxxxxxxxxxxx/resourcegroups?api-version=2015-01-01
HTTP/1.1
> 2017-01-25 11:57:04,729 DEBUG 106 o.j.i.ContentMetadataCodec$DefaultContentMetadataCodec
[nager-XBhutgvo-4] Invalid Expires header (-1); should be in RFC-1123 format; treating as
already expired: Error parsing data at 0
> 2017-01-25 11:57:04,729 DEBUG 106 o.j.h.o.OkHttpCommandExecutorService [nager-XBhutgvo-4]
Receiving response 300674855: HTTP/1.1 200 OK
> 2017-01-25 11:57:04,732 DEBUG 106 o.j.r.i.InvokeHttpMethod [nager-XBhutgvo-4] >>
invoking storageaccount:list
> 2017-01-25 11:57:04,733 DEBUG 106 o.j.h.o.OkHttpCommandExecutorService [nager-XBhutgvo-4]
Sending request -641560959: GET https://management.azure.com/subscriptions/341751b0-xxxx-45ce-9498-xxxxxxxxxxxx/resourcegroups/aleks-test-res/providers/Microsoft.Storage/storageAccou
> 2017-01-25 11:57:04,763 DEBUG 143 o.a.b.u.r.Repeater [nager-XBhutgvo-6] Repeater (repeated
failure; excluding stacktrace): java.lang.AssertionError: service.isUp expected equals true
but found false
> 2017-01-25 11:57:05,264 DEBUG 143 o.a.b.u.r.Repeater [nager-XBhutgvo-6] Repeater (repeated
failure; excluding stacktrace): java.lang.AssertionError: service.isUp expected equals true
but found false
> 2017-01-25 11:57:05,764 DEBUG 143 o.a.b.u.r.Repeater [nager-XBhutgvo-6] Repeater (repeated
failure; excluding stacktrace): java.lang.AssertionError: service.isUp expected equals true
but found false
> 2017-01-25 11:57:05,938 DEBUG 106 o.j.i.ContentMetadataCodec$DefaultContentMetadataCodec
[nager-XBhutgvo-4] Invalid Expires header (-1); should be in RFC-1123 format; treating as
already expired: Error parsing data at 0
> 2017-01-25 11:57:05,938 DEBUG 106 o.j.h.o.OkHttpCommandExecutorService [nager-XBhutgvo-4]
Receiving response -641560959: HTTP/1.1 429
> 2017-01-25 11:57:05,940 WARN  126 o.a.b.l.j.JcloudsLocation [nager-XBhutgvo-4] Error
loading available images to report (following original error matching template which will
be rethrown): org.jclouds.azurecompute.arm.exceptions.AzureComputeRateLimitExceededException:
HTT
> {x-ms-ratelimit-remaining-subscription-reads=[14947]}
> org.jclouds.azurecompute.arm.exceptions.AzureComputeRateLimitExceededException: HTTP/1.1
429
> {x-ms-ratelimit-remaining-subscription-reads=[14947]}
>         at org.jclouds.azurecompute.arm.handlers.AzureComputeErrorHandler.handleError(AzureComputeErrorHandler.java:73)
>         at org.jclouds.http.handlers.DelegatingErrorHandler.handleError(DelegatingErrorHandler.java:65)
>         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.$Proxy174.list(Unknown Source)
>         at org.jclouds.azurecompute.arm.compute.AzureComputeServiceAdapter.listImages(AzureComputeServiceAdapter.java:231)
>         at org.jclouds.compute.config.ComputeServiceAdapterContextModule$2.get(ComputeServiceAdapterContextModule.java:121)
>         at org.jclouds.compute.config.ComputeServiceAdapterContextModule$2.get(ComputeServiceAdapterContextModule.java:118)
>         at org.jclouds.rest.suppliers.MemoizedRetryOnTimeOutButNotOnAuthorizationExceptionSupplier$SetAndThrowAuthorizationExceptionSupplierBackedLoader.load(MemoizedRetryOnTimeOutButNotOnAuthorizationExceptionSupplier.java:75)
>         at org.jclouds.rest.suppliers.MemoizedRetryOnTimeOutButNotOnAuthorizationExceptionSupplier$SetAndThrowAuthorizationExceptionSupplierBackedLoader.load(MemoizedRetryOnTimeOutButNotOnAuthorizationExceptionSupplier.java:57)
>         at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3527)
>         at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2319)
>         at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2282)
>         at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2197)
>         at com.google.common.cache.LocalCache.get(LocalCache.java:3937)
>         at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3941)
>         at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4824)
>         at org.jclouds.rest.suppliers.MemoizedRetryOnTimeOutButNotOnAuthorizationExceptionSupplier.get(MemoizedRetryOnTimeOutButNotOnAuthorizationExceptionSupplier.java:150)
>         at org.jclouds.compute.suppliers.ImageCacheSupplier.get(ImageCacheSupplier.java:106)
>         at org.jclouds.compute.suppliers.ImageCacheSupplier.get(ImageCacheSupplier.java:58)
>         at org.jclouds.compute.internal.BaseComputeService.listImages(BaseComputeService.java:384)
>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_111-internal]
>         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_111-internal]
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_111-internal]
>         at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_111-internal]
>         at com.google.inject.internal.DelegatingInvocationHandler.invoke(DelegatingInvocationHandler.java:37)[69:com.google.inject:3.0.0]
>         at com.sun.proxy.$Proxy155.listImages(Unknown Source)[:]
>         at org.apache.brooklyn.location.jclouds.JcloudsLocation.logAvailableTemplates(JcloudsLocation.java:1581)[126:org.apache.brooklyn.locations-jclouds:0.11.0.20170123_2005]
>         at org.apache.brooklyn.location.jclouds.JcloudsLocation.buildTemplate(JcloudsLocation.java:1432)[126:org.apache.brooklyn.locations-jclouds:0.11.0.20170123_2005]
>         at org.apache.brooklyn.location.jclouds.JcloudsLocation.obtainOnce(JcloudsLocation.java:676)[126:org.apache.brooklyn.locations-jclouds:0.11.0.20170123_2005]
>         at org.apache.brooklyn.location.jclouds.JcloudsLocation.obtain(JcloudsLocation.java:606)[126:org.apache.brooklyn.locations-jclouds:0.11.0.20170123_2005]
>         at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$ObtainLocationTask.call(MachineLifecycleEffectorTasks.java:443)[131:org.apache.brooklyn.software-base:0.11.0.20170123_2005]
>         at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$ObtainLocationTask.call(MachineLifecycleEffectorTasks.java:433)[131:org.apache.brooklyn.software-base:0.11.0.20170123_2005]
>         at org.apache.brooklyn.util.core.task.Tasks.withBlockingDetails(Tasks.java:106)[120:org.apache.brooklyn.core:0.11.0.20170123_2005]
>         at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$ProvisionMachineTask.call(MachineLifecycleEffectorTasks.java:414)[131:org.apache.brooklyn.software-base:0.11.0.20170123_2005]
>         at org.apache.brooklyn.entity.software.base.lifecycle.MachineLifecycleEffectorTasks$ProvisionMachineTask.call(MachineLifecycleEffectorTasks.java:390)[131:org.apache.brooklyn.software-base:0.11.0.20170123_2005]
>         at org.apache.brooklyn.util.core.task.DynamicSequentialTask$DstJob.call(DynamicSequentialTask.java:359)[120:org.apache.brooklyn.core:0.11.0.20170123_2005]
>         at org.apache.brooklyn.util.core.task.BasicExecutionManager$SubmissionCallable.call(BasicExecutionManager.java:522)[120:org.apache.brooklyn.core:0.11.0.20170123_2005]
>         at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_111-internal]
>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_111-internal]
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_111-internal]
>         at java.lang.Thread.run(Thread.java:745)[:1.8.0_111-internal]
> Caused by: org.jclouds.http.HttpResponseException: command: GET https://management.azure.com/subscriptions/341751b0-xxxx-45ce-9498-xxxxxxxxxxxx/resourcegroups/aleks-test-res/providers/Microsoft.Storage/storageAccounts
HTTP/1.1 failed with response: HTTP/1.1 429 ; content:
>         at org.jclouds.azurecompute.arm.handlers.AzureComputeErrorHandler.handleError(AzureComputeErrorHandler.java:45)
>         ... 46 more
> 2017-01-25 11:57:05,949 ERROR 126 o.a.b.l.j.JcloudsLocation [nager-XBhutgvo-4] Failed
to start VM for azurecompute-arm:southeastasia:https://management.azure.com/subscriptions/341751b0-xxxx-45ce-9498-xxxxxxxxxxxx@MongoDBServerImpl{id=k9ah7ty4jo,
hostname=null, port=null}
> {x-ms-ratelimit-remaining-subscription-reads=[14756]}
> {noformat}



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

Mime
View raw message