Aws-sam-cli: [nodejs10.x] response.Payload would show nothing ('') whenever an Error is thrown using mocha to run tests after `sam local start-lambda`.

Created on 11 Oct 2019  路  3Comments  路  Source: aws/aws-sam-cli

Description

After switching from nodejs8.10 to 10.x in sam.template.yaml file, if an Error was thrown, the Payload of a response (e.g., response.Payload) would not contain anything -- likely not even an empty string -- because when i tried to JSON.parse(response.Payload), it would throw SyntaxError: Unexpected end of JSON input. The response looked like this: { StatusCode: 200, Payload: '' }

However, in the Terminal running sam local start-lambda, you would still see the Error object with "errorType", "errorMessage", and "stack" properties on STDOUT, just could not store it in a variable, and in the Terminal that initiated the Lambda local invoke by running mocha -r ts-node/register src/tests/**/*.spec.ts, you could NOT see the Error being thrown.

(Note: It likely had nothing to do with chai the assertion library because i was not asserting or expecting anything yet, just wanted to see the response.Payload.)

Steps to reproduce

  1. In one Terminal window, cd ~/project/dir, run sam local start-lambda --region us-west-2
  2. In another Terminal window, cd ~/project/dir, run mocha -r ts-node/register src/tests/**/*.spec.ts

Files

  1. sam.template.yaml:
...
Resources:
  HelloWorldFunction:
    Type: AWS::Serverless::Function 
    Properties:
      ...
      Runtime: nodejs10.x
 ```

2. say, `src/tests/unit/test.spec.ts`: 

import * as AWS from 'aws-sdk';
import { LambdaInvocationParams } from '../src/aws/Lambda/LambdaParams';

const lambdaLocalConfig = new AWS.Lambda({
region: "us-west-2" ,
endpoint: "http://127.0.0.1:3001",
sslEnabled: false,
maxRetries: 0
});

export function lambdaLocalInvoke(params: LambdaInvocationParams) {
return new Promise((resolve, reject) => {
lambdaLocalConfig.invoke(params, (err: Error, data: any) => {
if (err) {
reject(err);
} else {
resolve(data);
}
});
});
}

describe("Test nodejs10.x", () => {
it("To see the response when an error is thrown:", async () => {
try {
const lambdaParams = new LambdaInvocationParams(FUNCTION_TO_TEST, JSON.stringify(LAMBDA_REQUEST));
const response = await lambdaLocalInvoke(lambdaParams);
console.log(response);
} catch (err) {
throw err;
}
}).timeout(10000);
});

3. The file containing Lambda Handler function:

export const handler = async (event: any) => {
try {
throw new Error("Something fishy....");
} catch (err) {
throw err;
}
return event;
}

### Observed result

In the Terminal running `sam local start-lambda`, which was as expected:

START RequestId: 76efd0aa-78a6-17ae-193c-93cb90086775 Version: $LATEST
2019-10-11T00:17:30.274Z 76efd0aa-78a6-17ae-193c-93cb90086775 INFO Running main function - const type
2019-10-11T00:17:30.319Z 76efd0aa-78a6-17ae-193c-93cb90086775 I at Runtime.r.lambdaHandler.e [as handler] (/var/task/ValidateReque at process._tickCallback (internal/process/next_tick.js:68:7)
2019-10-11T00:17:30.321Z 76efd0aa-78a6-17ae-193c-93cb90086775 ERROR Invoke Error {"errorType":"Error","errorMessage":"Something fishy....","stack":["Error: Something fishy...."," at Object. (/var/task/ValidateRequest.js:1:78919)"," at Generator.next ()"," at /var/task/ValidateRequest.js:1:78235"," at new Promise ()"," at a (/var/task/ValidateRequest.js:1:78009)"," at Runtime.r.lambdaHandler.e [as handler] (/var/task/ValidateRequest.js:1:78799)"," at Runtime.handleOnce (/var/runtime/Runtime.js:66:25)"," at process._tickCallback (internal/process/next_tick.js:68:7)"]}
END RequestId: 76efd0aa-78a6-17ae-193c-93cb90086775
REPORT RequestId: 76efd0aa-78a6-17ae-193c-93cb90086775 Duration: 67.00 ms Billed Duration: 100 ms Memory Size: 128 MB Max Memory Used: 48 MB
{
"errorType": "Error",
"errorMessage": "Something fishy...."
}

Nevertheless, in the Terminal that initiated the Lambda local invoke by running `mocha -r ts-node/register src/tests/**/*.spec.ts`, `console.log(response)` printed out the following:

{ StatusCode: 200, Payload: '' }

### Expected result

The expected result of the Terminal that initiated the Lambda local invoke by running `mocha -r ts-node/register src/tests/**/*.spec.ts` should look like this because after switching back to `nodejs8.10`, this was what it printed out by `console.log(response)`:

{
StatusCode: 200,
FunctionError: 'Unhandled',
Payload: '{"errorMessage":"Something fishy....","errorType":"Error","stackTrace":["Object. (/var/task/ValidateRequest.js:1:78981)","Generator.next ()","/var/task/ValidateRequest.js:1:78297","new Promise ()","a (/var/task/ValidateRequest.js:1:78071)","r.lambdaHandler.e (/var/task/ValidateRequest.js:1:78861)"]}'
}
```

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

  1. OS: macOS Mojave, version 10.14.6
  2. sam --version: SAM CLI, version 0.22.0
  3. "aws-sdk" of nodejs: 2.542.0
  4. "mocha" of nodejs: 6.2.1
arelocastart-lambda

Most helpful comment

I am seeing the same behaviour in my tests. For tests very similar to those by @bjea , comparing SAM CLI to real AWS Lambda reveals some differences:
SAM CLI 0.30.0, nodejs8.10 runtime:

{
  "StatusCode": 200,
  "FunctionError": "Unhandled",
  "Payload": "{\"errorMessage\":\"This is an error\",\"errorType\":\"Error\",\"stackTrace\":[\"exports.handler (/var/task/index.js:2:11)\"]}"
}

SAM CLI 0.30.0, nodejs10.x runtime:

{
  "StatusCode": 200,
  "Payload": ""
}

Real AWS Lambda, nodejs8.10 runtime:

{
  "StatusCode": 200,
  "FunctionError": "Handled",
  "ExecutedVersion": "$LATEST",
  "Payload": "{\"errorMessage\":\"This is an error\",\"errorType\":\"Error\",\"stackTrace\":[\"exports.handler (/var/task/index.js:2:11)\"]}"
}

Real AWS Lambda, nodejs10.x runtime:

{
  "StatusCode": 200,
  "FunctionError": "Unhandled",
  "ExecutedVersion": "$LATEST",
  "Payload": "{\"errorType\":\"Error\",\"errorMessage\":\"This is an error\",\"trace\":[\"Error: This is an error\",\"    at Runtime.exports.handler (/var/task/index.js:2:11)\",\"    at Runtime.handleOnce (/var/runtime/Runtime.js:66:25)\",\"    at process._tickCallback (internal/process/next_tick.js:68:7)\"]}"
}

The most problematic discrepancy for me is the empty Payload string, as my test verification steps assert on its contents.

All 3 comments

I am seeing the same behaviour in my tests. For tests very similar to those by @bjea , comparing SAM CLI to real AWS Lambda reveals some differences:
SAM CLI 0.30.0, nodejs8.10 runtime:

{
  "StatusCode": 200,
  "FunctionError": "Unhandled",
  "Payload": "{\"errorMessage\":\"This is an error\",\"errorType\":\"Error\",\"stackTrace\":[\"exports.handler (/var/task/index.js:2:11)\"]}"
}

SAM CLI 0.30.0, nodejs10.x runtime:

{
  "StatusCode": 200,
  "Payload": ""
}

Real AWS Lambda, nodejs8.10 runtime:

{
  "StatusCode": 200,
  "FunctionError": "Handled",
  "ExecutedVersion": "$LATEST",
  "Payload": "{\"errorMessage\":\"This is an error\",\"errorType\":\"Error\",\"stackTrace\":[\"exports.handler (/var/task/index.js:2:11)\"]}"
}

Real AWS Lambda, nodejs10.x runtime:

{
  "StatusCode": 200,
  "FunctionError": "Unhandled",
  "ExecutedVersion": "$LATEST",
  "Payload": "{\"errorType\":\"Error\",\"errorMessage\":\"This is an error\",\"trace\":[\"Error: This is an error\",\"    at Runtime.exports.handler (/var/task/index.js:2:11)\",\"    at Runtime.handleOnce (/var/runtime/Runtime.js:66:25)\",\"    at process._tickCallback (internal/process/next_tick.js:68:7)\"]}"
}

The most problematic discrepancy for me is the empty Payload string, as my test verification steps assert on its contents.

I can confirm the bug. The issue is Lambda container returns 2 streams (Data and Error). In Node 8, container was returning error message in Data Stream[1] and empty error stream so we were parsing data stream and showing error message. Node 10 container returns error in Error Stream[2], which we are not parsing currently. I'll update this ticket once we come up with plan to fix the issue.

  1. b'\n{"errorType":"ReferenceError","errorMessage":"x is not defined","stackTrace":["exports.lambdaHandler (/var/task/app.js:2:3)"]}\n'
  2. b'2019-11-22T13:17:29.521Z\t1d2d61be-762f-1440-1624-e40cb550c4fe\tERROR\tInvoke Error\t{"errorType":"ReferenceError","errorMessage":"x is not defined","stack":["ReferenceError: x is not defined"," at Runtime.exports.lambdaHandler [as handler] (/var/task/app.js:2:3)"," at Runtime.handleOnce (/var/runtime/Runtime.js:66:25)"]}\n'
  3. Code to repro
exports.lambdaHandler = async (event, context) => {
  return x + 10;
};
  1. Command to trigger lambda: aws lambda invoke --function-name "HelloWorldFunction" --endpoint-url "http://127.0.0.1:3010" --no-verify-ssl nodejs10.out && cat nodejs10.out
  2. Output
{
    "StatusCode": 200
}
{"errorType":"ReferenceError","errorMessage":"x is not defined"}

Patched was released in 0.38.0.

Closing

Was this page helpful?
0 / 5 - 0 ratings

Related issues

joekiller picture joekiller  路  4Comments

PhungXuanAnh picture PhungXuanAnh  路  3Comments

Caian picture Caian  路  3Comments

asyba picture asyba  路  3Comments

cmccoypdx picture cmccoypdx  路  3Comments