Aws-sam-cli: 1.13.1: Invalid lambda response received: Lambda response must be valid json

[BR0kEN-]

Description:

sam local start-api stopped triggering Lambda by HTTP request. Downgrading to 1.12.0 gives the expected result.

Steps to reproduce:

sam build --use-container --debug
sam local start-api --port 4004 --docker-network host --skip-pull-image --debug &
curl -X POST http://127.0.0.1:4004/api/v1/app/add

Observed result:

2020-12-02 19:41:11,763 | Constructed String representation of Event to invoke Lambda. Event: {"body": null, "headers": {"Accept": "*/*", "Accept-Encoding": "gzip, deflate", "Connection": "keep-alive", "Content-Length": "0", "Host": "127.0.0.1:4004", "User-Agent": "python-requests/2.23.0", "X-Forwarded-Port": "4004", "X-Forwarded-Proto": "http"}, "httpMethod": "POST", "isBase64Encoded": false, "multiValueHeaders": {"Accept": ["*/*"], "Accept-Encoding": ["gzip, deflate"], "Connection": ["keep-alive"], "Content-Length": ["0"], "Host": ["127.0.0.1:4004"], "User-Agent": ["python-requests/2.23.0"], "X-Forwarded-Port": ["4004"], "X-Forwarded-Proto": ["http"]}, "multiValueQueryStringParameters": null, "path": "/api/v1/app/add", "pathParameters": {"schema_app": "app", "schema_version": "v1"}, "queryStringParameters": null, "requestContext": {"accountId": "123456789012", "apiId": "1234567890", "domainName": "127.0.0.1:4004", "extendedRequestId": null, "httpMethod": "POST", "identity": {"accountId": null, "apiKey": null, "caller": null, "cognitoAuthenticationProvider": null, "cognitoAuthenticationType": null, "cognitoIdentityPoolId": null, "sourceIp": "127.0.0.1", "user": null, "userAgent": "Custom User Agent String", "userArn": null}, "path": "/api/{schema_version}/{schema_app}/add", "protocol": "HTTP/1.1", "requestId": "b5ee986a-61f4-4954-b68b-c2af1457d70c", "requestTime": "02/Dec/2020:15:39:25 +0000", "requestTimeEpoch": 1606923565, "resourceId": "123456", "resourcePath": "/api/{schema_version}/{schema_app}/add", "stage": "staging"}, "resource": "/api/{schema_version}/{schema_app}/add", "stageVariables": null, "version": "1.0"}
2020-12-02 19:41:11,764 | Found one Lambda function with name 'Locator'
2020-12-02 19:41:11,764 | Invoking handler_locator.handle (python3.7)
2020-12-02 19:41:11,764 | Environment variables overrides data is standard format
2020-12-02 19:41:11,764 | Resolving code path. Cwd=/Users/BR0kEN/projects/SANITIZED/.aws-sam/build, CodeUri=Locator
2020-12-02 19:41:11,764 | Resolved absolute path to code is /Users/BR0kEN/projects/SANITIZED/.aws-sam/build/Locator
2020-12-02 19:41:11,764 | Code /Users/BR0kEN/projects/SANITIZED/.aws-sam/build/Locator is not a zip/jar file
2020-12-02 19:41:11,783 | Requested to skip pulling images ...

2020-12-02 19:41:11,783 | Mounting /Users/BR0kEN/projects/SANITIZED/.aws-sam/build/Locator as /var/task:ro,delegated inside runtime container
2020-12-02 19:41:12,269 | Starting a timer for 180 seconds for function 'Locator'
2020-12-02 19:41:13,118 | No response from invoke container for Locator
2020-12-02 19:41:13,119 | Invalid lambda response received: Lambda response must be valid json
2020-12-02 19:41:13 127.0.0.1 - - [02/Dec/2020 19:41:13] "POST /api/v1/app/add HTTP/1.1" 502 -

Expected result:

2020-12-02 19:43:51,479 | Constructed String representation of Event to invoke Lambda. Event: {"body": null, "headers": {"Accept": "*/*", "Accept-Encoding": "gzip, deflate", "Connection": "keep-alive", "Content-Length": "0", "Host": "127.0.0.1:4004", "User-Agent": "python-requests/2.23.0", "X-Forwarded-Port": "4004", "X-Forwarded-Proto": "http"}, "httpMethod": "POST", "isBase64Encoded": false, "multiValueHeaders": {"Accept": ["*/*"], "Accept-Encoding": ["gzip, deflate"], "Connection": ["keep-alive"], "Content-Length": ["0"], "Host": ["127.0.0.1:4004"], "User-Agent": ["python-requests/2.23.0"], "X-Forwarded-Port": ["4004"], "X-Forwarded-Proto": ["http"]}, "multiValueQueryStringParameters": null, "path": "/api/v1/app/add", "pathParameters": {"schema_app": "app", "schema_version": "v1"}, "queryStringParameters": null, "requestContext": {"accountId": "123456789012", "apiId": "1234567890", "domainName": "127.0.0.1:4004", "extendedRequestId": null, "httpMethod": "POST", "identity": {"accountId": null, "apiKey": null, "caller": null, "cognitoAuthenticationProvider": null, "cognitoAuthenticationType": null, "cognitoIdentityPoolId": null, "sourceIp": "127.0.0.1", "user": null, "userAgent": "Custom User Agent String", "userArn": null}, "path": "/api/{schema_version}/{schema_app}/add", "protocol": "HTTP/1.1", "requestId": "03b60fd2-78ab-4fc4-bcfa-930e57bfd9ee", "requestTime": "02/Dec/2020:15:43:40 +0000", "requestTimeEpoch": 1606923820, "resourceId": "123456", "resourcePath": "/api/{schema_version}/{schema_app}/add", "stage": "staging"}, "resource": "/api/{schema_version}/{schema_app}/add", "stageVariables": null, "version": "1.0"}
2020-12-02 19:43:51,479 | Found one Lambda function with name 'Locator'
2020-12-02 19:43:51,480 | Invoking handler_locator.handle (python3.7)
2020-12-02 19:43:51,480 | Environment variables overrides data is standard format
2020-12-02 19:43:51,480 | Loading AWS credentials from session with profile 'None'
2020-12-02 19:43:51,492 | Resolving code path. Cwd=/Users/BR0kEN/projects/SANITIZED/.aws-sam/build, CodeUri=Locator
2020-12-02 19:43:51,493 | Resolved absolute path to code is /Users/BR0kEN/projects/SANITIZED/.aws-sam/build/Locator
2020-12-02 19:43:51,493 | Code /Users/BR0kEN/projects/SANITIZED/.aws-sam/build/Locator is not a zip/jar file
2020-12-02 19:43:51,500 | Image was not found.
Building image.........
2020-12-02 19:43:51,831 | Requested to skip pulling images ...

2020-12-02 19:43:51,832 | Mounting /Users/BR0kEN/projects/SANITIZED/.aws-sam/build/Locator as /var/task:ro,delegated inside runtime container
2020-12-02 19:43:52,374 | Starting a timer for 180 seconds for function 'Locator'
START RequestId: e1cdfb2a-7475-1d51-6178-88c4176b300c Version: $LATEST
[ERROR] 2020-12-02T15:43:53.738Z    e1cdfb2a-7475-1d51-6178-88c4176b300c    POST: handler failed.
Traceback (most recent call last):
  File "/var/task/src/controller.py", line 130, in _get_data_document_prepared_for_storage
    document = self._schema.get_data_document(request.body, update)
  File "/var/task/src/schema/schema.py", line 117, in get_data_document
    raise ValidationError(["no data provided"])
src.validation.errors.ValidationError: ['no data provided']

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/var/task/src/handler/handler.py", line 149, in handle_request
    return _handlers[method](HandlerRequest(method, resource, body, query))
  File "/var/task/src/controller.py", line 31, in create
    fields=self._get_data_document_prepared_for_storage(request, update=False),
  File "/var/task/src/controller.py", line 132, in _get_data_document_prepared_for_storage
    raise HandlerError(error_code, {"body": error.errors})
src.handler.handler.HandlerError: Invalid document
END RequestId: e1cdfb2a-7475-1d51-6178-88c4176b300c
REPORT RequestId: e1cdfb2a-7475-1d51-6178-88c4176b300c  Init Duration: 1349.40 ms   Duration: 46.97 ms  Billed Duration: 100 ms Memory Size: 128 MB Max Memory Used: 32 MB
2020-12-02 19:43:53 127.0.0.1 - - [02/Dec/2020 19:43:53] "POST /api/v1/app/add HTTP/1.1" 400 -

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

1. OS: macOS Big Sur 11.0.1 (20B29)
2. sam --version: 1.13.1

[sdwvit]

is there any workaround available? how do I downgrade?

[BR0kEN-]

@sdwvit

pip3 install aws-sam-cli==1.12.0

[AaronDDM]

Can confirm we are experiencing this. It did not occur in versions 1.3.0, 1.6.0. But I am not sure what version this bug was introduced in - we are getting this exact same issue in 1.13.2.

[smalec]

I'm getting the same error while trying to complete official tutorial: https://docs.aws.amazon.com/serverless-application-model/latest/developerguide/serverless-getting-started-hello-world.html.

Downgrading to 1.12.0 is not an option for those who use Lambda Images.

[meetreks]

Getting the same error as well. Looks like a known bug. Any resolution will be really helpful. Error notes attached below...

Mounting HelloWorldFunction at http://127.0.0.1:3000/hello [GET]
You can now browse to the above endpoints to invoke your functions. You do not need to restart/reload SAM CLI while working on your functions, changes will be reflected instantly/automatically. You only need to restart SAM CLI if you update your AWS SAM template
2020-12-08 20:13:25 * Running on http://127.0.0.1:3000/ (Press CTRL+C to quit)
Invoking app.lambda_handler (python3.6)
Skip pulling image and use local one: amazon/aws-sam-cli-emulation-image-python3.6:rapid-1.13.2.

Mounting C:\Users\rekharamesh\sai-sam-model.aws-sam\build\HelloWorldFunction as /var/task:ro,delegated inside runtime container
No response from invoke container for HelloWorldFunction
Invalid lambda response received: Lambda response must be valid json
2020-12-08 20:14:03 127.0.0.1 - - [08/Dec/2020 20:14:03] "←[35m←[1mGET /hello HTTP/1.1←[0m" 502 -
2020-12-08 20:14:03 127.0.0.1 - - [08/Dec/2020 20:14:03] "←[31m←[1mGET /favicon.ico HTTP/1.1←[0m" 403 -
Invoking app.lambda_handler (python3.6)
Skip pulling image and use local one: amazon/aws-sam-cli-emulation-image-python3.6:rapid-1.13.2.

Mounting C:\Users\rekharamesh\sai-sam-model.aws-sam\build\HelloWorldFunction as /var/task:ro,delegated inside runtime container
No response from invoke container for HelloWorldFunction
Invalid lambda response received: Lambda response must be valid json
2020-12-08 20:14:25 127.0.0.1 - - [08/Dec/2020 20:14:25] "←[35m←[1mGET /hello HTTP/1.1←[0m" 502 -
2020-12-08 20:14:25 127.0.0.1 - - [08/Dec/2020 20:14:25] "←[31m←[1mGET /favicon.ico HTTP/1.1←[0m" 403 -

[jefrnc]

I am having the same error 🤷‍♂️

[jfuss]

So I was doing some digging on #2436 and I think they are both related.

So between 1.12 and 1.13, we changed how we communicate with the container. In 1.12, we just execute the container to run the code. With 1.13, we updated to use aws-lambda-rie. aws-lambda-rie stands up an endpoint within the container to communicate with the runtime itself. Since we are not communicating over http with the container, SAM CLI exposes a port to communicate with. From what I can gather, Docker will not let you expose a port if you connect to the 'host' network. The problem is Docker doesn't fail if you configure a port and run on the host network, why docker why!?!?

This is why SAM CLI cannot communicate with the local function. I need to do some deeper investigation to see how we can get around this docker limitation. I am not trilled to have to move back to executing the container. Communicating over http gives us much more control and allows us to integrate nicely with aws-lambda-rie. Open to suggestion on this.

This only appears to break for the host network, so if you drop the --docker-network host or provide a non host network thing should work as expected.

[sriram-mv]

Workarounds:

• Create a new docker network and link other containers that you will need to have access to, during execution of sam local and then specify that network.
  
  
  
  • docker network create mynetwork
  
  
  • docker network connect mynetwork
  
  
  • docker network connect mynetwork
  
  
  • docker network connect mynetwork
  
  
  • sam local invoke —docker-network mynetwork
  
  
• If your application does not depend on any services running on the host OS, you can safely drop --docker-network host from your command.
• If you still need to talk to host services from with your lambda function code. You could use host.docker.internal as specified under: https://docs.docker.com/docker-for-mac/networking/#use-cases-and-workarounds

Use cases

• What are the use-cases for using --docker-network host?

Docker network host only works on Linux, so we are interested in hearing the use-cases to make sure we understand what kind of workloads will be impacted.

[BR0kEN-]

@sriram-mv here is the extract from the Makefile on one of my projects:

# Start local AWS API Gateway replica for API calls testing.
local-api: local-build wait-db-readiness
    @echo 'Use "make stop-local-api" to stop the API.'
    @# The "host" network should be used to connect to 
        @# the database, defined in Docker Compose.
    sam local start-api --port 4004 --docker-network host --skip-pull-image --debug &

Should also work with the network the Docker Compose creates for the stack. Didn't test but think it should.

Edit: Dec 13, 2020:

It does not work.

sam local start-api --port 4004 --docker-network SANITIZED_default --skip-pull-image --debug &
curl -X POST http://127.0.0.1:4004/api/v1/app/add

2020-12-13 12:36:40,357 | Mounting /Users/BR0kEN/projects/SANITIZED/.aws-sam/build/Locator as /var/task:ro,delegated inside runtime container
2020-12-13 12:36:41,071 | Starting a timer for 180 seconds for function 'Locator'
START RequestId: 25b69609-beb4-4be4-9a58-ebb839ececad Version: $LATEST
[ERROR] 2020-12-13T08:36:42.205Z    25b69609-beb4-4be4-9a58-ebb839ececad    Unable to establish database connection.
Traceback (most recent call last):
  File "/var/task/pymysql/connections.py", line 571, in connect
    **kwargs)
  File "/var/lang/lib/python3.7/socket.py", line 728, in create_connection
    raise err
  File "/var/lang/lib/python3.7/socket.py", line 716, in create_connection
    sock.connect(sa)
OSError: [Errno 99] Cannot assign requested address

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/var/task/src/storage/mysql/driver_mysql.py", line 74, in __init__
    connect_timeout=5,
  File "/var/task/pymysql/connections.py", line 327, in __init__
    self.connect()
  File "/var/task/pymysql/connections.py", line 619, in connect
    raise exc
pymysql.err.OperationalError: (2003, "Can't connect to MySQL server on 'localhost' ([Errno 99] Cannot assign requested address)")
[ERROR] 2020-12-13T08:36:42.206Z    25b69609-beb4-4be4-9a58-ebb839ececad    POST: handler failed.

Will try changing the DB connection host too. As you see the convenience is already lost.

Edit 2: does not work. Unable to connect to a database provided by Docker Compose from the host.

[BenVosper]

We're getting the same 502 response on 1.13.2. But we're not using the --docker-network flag at all.

We've been forced to fall back to 1.12.0.

Is there any information I can provide about our setup to help with this?

[jfuss]

@BR0kEN- You are trying to connect to localhost but the container is not on that network. You should be using host.docker.internal as the endpoint to communicate to if you are trying to actually communicate to your machines localhost.

[BR0kEN-]

@jfuss Well, yeah, that can work but why should I not be using the host Docker network and localhost for connection?

[jfuss]

@BR0kEN- SAM CLI need to publish a port in order to communicate to the container. Docker disallows this on host. Further more, Docker has documentation that states the host network driver is only supported on Linux: https://docs.docker.com/network/host/. On Mac and Windows, host means the docker vm not your machine. This is why we recommended to use a different network as this still allows us to publish a port for our communication and customers can still do communication within that docker network for whatever they need (though this may require different configuration of your endpoints in the local mode).

Please see https://github.com/aws/aws-sam-cli/issues/2436#issuecomment-742242804 and https://github.com/aws/aws-sam-cli/issues/2436#issuecomment-743472832 from above.

[smalec]

I'm using aws-sam-cli inside a docker conatiner and still can't get it working. Basically I want to run sam-app from official tutorial (https://docs.aws.amazon.com/serverless-application-model/latest/developerguide/serverless-getting-started-hello-world.html) inside docker container. So I have following Dockerfile:

FROM python:3.7.4-slim-buster

RUN pip install aws-sam-cli
RUN apt-get update && apt-get install -y git
RUN sam init --runtime python3.7 --dependency-manager pip --app-template hello-world --name sam-app --package-type Zip

WORKDIR sam-app

CMD sam build && sam local invoke "HelloWorldFunction" -e events/event.json

Running such Dockerfile (docker run -v /var/run/docker.sock:/var/run/docker.sock) ends with:

No response from invoke container for HelloWorldFunction

I've tried to run it in non-host network, but no success yet.

[OrenSchwartz]

getting the same thing. can anyone help ?