Uploaded image for project: 'jclouds'
  1. jclouds
  2. JCLOUDS-1229

Azure ARM - No retry is the rate limit is exceeded

    XMLWordPrintableJSON

Details

    Description

      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.

      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]}

      Attachments

        Activity

          People

            Unassigned Unassigned
            tbouron Thomas Bouron
            Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: