Aled Sage created BROOKLYN-399:
----------------------------------
Summary: aws-ec2 provisoining: retrieving images from every
region, rather than just one (inefficient!)
Key: BROOKLYN-399
URL: https://issues.apache.org/jira/browse/BROOKLYN-399
Project: Brooklyn
Issue Type: Bug
Affects Versions: 0.9.0
Reporter: Aled Sage
Assignee: Aled Sage
When provisioning a VM in an AWS region (using {{location:
aws-ec2:us-east-1}}), it retrieves the details of every region rather than just
the one specified.
For example, it calls {{DescribeAvailabilityZones}} in every region, and
{{DescribeImages}} in every region.
This is (a lot of!) unnecessary extra work that the Brooklyn server is doing.
It might also increases our changes of being rate-limited (if multiple apps are
deploying to different regions concurrently).
Below is the output showing the API calls we made:
{noformat}
grep -E "InvokeHttpMethod.* invoking
|JavaUrlHttpCommandExecutorService.*(Sending request|Receiving response)"
brooklyn.debug.log
2016-11-23 15:51:39,908 DEBUG o.j.r.i.InvokeHttpMethod [main]: >> invoking
DescribeRegions
2016-11-23 15:51:40,057 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Sending request -1293445899: POST https://ec2.us-east-1.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:40,891 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Receiving response -1293445899: HTTP/1.1 200 OK
2016-11-23 15:51:46,532 DEBUG o.j.r.i.InvokeHttpMethod [main]: >> invoking
DescribeAvailabilityZones
2016-11-23 15:51:46,537 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Sending request -586747076: POST https://ec2.eu-central-1.amazonaws.com/
HTTP/1.1
2016-11-23 15:51:46,729 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Receiving response -586747076: HTTP/1.1 200 OK
2016-11-23 15:51:46,740 DEBUG o.j.r.i.InvokeHttpMethod [main]: >> invoking
DescribeAvailabilityZones
2016-11-23 15:51:46,745 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Sending request -1119368789: POST https://ec2.sa-east-1.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:47,896 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Receiving response -1119368789: HTTP/1.1 200 OK
2016-11-23 15:51:47,902 DEBUG o.j.r.i.InvokeHttpMethod [main]: >> invoking
DescribeAvailabilityZones
2016-11-23 15:51:47,908 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Sending request -684139233: POST https://ec2.ap-northeast-1.amazonaws.com/
HTTP/1.1
2016-11-23 15:51:49,748 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Receiving response -684139233: HTTP/1.1 200 OK
2016-11-23 15:51:49,755 DEBUG o.j.r.i.InvokeHttpMethod [main]: >> invoking
DescribeAvailabilityZones
2016-11-23 15:51:49,758 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Sending request -1706527358: POST https://ec2.eu-west-1.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:49,949 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Receiving response -1706527358: HTTP/1.1 200 OK
2016-11-23 15:51:49,955 DEBUG o.j.r.i.InvokeHttpMethod [main]: >> invoking
DescribeAvailabilityZones
2016-11-23 15:51:49,957 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Sending request -252867372: POST https://ec2.us-east-1.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:50,384 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Receiving response -252867372: HTTP/1.1 200 OK
2016-11-23 15:51:50,390 DEBUG o.j.r.i.InvokeHttpMethod [main]: >> invoking
DescribeAvailabilityZones
2016-11-23 15:51:50,393 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Sending request 1267838460: POST https://ec2.us-west-1.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:51,138 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Receiving response 1267838460: HTTP/1.1 200 OK
2016-11-23 15:51:51,145 DEBUG o.j.r.i.InvokeHttpMethod [main]: >> invoking
DescribeAvailabilityZones
2016-11-23 15:51:51,147 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Sending request 679642982: POST https://ec2.us-west-2.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:51,829 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Receiving response 679642982: HTTP/1.1 200 OK
2016-11-23 15:51:51,835 DEBUG o.j.r.i.InvokeHttpMethod [main]: >> invoking
DescribeAvailabilityZones
2016-11-23 15:51:51,838 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Sending request 186208934: POST https://ec2.ap-southeast-2.amazonaws.com/
HTTP/1.1
2016-11-23 15:51:53,325 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Receiving response 186208934: HTTP/1.1 200 OK
2016-11-23 15:51:53,331 DEBUG o.j.r.i.InvokeHttpMethod [main]: >> invoking
DescribeAvailabilityZones
2016-11-23 15:51:53,334 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Sending request -1354539746: POST https://ec2.ap-southeast-1.amazonaws.com/
HTTP/1.1
2016-11-23 15:51:55,317 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [main]:
Receiving response -1354539746: HTTP/1.1 200 OK
2016-11-23 15:51:55,402 DEBUG o.j.r.i.InvokeHttpMethod [user thread 8]: >>
invoking DescribeImages
2016-11-23 15:51:55,402 DEBUG o.j.r.i.InvokeHttpMethod [user thread 10]: >>
invoking DescribeImages
2016-11-23 15:51:55,402 DEBUG o.j.r.i.InvokeHttpMethod [user thread 7]: >>
invoking DescribeImages
2016-11-23 15:51:55,402 DEBUG o.j.r.i.InvokeHttpMethod [user thread 6]: >>
invoking DescribeImages
2016-11-23 15:51:55,405 DEBUG o.j.r.i.InvokeHttpMethod [user thread 12]: >>
invoking DescribeImages
2016-11-23 15:51:55,406 DEBUG o.j.r.i.InvokeHttpMethod [user thread 11]: >>
invoking DescribeImages
2016-11-23 15:51:55,406 DEBUG o.j.r.i.InvokeHttpMethod [user thread 5]: >>
invoking DescribeImages
2016-11-23 15:51:55,402 DEBUG o.j.r.i.InvokeHttpMethod [user thread 2]: >>
invoking DescribeImages
2016-11-23 15:51:55,402 DEBUG o.j.r.i.InvokeHttpMethod [user thread 9]: >>
invoking DescribeImages
2016-11-23 15:51:55,407 DEBUG o.j.r.i.InvokeHttpMethod [user thread 4]: >>
invoking DescribeImages
2016-11-23 15:51:55,411 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 12]: Sending request 330550067: POST
https://ec2.ap-southeast-1.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:55,411 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 7]: Sending request -348882795: POST
https://ec2.eu-west-1.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:55,412 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 5]: Sending request 1825720062: POST
https://ec2.sa-east-1.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:55,412 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 8]: Sending request 489719034: POST https://ec2.us-east-1.amazonaws.com/
HTTP/1.1
2016-11-23 15:51:55,411 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 10]: Sending request 96455669: POST https://ec2.us-west-2.amazonaws.com/
HTTP/1.1
2016-11-23 15:51:55,413 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 6]: Sending request -79242123: POST
https://ec2.ap-northeast-1.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:55,411 DEBUG o.j.r.i.InvokeHttpMethod [user thread 3]: >>
invoking DescribeImages
2016-11-23 15:51:55,416 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 11]: Sending request 1188482435: POST
https://ec2.ap-southeast-2.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:55,416 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 4]: Sending request -1824164655: POST
https://ec2.us-west-2.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:55,417 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 2]: Sending request -1306355801: POST
https://ec2.us-east-1.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:55,420 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 3]: Sending request 1301021373: POST
https://ec2.eu-central-1.amazonaws.com/ HTTP/1.1
2016-11-23 15:51:55,421 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 9]: Sending request 607419236: POST https://ec2.us-west-1.amazonaws.com/
HTTP/1.1
2016-11-23 15:51:56,022 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 3]: Receiving response 1301021373: HTTP/1.1 200 OK
2016-11-23 15:51:56,466 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 7]: Receiving response -348882795: HTTP/1.1 200 OK
2016-11-23 15:51:56,909 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 2]: Receiving response -1306355801: HTTP/1.1 200 OK
2016-11-23 15:51:56,958 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 5]: Receiving response 1825720062: HTTP/1.1 200 OK
2016-11-23 15:51:56,958 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 9]: Receiving response 607419236: HTTP/1.1 200 OK
2016-11-23 15:51:57,081 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 4]: Receiving response -1824164655: HTTP/1.1 200 OK
2016-11-23 15:51:57,190 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 10]: Receiving response 96455669: HTTP/1.1 200 OK
2016-11-23 15:51:57,205 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 12]: Receiving response 330550067: HTTP/1.1 200 OK
2016-11-23 15:51:57,267 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 8]: Receiving response 489719034: HTTP/1.1 200 OK
2016-11-23 15:51:57,283 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 6]: Receiving response -79242123: HTTP/1.1 200 OK
2016-11-23 15:51:57,371 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 11]: Receiving response 1188482435: HTTP/1.1 200 OK
2016-11-23 15:52:00,883 DEBUG o.j.r.i.InvokeHttpMethod [user thread 4]: >>
invoking DescribeImages
2016-11-23 15:52:00,888 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 4]: Sending request 2102082252: POST
https://ec2.eu-west-1.amazonaws.com/ HTTP/1.1
2016-11-23 15:52:01,616 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 4]: Receiving response 2102082252: HTTP/1.1 200 OK
2016-11-23 15:53:05,250 DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService [user
thread 1]: Sending request 562982793: POST https://ec2.us-east-1.amazonaws.com/
HTTP/1.1
{noformat}
Digging into the jclouds code a bit, the {{AWSEC2ImageSupplier}} is constructed
with {{@Region Supplier<Set<String>> regions}} which delegates to
{{DescribeRegionsForRegionURIs}}. This will return all regions, unless
{{RegionIdsFromConfiguration}} is configured with the property
{{"jclouds.regions"}} which is used as a filter. After getting the regions, It
then calls {{DescribeImagesParallel}}, which calls {{describeImagesInRegion}}
on each of the given regions.
We can configure this easily in Brooklyn's {{ComputeServiceRegistryImpl}} to
set the property {{"jclouds.regions"}}.
Testing this, the time for resolving the template etc (not counting the VM
provisioning) goes from 110 seconds, down to 10 seconds!
The memory usage also improves massively. In a simple test where we resolve the
template but skip the VM provisioning, the memory usage peaked at 173MB. With
the "jclouds.regions" property set, it only peaked at 61MB.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
