jclouds-notifications mailing list archives

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

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

Ignasi Barrera commented on JCLOUDS-1229:
-----------------------------------------

Rate limited requests work a bit different. It makes no sense to apply an exponential backoff
(as opposed to server errors such as service unavailable, etc). In rate limtied scenarios
what the client should do is inspect the response, and determine when a new request can be
issued based on the rate limit information.

The Azure ARM provider does it by reading the "Retry-After" header, according to the [Azure
documentation|https://docs.microsoft.com/en-us/azure/azure-resource-manager/resource-manager-request-limits]
and waiting the amount of time indicated int he response. You can see the relevant code [here|https://github.com/jclouds/jclouds-labs/blob/master/azurecompute-arm/src/main/java/org/jclouds/azurecompute/arm/handlers/AzureRateLimitRetryHandler.java]
and [here|https://github.com/jclouds/jclouds/blob/master/core/src/main/java/org/jclouds/http/handlers/RateLimitRetryHandler.java#L90-L120].

If you enable the {{org.jclouds}} logger you should see the relevant logs. In your case I'd
say that the response does not containt the Retry-After header, or the wait period is too
much and jclouds aborts the rate limit wait. The latter can be configured by setting the [PROPERTY_MAX_RATE_LIMIT_WAIT|https://github.com/jclouds/jclouds/blob/master/core/src/main/java/org/jclouds/Constants.java#L363-L369]
property when creating the context.

Another common cause of the rate limit issues is the amount of images being considered by
default. In order to get the details of an image there are many calls that need to be done
to Azure (due to the structure of the ARM API), so a good way of limiting that is by setting
the [IMAGE_PUBLISHERS|https://github.com/jclouds/jclouds-labs/blob/master/azurecompute-arm/src/main/java/org/jclouds/azurecompute/arm/config/AzureComputeProperties.java#L37]
property to a limited set of publishers (it defaults to "Canonical,RedHat").

> 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