[Python3.6] start-api cuts reponse body to 16KB

Caian commented 6 years ago

Description:

I have a lambda code that returns a static base64-encoded HTML of around 21KB in size (AWS compliant JSON + encoded body), but when running with sam local start-api I only receive a string with the partial base64-encoded data as response and not the decoded HTML.

There are no errors in the log, even with --debug.

I think the entire response is being cut and the fields informing the base64 encoding are also being cut out because I have executed the lambda directly from docker using:

docker run --rm -v "$PWD":/var/task lambci/lambda:python3.6 handler.lambda_handler '{"httpMethod": "GET", "body": null, "resource": "/", "requestContext": {"resourceId": "123456", "apiId": "1234567890", "resourcePath": "/", "httpMethod": "GET", "requestId": "c6af9ac6-7b61-11e6-9a41-93e8deadbeef", "accountId": "123456789012", "stage": "prod", "identity": {"apiKey": null, "userArn": null, "cognitoAuthenticationType": null, "caller": null, "userAgent": "Custom User Agent String", "user": null, "cognitoIdentityPoolId": null, "cognitoAuthenticationProvider": null, "sourceIp": "127.0.0.1", "accountId": null}, "extendedRequestId": null, "path": "/"}, "queryStringParameters": null, "headers": {"Host": "127.0.0.1:3000", "Connection": "keep-alive", "Cache-Control": "max-age=0", "Upgrade-Insecure-Requests": "1", "User-Agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36", "Accept": "text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8", "Accept-Encoding": "gzip, deflate, br", "Accept-Language": "en-US,en;q=0.9", "Cookie": "csrftoken=62SITV38M5HButV20locwpQKAgBv3B6SChMlhSOG4hbYCGX0uAzMm3CxOHuzrMmo", "X-Forwarded-Proto": "http", "X-Forwarded-Port": "3000"}, "pathParameters": null, "stageVariables": null, "path": "/", "isBase64Encoded": false}'

and the output appears correct.

Steps to reproduce the issue:

Create a lambda that returns a base64-encoded body of around 21KB in size;
Run sam local start-api;
Acess the local API from a browser;

Observed result:

The body is cut and not decoded from base64 to HTML

Expected result:

The full HTML page: https://en.wikipedia.org/wiki/Django_(web_framework)#/media/File:Django_2.1_landing_page.png

Additional environment details (Ex: Windows, Mac, Amazon Linux etc)

Linux Mint 18

Output of sam --version:

SAM CLI, version 0.6.0

Optional Debug logs:

2018-09-02 12:01:05 Constructed String representation of Event to invoke Lambda. Event: {"httpMethod": "GET", "body": null, "resource": "/", "requestContext": {"resourceId": "123456", "apiId": "1234567890", "resourcePath": "/", "httpMethod": "GET", "requestId": "c6af9ac6-7b61-11e6-9a41-93e8deadbeef", "accountId": "123456789012", "stage": "prod", "identity": {"apiKey": null, "userArn": null, "cognitoAuthenticationType": null, "caller": null, "userAgent": "Custom User Agent String", "user": null, "cognitoIdentityPoolId": null, "cognitoAuthenticationProvider": null, "sourceIp": "127.0.0.1", "accountId": null}, "extendedRequestId": null, "path": "/"}, "queryStringParameters": null, "headers": {"Host": "127.0.0.1:3000", "Connection": "keep-alive", "Cache-Control": "max-age=0", "Upgrade-Insecure-Requests": "1", "User-Agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36", "Accept": "text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8", "Accept-Encoding": "gzip, deflate, br", "Accept-Language": "en-US,en;q=0.9", "Cookie": "csrftoken=62SITV38M5HButV20locwpQKAgBv3B6SChMlhSOG4hbYCGX0uAzMm3CxOHuzrMmo", "X-Forwarded-Proto": "http", "X-Forwarded-Port": "3000"}, "pathParameters": null, "stageVariables": null, "path": "/", "isBase64Encoded": false}
2018-09-02 12:01:05 Found one Lambda function with name 'ZappaTestFunction'
2018-09-02 12:01:05 Invoking handler.lambda_handler (python3.6)
2018-09-02 12:01:05 Environment variables overrides data is standard format
2018-09-02 12:01:05 Loading AWS credentials from session with profile 'None'
2018-09-02 12:01:05 Loading variable profile from defaults.
2018-09-02 12:01:05 Loading variable config_file from defaults.
2018-09-02 12:01:05 Loading variable credentials_file from defaults.
2018-09-02 12:01:05 Loading variable data_path from defaults.
2018-09-02 12:01:05 Loading variable profile from defaults.
2018-09-02 12:01:05 Loading variable credentials_file from defaults.
2018-09-02 12:01:05 Loading variable config_file from defaults.
2018-09-02 12:01:05 Loading variable profile from defaults.
2018-09-02 12:01:05 Loading variable metadata_service_timeout from defaults.
2018-09-02 12:01:05 Loading variable profile from defaults.
2018-09-02 12:01:05 Loading variable metadata_service_num_attempts from defaults.
2018-09-02 12:01:05 Loading variable profile from defaults.
2018-09-02 12:01:05 Looking for credentials via: env
2018-09-02 12:01:05 Looking for credentials via: assume-role
2018-09-02 12:01:05 Looking for credentials via: shared-credentials-file
2018-09-02 12:01:05 Found credentials in shared credentials file: ~/.aws/credentials
2018-09-02 12:01:05 Loading variable profile from defaults.
2018-09-02 12:01:05 Loading variable profile from defaults.
2018-09-02 12:01:05 Loading variable region from config file with value 'us-east-1'.
2018-09-02 12:01:05 Loading variable profile from defaults.
2018-09-02 12:01:05 Loading variable profile from defaults.
2018-09-02 12:01:05 Loading variable region from config file with value 'us-east-1'.
2018-09-02 12:01:05 Loading variable profile from defaults.
2018-09-02 12:01:05 Loading variable profile from defaults.
2018-09-02 12:01:05 Loading variable region from config file with value 'us-east-1'.
2018-09-02 12:01:05 Resolving code path. Cwd=/home/caian/Desktop/aws-sam/sam-app, CodeUri=django_test/
2018-09-02 12:01:05 Resolved absolute path to code is /home/caian/Desktop/aws-sam/sam-app/django_test
2018-09-02 12:01:05 Code /home/caian/Desktop/aws-sam/sam-app/django_test is not a zip/jar file
2018-09-02 12:01:05 Trying paths: ['/home/caian/.docker/config.json', '/home/caian/.dockercfg']
2018-09-02 12:01:05 No config file found
2018-09-02 12:01:05 Trying paths: ['/home/caian/.docker/config.json', '/home/caian/.dockercfg']
2018-09-02 12:01:05 No config file found
2018-09-02 12:01:05 http://localhost:None "GET /v1.35/images/lambci/lambda:python3.6/json HTTP/1.1" 200 None
2018-09-02 12:01:05 Looking for auth config
2018-09-02 12:01:05 No auth config in memory - loading from filesystem
2018-09-02 12:01:05 Trying paths: ['/home/caian/.docker/config.json', '/home/caian/.dockercfg']
2018-09-02 12:01:05 No config file found
2018-09-02 12:01:05 Looking for auth entry for 'docker.io'
2018-09-02 12:01:05 No entry found
2018-09-02 12:01:05 No auth config found
2018-09-02 12:01:08 http://localhost:None "POST /v1.35/images/create?tag=python3.6&fromImage=lambci%2Flambda HTTP/1.1" 200 None

Fetching lambci/lambda:python3.6 Docker container image......
2018-09-02 12:01:08 Mounting /home/caian/Desktop/aws-sam/sam-app/django_test as /var/task:ro inside runtime container
2018-09-02 12:01:10 http://localhost:None "POST /v1.35/containers/create HTTP/1.1" 201 201
2018-09-02 12:01:10 http://localhost:None "GET /v1.35/containers/9d030423591c3a3ff266eb552dbe7436231eda675f0a43440348854ddb6fd0c3/json HTTP/1.1" 200 None
2018-09-02 12:01:10 http://localhost:None "GET /v1.35/containers/9d030423591c3a3ff266eb552dbe7436231eda675f0a43440348854ddb6fd0c3/json HTTP/1.1" 200 None
2018-09-02 12:01:11 http://localhost:None "POST /v1.35/containers/9d030423591c3a3ff266eb552dbe7436231eda675f0a43440348854ddb6fd0c3/start HTTP/1.1" 204 0
2018-09-02 12:01:11 Starting a timer for 100 seconds for function 'ZappaTestFunction'
2018-09-02 12:01:11 http://localhost:None "GET /v1.35/containers/9d030423591c3a3ff266eb552dbe7436231eda675f0a43440348854ddb6fd0c3/json HTTP/1.1" 200 None
2018-09-02 12:01:11 http://localhost:None "POST /containers/9d030423591c3a3ff266eb552dbe7436231eda675f0a43440348854ddb6fd0c3/attach?stdout=1&stderr=1&logs=1&stream=1&stdin=0 HTTP/1.1" 101 0
START RequestId: 97c54ba4-4222-4eb0-b067-d9ecc7647f35 Version: $LATEST
{'httpMethod': 'GET', 'body': None, 'resource': '/', 'requestContext': {'resourceId': '123456', 'apiId': '1234567890', 'resourcePath': '/', 'httpMethod': 'GET', 'requestId': 'c6af9ac6-7b61-11e6-9a41-93e8deadbeef', 'accountId': '123456789012', 'stage': 'prod', 'identity': {'apiKey': None, 'userArn': None, 'cognitoAuthenticationType': None, 'caller': None, 'userAgent': 'Custom User Agent String', 'user': None, 'cognitoIdentityPoolId': None, 'cognitoAuthenticationProvider': None, 'sourceIp': '127.0.0.1', 'accountId': None}, 'extendedRequestId': None, 'path': '/'}, 'queryStringParameters': None, 'headers': {'Host': '127.0.0.1:3000', 'Connection': 'keep-alive', 'Cache-Control': 'max-age=0', 'Upgrade-Insecure-Requests': '1', 'User-Agent': 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36', 'Accept': 'text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8', 'Accept-Encoding': 'gzip, deflate, br', 'Accept-Language': 'en-US,en;q=0.9', 'Cookie': 'csrftoken=62SITV38M5HButV20locwpQKAgBv3B6SChMlhSOG4hbYCGX0uAzMm3CxOHuzrMmo', 'X-Forwarded-Proto': 'http', 'X-Forwarded-Port': '3000'}, 'pathParameters': None, 'stageVariables': None, 'path': '/', 'isBase64Encoded': False}
['__class__', '__delattr__', '__dict__', '__dir__', '__doc__', '__eq__', '__format__', '__ge__', '__getattribute__', '__gt__', '__hash__', '__init__', '__init_subclass__', '__le__', '__lt__', '__module__', '__ne__', '__new__', '__reduce__', '__reduce_ex__', '__repr__', '__setattr__', '__sizeof__', '__str__', '__subclasshook__', '__weakref__', 'aws_request_id', 'client_context', 'function_name', 'function_version', 'get_remaining_time_in_millis', 'identity', 'invoked_function_arn', 'log', 'log_group_name', 'log_stream_name', 'memory_limit_in_mb']
Instancing..
[DEBUG] 2018-09-02T15:01:13.310Z    97c54ba4-4222-4eb0-b067-d9ecc7647f35    Zappa Event: {'httpMethod': 'GET', 'body': None, 'resource': '/', 'requestContext': {'resourceId': '123456', 'apiId': '1234567890', 'resourcePath': '/', 'httpMethod': 'GET', 'requestId': 'c6af9ac6-7b61-11e6-9a41-93e8deadbeef', 'accountId': '123456789012', 'stage': 'prod', 'identity': {'apiKey': None, 'userArn': None, 'cognitoAuthenticationType': None, 'caller': None, 'userAgent': 'Custom User Agent String', 'user': None, 'cognitoIdentityPoolId': None, 'cognitoAuthenticationProvider': None, 'sourceIp': '127.0.0.1', 'accountId': None}, 'extendedRequestId': None, 'path': '/'}, 'queryStringParameters': None, 'headers': {'Host': '127.0.0.1:3000', 'Connection': 'keep-alive', 'Cache-Control': 'max-age=0', 'Upgrade-Insecure-Requests': '1', 'User-Agent': 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36', 'Accept': 'text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8', 'Accept-Encoding': 'gzip, deflate, br', 'Accept-Language': 'en-US,en;q=0.9', 'Cookie': 'csrftoken=62SITV38M5HButV20locwpQKAgBv3B6SChMlhSOG4hbYCGX0uAzMm3CxOHuzrMmo', 'X-Forwarded-Proto': 'http', 'X-Forwarded-Port': '3000'}, 'pathParameters': None, 'stageVariables': None, 'path': '/', 'isBase64Encoded': False}

[INFO]  2018-09-02T15:01:13.339Z    97c54ba4-4222-4eb0-b067-d9ecc7647f35    127.0.0.1 - - [02/Sep/2018:15:01:13 +0000] "GET / HTTP/1.1" 200 16348 "" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36" 0/28.153000000000002

END RequestId: 97c54ba4-4222-4eb0-b067-d9ecc7647f35
REPORT RequestId: 97c54ba4-4222-4eb0-b067-d9ecc7647f35 Duration: 1600 ms Billed Duration: 1700 ms Memory Size: 128 MB Max Memory Used: 39 MB
2018-09-02 12:01:14 http://localhost:None "GET /v1.35/containers/9d030423591c3a3ff266eb552dbe7436231eda675f0a43440348854ddb6fd0c3/json HTTP/1.1" 200 None
2018-09-02 12:01:14 http://localhost:None "DELETE /v1.35/containers/9d030423591c3a3ff266eb552dbe7436231eda675f0a43440348854ddb6fd0c3?v=False&link=False&force=True HTTP/1.1" 204 0
2018-09-02 12:01:14 127.0.0.1 - - [02/Sep/2018 12:01:14] "GET / HTTP/1.1" 200 -
2018-09-02 12:01:14 127.0.0.1 - - [02/Sep/2018 12:01:14] "GET /favicon.ico HTTP/1.1" 403 -

Thank you,

Caian

Caian commented 6 years ago

Some additional information:

The data is being read correctly from the docker container (as seen up to local_apigw_service.py:146);
The size of the trimmed body matches the content size of 16348 bytes specified in the response;

Maybe the data is not being decoded before asserting the content length?

EDIT: It appears that is_best_match_in_binary_types = False in _should_base64_decode_body even though is_base_64_encoded = True so data never gets decoded.

sanathkr commented 6 years ago

In your SAM template, have you set BinaryMediaType? And the media type specified in this setting must match the content-type in your response. This will set is_best_match_in_binary_types to True and trigger a decode.

Caian commented 6 years ago

Hello,

No, I haven't set BinaryMediaType, do you have any documentation for this option? In my case the content is plain text/html that is automatically encoded as base64 by the Zappa framework. Should I set BinaryMediaType to */*? Is this related to #312?

Can you please elaborate on the logic behind this design? Because I am struggling to understand why does the list of binary media types have preference over the field in the response stating that the body is encoded as base64. Shouldn't be an OR operation instead?

Thank you.

jfuss commented 5 years ago

@Caian The design is aimed to emulate the APIGateway Service. Have you run this on AWS? Can you provide a full example to make reproducing easier?

jfuss commented 5 years ago

Closing due to no response.

aws / aws-sam-cli

[Python3.6] start-api cuts reponse body to 16KB #646