{"action":"created","issue":{"url":"https://api.github.com/repos/cloudfoundry-incubator/bosh-aws-cpi-release/issues/19","repository_url":"https://api.github.com/repos/cloudfoundry-incubator/bosh-aws-cpi-release","labels_url":"https://api.github.com/repos/cloudfoundry-incubator/bosh-aws-cpi-release/issues/19/labels{/name}","comments_url":"https://api.github.com/repos/cloudfoundry-incubator/bosh-aws-cpi-release/issues/19/comments","events_url":"https://api.github.com/repos/cloudfoundry-incubator/bosh-aws-cpi-release/issues/19/events","html_url":"https://github.com/cloudfoundry-incubator/bosh-aws-cpi-release/issues/19","id":126166145,"number":19,"title":"Often getting the error \"Request limit exceeded.\" using AWS API. Is aws.max_retries the solution?","user":{"login":"keymon","id":280032,"avatar_url":"https://avatars.githubusercontent.com/u/280032?v=3","gravatar_id":"","url":"https://api.github.com/users/keymon","html_url":"https://github.com/keymon","followers_url":"https://api.github.com/users/keymon/followers","following_url":"https://api.github.com/users/keymon/following{/other_user}","gists_url":"https://api.github.com/users/keymon/gists{/gist_id}","starred_url":"https://api.github.com/users/keymon/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/keymon/subscriptions","organizations_url":"https://api.github.com/users/keymon/orgs","repos_url":"https://api.github.com/users/keymon/repos","events_url":"https://api.github.com/users/keymon/events{/privacy}","received_events_url":"https://api.github.com/users/keymon/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":4,"created_at":"2016-01-12T12:10:55Z","updated_at":"2016-02-03T01:29:07Z","closed_at":null,"body":"When deploying a CF installation on AWS, sometimes I hit the error `AWS::EC2::Errors::RequestLimitExceeded Request limit exceeded.`. \r\n\r\nIn some portions of the code of this CPI, [some calls are wrapped around a decorator which retries the requests](https://github.com/cloudfoundry-incubator/bosh-aws-cpi-release/blob/eb9f26d419a5c94f5996fb82285fb29fc5515b89/src/bosh_aws_cpi/lib/cloud/aws/instance_manager.rb#L166), but there are several calls to the API that are not wrapped but that call the AWS api via the AWS sdk library used, specially when querying the existing state (e.g. listing AMI images).\r\n\r\nIn [this PR the solution is wrap](https://github.com/cloudfoundry-incubator/bosh-aws-cpi-release/pull/17#issuecomment-158827233) all the AWS client with some retry logic in the CPI code, but as said, there are several inexplicit calls to the API  that are not wrapped.\r\n\r\nBut I do think that [the configuration `max_entries`](https://github.com/cloudfoundry-incubator/bosh-aws-cpi-release/blob/118ea6df1fd6c9f9c2116a5e47a27cfb33e834c9/src/bosh_aws_cpi/lib/cloud/aws/cloud.rb#L37) can solve that. bosh-aws-cpi uses the AWS sdk v1 (latest version is v2), and [reviewing the SDK code](https://github.com/aws/aws-sdk-ruby/blob/aws-sdk-v1/lib/aws/core/client.rb) it seems the requests are retried by the library. \r\n\r\nSo, if using a higher value of `aws.max_entries` this issue can be solved, I suggest either increase the default value and/or document the issue and the setting, as the issue is really common. I also wonder if we need to wrap the code with `Bosh::Common.retryable` at all.\r\n\r\nError example:\r\n\r\n``` \r\nD, [2016-01-12 09:53:13 #18310] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:matt\r\nD, [2016-01-12 09:53:13 #18310] [create_missing_vm(runner_z1, 0/1)] DEBUG -- DirectorJobRunner: External CPI got response: {\"result\":null,\"error\":{\"type\":\"Unknown\",\"message\":\"Request limit exceeded.\",\"ok_to_retry\":false},\"log\":\"Rescued Unknown: Request limit exceeded.. backtrace: /var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/client.rb:375:in `return_or_raise'\\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/client.rb:476:in `client_request'\\n(eval):3:in `describe_images'\\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/ec2/resource.rb:72:in `describe_call'\\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/ec2/resource.rb:56:in `get_resource'\\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/resource.rb:235:in `block (2 levels) in define_attribute_getter'\\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/cacheable.rb:63:in `retrieve_attribute'\\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/ec2/resource.rb:66:in `retrieve_attribute'\\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/resource.rb:235:in `block in define_attribute_getter'\\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/instance_manager.rb:120:in `build_instance_params'\\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/instance_manager.rb:81:in `create'\\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/cloud.rb:127:in `block in create_vm'\\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_common-1.3071.0/lib/common/thread_formatter.rb:49:in `with_thread_name'\\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/cloud.rb:122:in `create_vm'\\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_cpi-1.3071.0/lib/bosh/cpi/cli.rb:71:in `public_send'\\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_cpi-1.3071.0/lib/bosh/cpi/cli.rb:71:in `run'\\n/var/vcap/packages/bosh_aws_cpi/bin/aws_cpi:28:in `<main>'\"}, err: I, [2016-01-12T09:53:10.833273 #18490]  INFO -- : [AWS EC2 200 0.134925 0 retries] describe_regions()  \r\n\r\nI, [2016-01-12T09:53:11.073708 #18490]  INFO -- : [AWS EC2 200 0.229609 0 retries] describe_images(:filters=>[{:name=>\"image-id\",:values=>[\"ami-8bf7c4fc\"]}])  \r\n\r\nI, [2016-01-12T09:53:13.168565 #18490]  INFO -- : [AWS EC2 503 2.078879 2 retries] describe_images(:image_ids=>[\"ami-8bf7c4fc\"]) AWS::EC2::Errors::RequestLimitExceeded Request limit exceeded.\r\n\r\nE, [2016-01-12T09:53:13.169478 #18490] ERROR -- : Failed to create instance: Request limit exceeded.\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/client.rb:375:in `return_or_raise'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/client.rb:476:in `client_request'\r\n(eval):3:in `describe_images'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/ec2/resource.rb:72:in `describe_call'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/ec2/resource.rb:56:in `get_resource'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/resource.rb:235:in `block (2 levels) in define_attribute_getter'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/cacheable.rb:63:in `retrieve_attribute'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/ec2/resource.rb:66:in `retrieve_attribute'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/resource.rb:235:in `block in define_attribute_getter'\r\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/instance_manager.rb:120:in `build_instance_params'\r\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/instance_manager.rb:81:in `create'\r\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/cloud.rb:127:in `block in create_vm'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_common-1.3071.0/lib/common/thread_formatter.rb:49:in `with_thread_name'\r\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/cloud.rb:122:in `create_vm'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_cpi-1.3071.0/lib/bosh/cpi/cli.rb:71:in `public_send'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_cpi-1.3071.0/lib/bosh/cpi/cli.rb:71:in `run'\r\n/var/vcap/packages/bosh_aws_cpi/bin/aws_cpi:28:in `<main>'\r\n, exit_status: pid 18483 exit 0\r\nE, [2016-01-12 09:53:13 #18310] [create_missing_vm(runner_z1, 0/1)] ERROR -- DirectorJobRunner: error creating vm: Unknown CPI error 'Unknown' with message 'Request limit exceeded.'\r\n\r\nI, [2016-01-12T09:53:13.333183 #18476]  INFO -- : [AWS EC2 503 2.252245 2 retries] describe_images(:filters=>[{:name=>\"image-id\",:values=>[\"ami-8bf7c4fc\"]}]) AWS::EC2::Errors::RequestLimitExceeded Request limit exceeded.\r\n\r\n, exit_status: pid 18463 exit 0\r\nI, [2016-01-12 09:53:13 #18310] [create_missing_vm(runner_z1, 0/1)]  INFO -- DirectorJobRunner: Cleaning up the created VM due to an error: Unknown CPI error 'Unknown' with message 'Request limit exceeded.'\r\nD, [2016-01-12 09:53:13 #18310] [] DEBUG -- DirectorJobRunner: Worker thread raised exception: Unknown CPI error 'Unknown' with message 'Request limit exceeded.' - /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_cpi-1.3153.0/lib/cloud/external_cpi.rb:108:in `handle_error'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_cpi-1.3153.0/lib/cloud/external_cpi.rb:89:in `invoke_cpi_method'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_cpi-1.3153.0/lib/cloud/external_cpi.rb:51:in `create_vm'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3153.0/lib/bosh/director/vm_creator.rb:41:in `create'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3153.0/lib/bosh/director/resource_pool_updater.rb:51:in `create_missing_vm'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3153.0/lib/bosh/director/resource_pool_updater.rb:34:in `block (4 levels) in create_missing_vms'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3153.0/lib/common/thread_formatter.rb:49:in `with_thread_name'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3153.0/lib/bosh/director/resource_pool_updater.rb:32:in `block (3 levels) in create_missing_vms'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3153.0/lib/bosh/director/event_log.rb:97:in `call'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3153.0/lib/bosh/director/event_log.rb:97:in `advance_and_track'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3153.0/lib/bosh/director/event_log.rb:50:in `track'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3153.0/lib/bosh/director/resource_pool_updater.rb:31:in `block (2 levels) in create_missing_vms'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3153.0/lib/common/thread_pool.rb:77:in `call'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3153.0/lib/common/thread_pool.rb:77:in `block (2 levels) in create_thread'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3153.0/lib/common/thread_pool.rb:63:in `loop'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3153.0/lib/common/thread_pool.rb:63:in `block in create_thread'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'\r\n``` \r\n\r\nFollowing some stacktraces, I identified these points where this error can raise:\r\n\r\nhttps://github.com/cloudfoundry-incubator/bosh-aws-cpi-release/blob/master/src/bosh_aws_cpi/lib/cloud/aws/instance_manager.rb#L121\r\n``` \r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/client.rb:375:in `return_or_raise'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/client.rb:476:in `client_request'\r\n(eval):3:in `describe_images'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/ec2/resource.rb:72:in `describe_call'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/ec2/resource.rb:56:in `get_resource'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/resource.rb:235:in `block (2 levels) in define_attribute_getter'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/cacheable.rb:63:in `retrieve_attribute'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/ec2/resource.rb:66:in `retrieve_attribute'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/resource.rb:235:in `block in define_attribute_getter'\r\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/instance_manager.rb:120:in `build_instance_params'\r\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/instance_manager.rb:81:in `create'\r\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/cloud.rb:127:in `block in create_vm'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_common-1.3071.0/lib/common/thread_formatter.rb:49:in `with_thread_name'\r\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/cloud.rb:122:in `create_vm'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_cpi-1.3071.0/lib/bosh/cpi/cli.rb:71:in `public_send'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_cpi-1.3071.0/lib/bosh/cpi/cli.rb:71:in `run'\r\n/var/vcap/packages/bosh_aws_cpi/bin/aws_cpi:28:in `<main>'\r\n``` \r\n\r\nhttps://github.com/cloudfoundry-incubator/bosh-aws-cpi-release/blob/master/src/bosh_aws_cpi/lib/cloud/aws/stemcell.rb#L9\r\n``` \r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/client.rb:375:in `return_or_raise'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/core/client.rb:476:in `client_request'\r\n(eval):3:in `describe_images'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/aws-sdk-v1-1.60.2/lib/aws/ec2/image.rb:220:in `exists?'\r\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/stemcell.rb:9:in `find'\r\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/stemcell_finder.rb:8:in `find_by_region_and_id'\r\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/cloud.rb:124:in `block in create_vm'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_common-1.3071.0/lib/common/thread_formatter.rb:49:in `with_thread_name'\r\n/var/vcap/packages/bosh_aws_cpi/lib/cloud/aws/cloud.rb:122:in `create_vm'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_cpi-1.3071.0/lib/bosh/cpi/cli.rb:71:in `public_send'\r\n/var/vcap/packages/bosh_aws_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_cpi-1.3071.0/lib/bosh/cpi/cli.rb:71:in `run'\r\n/var/vcap/packages/bosh_aws_cpi/bin/aws_cpi:28:in `<main>'\r\n```\r\n"},"comment":{"url":"https://api.github.com/repos/cloudfoundry-incubator/bosh-aws-cpi-release/issues/comments/178945761","html_url":"https://github.com/cloudfoundry-incubator/bosh-aws-cpi-release/issues/19#issuecomment-178945761","issue_url":"https://api.github.com/repos/cloudfoundry-incubator/bosh-aws-cpi-release/issues/19","id":178945761,"user":{"login":"cppforlife","id":185847,"avatar_url":"https://avatars.githubusercontent.com/u/185847?v=3","gravatar_id":"","url":"https://api.github.com/users/cppforlife","html_url":"https://github.com/cppforlife","followers_url":"https://api.github.com/users/cppforlife/followers","following_url":"https://api.github.com/users/cppforlife/following{/other_user}","gists_url":"https://api.github.com/users/cppforlife/gists{/gist_id}","starred_url":"https://api.github.com/users/cppforlife/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/cppforlife/subscriptions","organizations_url":"https://api.github.com/users/cppforlife/orgs","repos_url":"https://api.github.com/users/cppforlife/repos","events_url":"https://api.github.com/users/cppforlife/events{/privacy}","received_events_url":"https://api.github.com/users/cppforlife/received_events","type":"User","site_admin":false},"created_at":"2016-02-03T01:29:07Z","updated_at":"2016-02-03T01:29:07Z","body":"@keymon thanks for details notes. we'll expose max_retries configuration and document it."}}