You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@jclouds.apache.org by "Ignasi Barrera (JIRA)" <ji...@apache.org> on 2017/01/25 13:55:26 UTC
[jira] [Commented] (JCLOUDS-1229) Azure ARM - No retry is the rate
limit is exceeded
[ 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)