Lambda client apparently does not use connection pooling

[siscia]

Describe the bug

The lambda client (apparently) does not use correctly the https pooling.

Expected Behavior

Invoking lambda while using boto3 should use a connection pool and re-use previously established connections.

Current Behavior

The boto3 client, while using lambda, does not use the connection pooling and it re-creates a new connection at each invocation.

Reproduction Steps

>>> import boto3
>>> import datetime
>>> from botocore.config import Config
>>> 
>>> c = Config(tcp_keepalive = True)
>>> ll = boto3.client("lambda", "eu-west-1", config=c)
>>> boto3.set_stream_logger(name='')
>>> ll.invoke(FunctionName = "Test1")
2023-09-06 01:31:37,760 botocore.hooks [DEBUG] Event before-parameter-build.lambda.Invoke: calling handler <function generate_idempotent_uuid at 0x7fdc735fe950>
2023-09-06 01:31:37,760 botocore.regions [DEBUG] Calling endpoint provider with parameters: {'Region': 'eu-west-1', 'UseDualStack': False, 'UseFIPS': False}
2023-09-06 01:31:37,761 botocore.regions [DEBUG] Endpoint provider result: https://lambda.eu-west-1.amazonaws.com
2023-09-06 01:31:37,761 botocore.hooks [DEBUG] Event before-call.lambda.Invoke: calling handler <function add_recursion_detection_header at 0x7fdc735fe5f0>
2023-09-06 01:31:37,762 botocore.hooks [DEBUG] Event before-call.lambda.Invoke: calling handler <function inject_api_version_header_if_needed at 0x7fdc736201f0>
2023-09-06 01:31:37,762 botocore.endpoint [DEBUG] Making request for OperationModel(name=Invoke) with params: {'url_path': '/2015-03-31/functions/Test1/invocations', 'query_string': {}, 'method': 'POST', 'headers': {'User-Agent': 'Boto3/1.28.35 md/Botocore#1.31.35 ua/2.0 os/linux#6.2.0-32-generic md/arch#x86_64 lang/python#3.10.12 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.35'}, 'body': b'', 'url': 'https://lambda.eu-west-1.amazonaws.com/2015-03-31/functions/Test1/invocations', 'context': {'client_region': 'eu-west-1', 'client_config': <botocore.config.Config object at 0x7fdc734dff10>, 'has_streaming_input': True, 'auth_type': None}}
2023-09-06 01:31:37,762 botocore.hooks [DEBUG] Event request-created.lambda.Invoke: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7fdc734dfd60>>
2023-09-06 01:31:37,762 botocore.hooks [DEBUG] Event choose-signer.lambda.Invoke: calling handler <function set_operation_specific_signer at 0x7fdc735fe830>
2023-09-06 01:31:37,763 botocore.auth [DEBUG] Calculating signature using v4 auth.
2023-09-06 01:31:37,763 botocore.auth [DEBUG] CanonicalRequest:
POST
/2015-03-31/functions/Test1/invocations

host:lambda.eu-west-1.amazonaws.com
x-amz-date:20230905T233137Z

host;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2023-09-06 01:31:37,763 botocore.auth [DEBUG] StringToSign:
AWS4-HMAC-SHA256
20230905T233137Z
20230905/eu-west-1/lambda/aws4_request
19869adcde90b2100a5726d3d270efd00ff7883f17bf9ac202fe51b53e27462c
2023-09-06 01:31:37,763 botocore.auth [DEBUG] Signature:
3f19b3a3cdf2f8c3fac6259b3e1d50ca35dea371c74bbc885a0d0bbe560b342c
2023-09-06 01:31:37,763 botocore.hooks [DEBUG] Event request-created.lambda.Invoke: calling handler <function add_retry_headers at 0x7fdc736208b0>
2023-09-06 01:31:37,764 botocore.endpoint [DEBUG] Sending http request: <AWSPreparedRequest stream_output=True, method=POST, url=https://lambda.eu-west-1.amazonaws.com/2015-03-31/functions/Test1/invocations, headers={'User-Agent': b'Boto3/1.28.35 md/Botocore#1.31.35 ua/2.0 os/linux#6.2.0-32-generic md/arch#x86_64 lang/python#3.10.12 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.35', 'X-Amz-Date': b'20230905T233137Z', 'Authorization': b'AWS4-HMAC-SHA256 Credential=AKIA4SALOOJ7AEKUK5NR/20230905/eu-west-1/lambda/aws4_request, SignedHeaders=host;x-amz-date, Signature=3f19b3a3cdf2f8c3fac6259b3e1d50ca35dea371c74bbc885a0d0bbe560b342c', 'amz-sdk-invocation-id': b'2300ba10-6bb3-4e44-bc8c-b3b2bc8d7d9c', 'amz-sdk-request': b'attempt=1', 'Content-Length': '0'}>
2023-09-06 01:31:37,765 botocore.httpsession [DEBUG] Certificate path: /home/simo/projects/cloud-monitoring/lambdas/collector/lib/python3.10/site-packages/certifi/cacert.pem
2023-09-06 01:31:37,766 urllib3.connectionpool [DEBUG] Starting new HTTPS connection (1): lambda.eu-west-1.amazonaws.com:443
2023-09-06 01:31:37,962 urllib3.connectionpool [DEBUG] https://lambda.eu-west-1.amazonaws.com:443 "POST /2015-03-31/functions/Test1/invocations HTTP/1.1" 200 4
2023-09-06 01:31:37,962 botocore.parsers [DEBUG] Response headers: {'Date': 'Tue, 05 Sep 2023 23:31:37 GMT', 'Content-Type': 'application/json', 'Content-Length': '4', 'Connection': 'keep-alive', 'x-amzn-RequestId': '5ef4c0e1-1f8e-4379-ae61-867c4119e0c9', 'x-amzn-Remapped-Content-Length': '0', 'X-Amz-Executed-Version': '$LATEST', 'X-Amzn-Trace-Id': 'root=1-64f7ba59-40378aa81e4eecc34002f96a;sampled=0;lineage=9a3f0624:0'}
2023-09-06 01:31:37,962 botocore.parsers [DEBUG] Response body:
<botocore.response.StreamingBody object at 0x7fdc73431210>
2023-09-06 01:31:37,963 botocore.hooks [DEBUG] Event needs-retry.lambda.Invoke: calling handler <botocore.retryhandler.RetryHandler object at 0x7fdc733d5480>
2023-09-06 01:31:37,963 botocore.retryhandler [DEBUG] No retry needed.
{'ResponseMetadata': {'RequestId': '5ef4c0e1-1f8e-4379-ae61-867c4119e0c9', 'HTTPStatusCode': 200, 'HTTPHeaders': {'date': 'Tue, 05 Sep 2023 23:31:37 GMT', 'content-type': 'application/json', 'content-length': '4', 'connection': 'keep-alive', 'x-amzn-requestid': '5ef4c0e1-1f8e-4379-ae61-867c4119e0c9', 'x-amzn-remapped-content-length': '0', 'x-amz-executed-version': '$LATEST', 'x-amzn-trace-id': 'root=1-64f7ba59-40378aa81e4eecc34002f96a;sampled=0;lineage=9a3f0624:0'}, 'RetryAttempts': 0}, 'StatusCode': 200, 'ExecutedVersion': '$LATEST', 'Payload': <botocore.response.StreamingBody object at 0x7fdc73431210>}
>>> ll.invoke(FunctionName = "Test1")
2023-09-06 01:31:44,875 botocore.hooks [DEBUG] Event before-parameter-build.lambda.Invoke: calling handler <function generate_idempotent_uuid at 0x7fdc735fe950>
2023-09-06 01:31:44,876 botocore.regions [DEBUG] Calling endpoint provider with parameters: {'Region': 'eu-west-1', 'UseDualStack': False, 'UseFIPS': False}
2023-09-06 01:31:44,876 botocore.regions [DEBUG] Endpoint provider result: https://lambda.eu-west-1.amazonaws.com
2023-09-06 01:31:44,876 botocore.hooks [DEBUG] Event before-call.lambda.Invoke: calling handler <function add_recursion_detection_header at 0x7fdc735fe5f0>
2023-09-06 01:31:44,876 botocore.hooks [DEBUG] Event before-call.lambda.Invoke: calling handler <function inject_api_version_header_if_needed at 0x7fdc736201f0>
2023-09-06 01:31:44,876 botocore.endpoint [DEBUG] Making request for OperationModel(name=Invoke) with params: {'url_path': '/2015-03-31/functions/Test1/invocations', 'query_string': {}, 'method': 'POST', 'headers': {'User-Agent': 'Boto3/1.28.35 md/Botocore#1.31.35 ua/2.0 os/linux#6.2.0-32-generic md/arch#x86_64 lang/python#3.10.12 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.35'}, 'body': b'', 'url': 'https://lambda.eu-west-1.amazonaws.com/2015-03-31/functions/Test1/invocations', 'context': {'client_region': 'eu-west-1', 'client_config': <botocore.config.Config object at 0x7fdc734dff10>, 'has_streaming_input': True, 'auth_type': None}}
2023-09-06 01:31:44,877 botocore.hooks [DEBUG] Event request-created.lambda.Invoke: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7fdc734dfd60>>
2023-09-06 01:31:44,877 botocore.hooks [DEBUG] Event choose-signer.lambda.Invoke: calling handler <function set_operation_specific_signer at 0x7fdc735fe830>
2023-09-06 01:31:44,877 botocore.auth [DEBUG] Calculating signature using v4 auth.
2023-09-06 01:31:44,877 botocore.auth [DEBUG] CanonicalRequest:
POST
/2015-03-31/functions/Test1/invocations

host:lambda.eu-west-1.amazonaws.com
x-amz-date:20230905T233144Z

host;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2023-09-06 01:31:44,877 botocore.auth [DEBUG] StringToSign:
AWS4-HMAC-SHA256
20230905T233144Z
20230905/eu-west-1/lambda/aws4_request
5c0a022620dca2c963e0f8a5c225fb0d6e62a81805a8cf108581159417d5fd2c
2023-09-06 01:31:44,877 botocore.auth [DEBUG] Signature:
e216752c801c2d4da14021874a2158b9213457ba670cbb75e47397c1356967af
2023-09-06 01:31:44,877 botocore.hooks [DEBUG] Event request-created.lambda.Invoke: calling handler <function add_retry_headers at 0x7fdc736208b0>
2023-09-06 01:31:44,878 botocore.endpoint [DEBUG] Sending http request: <AWSPreparedRequest stream_output=True, method=POST, url=https://lambda.eu-west-1.amazonaws.com/2015-03-31/functions/Test1/invocations, headers={'User-Agent': b'Boto3/1.28.35 md/Botocore#1.31.35 ua/2.0 os/linux#6.2.0-32-generic md/arch#x86_64 lang/python#3.10.12 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.35', 'X-Amz-Date': b'20230905T233144Z', 'Authorization': b'AWS4-HMAC-SHA256 Credential=AKIA4SALOOJ7AEKUK5NR/20230905/eu-west-1/lambda/aws4_request, SignedHeaders=host;x-amz-date, Signature=e216752c801c2d4da14021874a2158b9213457ba670cbb75e47397c1356967af', 'amz-sdk-invocation-id': b'c6fe90f0-025e-43c4-85ef-9754627c1b13', 'amz-sdk-request': b'attempt=1', 'Content-Length': '0'}>
2023-09-06 01:31:44,878 botocore.httpsession [DEBUG] Certificate path: /home/simo/projects/cloud-monitoring/lambdas/collector/lib/python3.10/site-packages/certifi/cacert.pem
2023-09-06 01:31:44,878 urllib3.connectionpool [DEBUG] Starting new HTTPS connection (2): lambda.eu-west-1.amazonaws.com:443
2023-09-06 01:31:45,038 urllib3.connectionpool [DEBUG] https://lambda.eu-west-1.amazonaws.com:443 "POST /2015-03-31/functions/Test1/invocations HTTP/1.1" 200 4
2023-09-06 01:31:45,038 botocore.parsers [DEBUG] Response headers: {'Date': 'Tue, 05 Sep 2023 23:31:45 GMT', 'Content-Type': 'application/json', 'Content-Length': '4', 'Connection': 'keep-alive', 'x-amzn-RequestId': '7378ab96-2dcf-4c14-a539-07ecf685634d', 'x-amzn-Remapped-Content-Length': '0', 'X-Amz-Executed-Version': '$LATEST', 'X-Amzn-Trace-Id': 'root=1-64f7ba60-49e20e4f53f4df294f5cf864;sampled=0;lineage=9a3f0624:0'}
2023-09-06 01:31:45,038 botocore.parsers [DEBUG] Response body:
<botocore.response.StreamingBody object at 0x7fdc73431570>
2023-09-06 01:31:45,039 botocore.hooks [DEBUG] Event needs-retry.lambda.Invoke: calling handler <botocore.retryhandler.RetryHandler object at 0x7fdc733d5480>
2023-09-06 01:31:45,039 botocore.retryhandler [DEBUG] No retry needed.
{'ResponseMetadata': {'RequestId': '7378ab96-2dcf-4c14-a539-07ecf685634d', 'HTTPStatusCode': 200, 'HTTPHeaders': {'date': 'Tue, 05 Sep 2023 23:31:45 GMT', 'content-type': 'application/json', 'content-length': '4', 'connection': 'keep-alive', 'x-amzn-requestid': '7378ab96-2dcf-4c14-a539-07ecf685634d', 'x-amzn-remapped-content-length': '0', 'x-amz-executed-version': '$LATEST', 'x-amzn-trace-id': 'root=1-64f7ba60-49e20e4f53f4df294f5cf864;sampled=0;lineage=9a3f0624:0'}, 'RetryAttempts': 0}, 'StatusCode': 200, 'ExecutedVersion': '$LATEST', 'Payload': <botocore.response.StreamingBody object at 0x7fdc73431570>}

You can see twice the line:

2023-09-06 01:31:44,878 urllib3.connectionpool [DEBUG] Starting new HTTPS connection (2): lambda.eu-west-1.amazonaws.com:443

Also the latency is such that can be explained by establishing a new connection.

Possible Solution

No response

Additional Information/Context

I believe this was already reported in:

#2666

SDK version used

boto3-1.28.35

Environment details (OS name and version, etc.)

Ubuntu

[tim-finnigan]

Hi @siscia thanks for reaching out. The Boto3 invoke command corresponds to the Lambda Invoke API. And since you're calling the invoke command twice, it is expected behavior that a new request would be sent for each separate API call.

[siscia]

Hi @tim-finnigan ,

for sure, the request must be sent twice since we invoke the function twice.

What is unclear is why the HTTP connection is created anew for each invoke instead of re-using the previous connection.

[tim-finnigan]

Hi @siscia thanks for following up. I think the issue here is that when you call invoke, if you don't read the response returned from Lambda then the connection remains in a busy state and won't be reused. Reading the response as shown here frees up the connection for reuse:

import boto3
boto3.set_stream_logger('')

client = boto3.client('lambda')

def test_invoke():
    response = client.invoke(FunctionName='connectTest')
    response_payload = response['Payload']
    response_payload = response['Payload'].read().decode('utf-8') # Line here needed to read response
    print(response_payload)

test_invoke()
test_invoke()

[siscia]

That was it!

Thanks a lot for your support!