Bug: sam local start-api - JSONDecodeError on API call with data

[irby]

Description:

I've noticed similar JSONDecodeError bugs mentioned in #4656 and #5067, but this one is specific to API calls made within my Lambda functions when I run locally. I'm running the latest SAM CLI version.

Steps to reproduce:

Have a request with data that is either sent to axios or fetch. For example:

const request = {
    method: 'post',
    url: 'http://myurl',
    headers: {
      'Content-Type': 'application/x-www-form-urlencoded',
    },
    data: qs.stringify({
      grant_type: 'client_credentials',
      ...
    }),
}

const response = await axios(request)

This call will

Traceback (most recent call last):                                                                                                                               
  File "flask/app.py", line 2529, in wsgi_app                                                                                                                    
  File "flask/app.py", line 1825, in full_dispatch_request                                                                                                       
  File "flask/app.py", line 1823, in full_dispatch_request                                                                                                       
  File "flask/app.py", line 1799, in dispatch_request                                                                                                            
  File "samcli/local/apigw/local_apigw_service.py", line 714, in _request_handler                                                                                
  File "samcli/local/apigw/local_apigw_service.py", line 612, in _invoke_lambda_function                                                                         
  File "samcli/commands/local/lib/local_lambda.py", line 144, in invoke                                                                                          
  File "samcli/lib/telemetry/metric.py", line 324, in wrapped_func                                                                                               
  File "samcli/local/lambdafn/runtime.py", line 201, in invoke                                                                                                   
  File "samcli/local/docker/container.py", line 354, in wait_for_result                                                                                          
  File "samcli/lib/utils/retry.py", line 30, in wrapper                                                                                                          
  File "samcli/local/docker/container.py", line 334, in wait_for_http_response                                                                                   
  File "json/__init__.py", line 357, in loads                                                                                                                    
  File "json/decoder.py", line 337, in decode                                                                                                                    
  File "json/decoder.py", line 355, in raw_decode                                                                                                                
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0) 

If I remove the data object from the axios call, I no longer hit this exception. For example:

const request = {
    method: 'post',
    url: 'http://myurl',
    headers: {
      'Content-Type': 'application/x-www-form-urlencoded',
    },
}

const response = await axios(request)

I do not hit the JSONDecodeError when I deploy my Lambda function to AWS, so I have a feeling this error is due to something under-the-hood in the SAM environment running my Lambda.

I've tried using fetch instead of axios to see if this was something axios related, but I saw similar results.

Observed result:

A json.decoder.JSONDecodeError is thrown when calling an API call with data

Expected result:

This error should not be thrown

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

{
  "version": "1.95.0",
  "system": {
    "python": "3.8.13",
    "os": "macOS-13.1-arm64-arm-64bit"
  },
  "additional_dependencies": {
    "docker_engine": "20.10.17",
    "aws_cdk": "Not available",
    "terraform": "1.5.3"
  },
  "available_beta_feature_env_vars": [
    "SAM_CLI_BETA_FEATURES",
    "SAM_CLI_BETA_BUILD_PERFORMANCE",
    "SAM_CLI_BETA_TERRAFORM_SUPPORT",
    "SAM_CLI_BETA_RUST_CARGO_LAMBDA"
  ]
}

[moelasmar]

thanks @irby for raising this issue. I will try to reproduce this issue.

[sbchisholm]

I encountered a the same json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0) using 1.95, reverting back to 1.94 resolved the issue for me.

Just noticed that 1.96 was released today, tested with that and have the same error as 1.95.

[moelasmar]

@sbchisholm, can you share your template with us, and also the function code?

[sbchisholm]

I can't share the function code unfortunately but I will say that it's C++.

sam cmd:

sam local start-lambda --template sam_template.yml --host 0.0.0.0 --env-vars sam_env.json --docker-network thingy

template:

AWSTemplateFormatVersion: '2010-09-09'
Transform: 'AWS::Serverless-2016-10-31'
Description: An AWS Serverless Specification template describing your function.
Resources:
  LambdaFunc:
    Type: 'AWS::Serverless::Function'
    Properties:
      Handler: lambda_handler
      Runtime: provided
      CodeUri: .
      Description: ''
      MemorySize: 1024
      Timeout: 900
      Environment:
        Variables:
          ...
          LOG_LEVEL:

[moelasmar]

can you run this command with --debug flag, and share the logs with us

[sbchisholm]

$ sam local start-lambda --template sam_template.yml --host 0.0.0.0 --env-vars sam_env.json --docker-network thingy --debug
2023-08-30 08:39:41,772 | No config file found in this directory.
2023-08-30 08:39:41,774 | OSError occurred while reading TOML file: [Errno 2] No such file or directory:
'/home/user/devel/project/build_output/lambda_func_sam_env/samconfig.toml'
2023-08-30 08:39:41,775 | Config file location:
/home/user/devel/project/build_output/lambda_func_sam_env/samconfig.toml
2023-08-30 08:39:41,776 | Config file
'/home/user/devel/project/build_output/lambda_func_sam_env/samconfig.toml' does not exist
2023-08-30 08:39:41,792 | Using config file: samconfig.toml, config environment: default
2023-08-30 08:39:41,793 | Expand command line arguments to:
2023-08-30 08:39:41,793 |
--template_file=/home/user/devel/project/build_output/lambda_func_sam_env/sam_template.yml
--host=0.0.0.0 --env_vars=sam_env.json --docker_network=portato --port=3001
--layer_cache_basedir=/home/user/.aws-sam/layers-pkg --container_host=localhost
--container_host_interface=127.0.0.1
2023-08-30 08:39:41,833 | local start_lambda command is called
2023-08-30 08:39:41,835 | No Parameters detected in the template
2023-08-30 08:39:41,845 | There is no customer defined id or cdk path defined for resource LambdaFunc,
so we will use the resource logical id as the resource id
2023-08-30 08:39:41,848 | Unable to resolve property LOG_LEVEL: None. Leaving as is.
2023-08-30 08:39:41,849 | 0 stacks found in the template
2023-08-30 08:39:41,849 | No Parameters detected in the template
2023-08-30 08:39:41,856 | There is no customer defined id or cdk path defined for resource LambdaFunc,
so we will use the resource logical id as the resource id
2023-08-30 08:39:41,859 | Unable to resolve property LOG_LEVEL: None. Leaving as is.
2023-08-30 08:39:41,859 | 1 resources found in the stack
2023-08-30 08:39:41,859 | Found Serverless function with name='LambdaFunc' and CodeUri='.'
2023-08-30 08:39:41,860 | --base-dir is not presented, adjusting uri . relative to
/home/user/devel/project/build_output/lambda_func_sam_env/sam_template.yml
2023-08-30 08:39:41,865 | Starting the Local Lambda Service. You can now invoke your Lambda Functions
defined in your template through the endpoint.
2023-08-30 08:39:41,865 | Localhost server is starting up. Multi-threading = True
2023-08-30 08:39:41 WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead.
 * Running on all addresses (0.0.0.0)
 * Running on http://127.0.0.1:3001
 * Running on http://192.168.1.178:3001
2023-08-30 08:39:41 Press CTRL+C to quit
2023-08-30 08:39:54,352 | Found one Lambda function with name 'LambdaFunc'
2023-08-30 08:39:54,352 | Invoking lambda_func (provided)
2023-08-30 08:39:54,353 | Environment variables data found for specific function in standard format
2023-08-30 08:39:54,353 | Loading AWS credentials from session with profile 'None'
2023-08-30 08:39:54,362 | Resolving code path.
Cwd=/home/user/devel/project/build_output/lambda_func_sam_env,
CodeUri=/home/user/devel/project/build_output/lambda_func_sam_env
2023-08-30 08:39:54,363 | Resolved absolute path to code is
/home/user/devel/project/build_output/lambda_func_sam_env
2023-08-30 08:39:54,363 | Code /home/user/devel/project/build_output/lambda_func_sam_env is not a
zip/jar file
2023-08-30 08:39:55,816 | Local image is up-to-date
2023-08-30 08:39:55,820 | Using local image: public.ecr.aws/lambda/provided:alami-rapid-x86_64.

2023-08-30 08:39:55,820 | Mounting /home/user/devel/project/build_output/lambda_func_sam_env as
/var/task:ro,delegated, inside runtime container
2023-08-30 08:39:56,167 | Starting a timer for 900 seconds for function 'LambdaFunc'
START RequestId: 2e8bf95b-3e58-4954-b305-dbec5dba4040 Version: $LATEST

...app logs...

END RequestId: 2e8bf95b-3e58-4954-b305-dbec5dba4040
REPORT RequestId: 2e8bf95b-3e58-4954-b305-dbec5dba4040  Init Duration: 0.11 ms  Duration: 2053.86 ms    Billed Duration: 2054 ms    Memory Size: 1024 MB    Max Memory Used: 1024 MB
2023-08-30 08:39:58,491 | Cleaning all decompressed code dirs
2023-08-30 08:39:58,492 | Exception on /2015-03-31/functions/LambdaFunc/invocations [POST]
Traceback (most recent call last):
  File "/home/user/.local/lib/python3.11/site-packages/flask/app.py", line 2529, in wsgi_app
    response = self.full_dispatch_request()
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/.local/lib/python3.11/site-packages/flask/app.py", line 1825, in
full_dispatch_request
    rv = self.handle_user_exception(e)
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/.local/lib/python3.11/site-packages/flask/app.py", line 1823, in
full_dispatch_request
    rv = self.dispatch_request()
         ^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/.local/lib/python3.11/site-packages/flask/app.py", line 1799, in dispatch_request
    return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File
"/home/user/.local/lib/python3.11/site-packages/samcli/local/lambda_service/local_lambda_invoke_service
.py", line 169, in _invoke_request_handler
    self.lambda_runner.invoke(function_name, request_data, stdout=stdout_stream_writer,
stderr=self.stderr)
  File "/home/user/.local/lib/python3.11/site-packages/samcli/commands/local/lib/local_lambda.py", line
144, in invoke
    self.local_runtime.invoke(
  File "/home/user/.local/lib/python3.11/site-packages/samcli/lib/telemetry/metric.py", line 324, in
wrapped_func
    return_value = func(*args, **kwargs)
                   ^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/.local/lib/python3.11/site-packages/samcli/local/lambdafn/runtime.py", line 201, in
invoke
    container.wait_for_result(
  File "/home/user/.local/lib/python3.11/site-packages/samcli/local/docker/container.py", line 354, in
wait_for_result
    response = self.wait_for_http_response(full_path, event, stdout)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/.local/lib/python3.11/site-packages/samcli/lib/utils/retry.py", line 30, in wrapper
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/.local/lib/python3.11/site-packages/samcli/local/docker/container.py", line 334, in
wait_for_http_response
    return json.dumps(json.loads(resp.content), ensure_ascii=False) if resp.content else ""
                      ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/.pyenv/versions/3.11.4/lib/python3.11/json/__init__.py", line 346, in loads
    return _default_decoder.decode(s)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/.pyenv/versions/3.11.4/lib/python3.11/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/.pyenv/versions/3.11.4/lib/python3.11/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
2023-08-30 08:39:58 10.99.0.13 - - [30/Aug/2023 08:39:58] "POST /2015-03-31/functions/LambdaFunc/invocations HTTP/1.1" 500 -

[hawflau]

@sbchisholm @irby Could you please let me know what your Lambda Code returns?

[sbchisholm]

@sbchisholm @irby Could you please let me know what your Lambda Code returns?

Yes it's just a string that says done or success or something simple like that. We're not returning an actual json object.

[hawflau]

I tried to reproduce and couldn't. I'm pretty sure that, in your case, the response from Lambda RIE was not a valid string that json.loads could de-serialize, and thus raise the JSONDecodeError.

In my attempts to reproduce the issue, I tried returning a string and returning nothing. And both responses got deserialized successfully. I think we can handle the JSONDecodeError gracefully.

[jigarzon]

This issue was fixed in my case, by upgrading from 1.95 to 1.97 version Still happening, I had one initial request working, but then it started failing again...

[jigarzon]

I fixed this increasing the MemorySize field in the sam config. It seems that SAM just kills the process in the middle, when memory gets above the limit, and generates an empty lambda response that breaks some parsing procedure

[kumulynja]

I fixed this increasing the MemorySize field in the sam config. It seems that SAM just kills the process in the middle, when memory gets above the limit, and generates an empty lambda response that breaks some parsing procedure

I had the same problem, also with axios, and this worked for me too, changed it from 128 to 256 and my axios.post works now. Thanks for figuring this out.

[github-actions]

Patch is released in v1.98.0. Closing