aws / aws-sam-cli

CLI tool to build, test, debug, and deploy Serverless applications using AWS SAM
https://aws.amazon.com/serverless/sam/
Apache License 2.0
6.47k stars 1.16k forks source link

Non-Zero Exit Code is Swallowed #1081

Open jcald1 opened 5 years ago

jcald1 commented 5 years ago

Description

When a Lambda throws an error, the SAM tool prints the exception, but a zero exit code is returned.

Steps to reproduce

Create a Lambda that throws an Error. Call the Lambda with SAM, e.g.: sam local invoke "lambda1"

Observed result

{"errorMessage":"Test Error","errorType":"Error","stackTrace":["exports.handler (/var/task/index.js:24:9)"]}
✨  Done in 8.61s.
MLP-0U8HV2H:mediainfo user$ echo $?
0

Expected result

An exit code of 1 or greater

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

1. MacOS
2. `sam --version`:
SAM CLI, version 0.14.0
`Add --debug flag to command you are running`

--debug

2019-03-25 18:11:08 Using SAM Template at /Users/user/projects/connect5-lambda-mediainfo/lambdas/mediainfo/template.yml
2019-03-25 18:11:08 Changing event name from creating-client-class.iot-data to creating-client-class.iot-data-plane
2019-03-25 18:11:08 Changing event name from before-call.apigateway to before-call.api-gateway
2019-03-25 18:11:08 Changing event name from request-created.machinelearning.Predict to request-created.machine-learning.Predict
2019-03-25 18:11:08 Changing event name from before-parameter-build.autoscaling.CreateLaunchConfiguration to before-parameter-build.auto-scaling.CreateLaunchConfiguration
2019-03-25 18:11:08 Changing event name from before-parameter-build.route53 to before-parameter-build.route-53
2019-03-25 18:11:08 Changing event name from request-created.cloudsearchdomain.Search to request-created.cloudsearch-domain.Search
2019-03-25 18:11:08 Changing event name from docs.*.autoscaling.CreateLaunchConfiguration.complete-section to docs.*.auto-scaling.CreateLaunchConfiguration.complete-section
2019-03-25 18:11:08 Changing event name from before-parameter-build.logs.CreateExportTask to before-parameter-build.cloudwatch-logs.CreateExportTask
2019-03-25 18:11:08 Changing event name from docs.*.logs.CreateExportTask.complete-section to docs.*.cloudwatch-logs.CreateExportTask.complete-section
2019-03-25 18:11:08 Changing event name from before-parameter-build.cloudsearchdomain.Search to before-parameter-build.cloudsearch-domain.Search
2019-03-25 18:11:08 Changing event name from docs.*.cloudsearchdomain.Search.complete-section to docs.*.cloudsearch-domain.Search.complete-section
2019-03-25 18:11:08 Changing event name from creating-client-class.iot-data to creating-client-class.iot-data-plane
2019-03-25 18:11:08 Changing event name from before-call.apigateway to before-call.api-gateway
2019-03-25 18:11:08 Changing event name from request-created.machinelearning.Predict to request-created.machine-learning.Predict
2019-03-25 18:11:08 Changing event name from before-parameter-build.autoscaling.CreateLaunchConfiguration to before-parameter-build.auto-scaling.CreateLaunchConfiguration
2019-03-25 18:11:08 Changing event name from before-parameter-build.route53 to before-parameter-build.route-53
2019-03-25 18:11:08 Changing event name from request-created.cloudsearchdomain.Search to request-created.cloudsearch-domain.Search
2019-03-25 18:11:08 Changing event name from docs.*.autoscaling.CreateLaunchConfiguration.complete-section to docs.*.auto-scaling.CreateLaunchConfiguration.complete-section
2019-03-25 18:11:08 Changing event name from before-parameter-build.logs.CreateExportTask to before-parameter-build.cloudwatch-logs.CreateExportTask
2019-03-25 18:11:08 Changing event name from docs.*.logs.CreateExportTask.complete-section to docs.*.cloudwatch-logs.CreateExportTask.complete-section
2019-03-25 18:11:08 Changing event name from before-parameter-build.cloudsearchdomain.Search to before-parameter-build.cloudsearch-domain.Search
2019-03-25 18:11:08 Changing event name from docs.*.cloudsearchdomain.Search.complete-section to docs.*.cloudsearch-domain.Search.complete-section
2019-03-25 18:11:08 local invoke command is called
2019-03-25 18:11:08 No Parameters detected in the template
2019-03-25 18:11:08 1 resources found in the template
2019-03-25 18:11:08 Found Serverless function with name='tfdefaultroutefile' and CodeUri='.'
2019-03-25 18:11:08 Trying paths: ['/Users/user/.docker/config.json', '/Users/user/.dockercfg']
2019-03-25 18:11:08 Found file at path: /Users/user/.docker/config.json
2019-03-25 18:11:08 Found 'auths' section
2019-03-25 18:11:08 Auth data for https://index.docker.io/v1/ is absent. Client might be using a credentials store instead.
2019-03-25 18:11:08 http://localhost:None "GET /v1.35/_ping HTTP/1.1" 200 2
2019-03-25 18:11:08 Looking for credentials via: env
2019-03-25 18:11:08 Found credentials in environment variables.
2019-03-25 18:11:08 Loading JSON file: /usr/local/Cellar/aws-sam-cli/0.14.0/libexec/lib/python3.7/site-packages/botocore/data/endpoints.json
2019-03-25 18:11:08 Event choose-service-name: calling handler <function handle_service_name_alias at 0x10b4df840>
2019-03-25 18:11:08 Loading JSON file: /usr/local/Cellar/aws-sam-cli/0.14.0/libexec/lib/python3.7/site-packages/botocore/data/lambda/2015-03-31/service-2.json
2019-03-25 18:11:08 Event creating-client-class.lambda: calling handler <function add_generate_presigned_url at 0x10b4a4378>
2019-03-25 18:11:08 The s3 config key is not a dictionary type, ignoring its value of: None
2019-03-25 18:11:08 Setting lambda timeout as (60, 60)
2019-03-25 18:11:08 Loading JSON file: /usr/local/Cellar/aws-sam-cli/0.14.0/libexec/lib/python3.7/site-packages/botocore/data/_retry.json
2019-03-25 18:11:08 Registering retry handlers for service: lambda
2019-03-25 18:11:08 Trying paths: ['/Users/user/.docker/config.json', '/Users/user/.dockercfg']
2019-03-25 18:11:08 Found file at path: /Users/user/.docker/config.json
2019-03-25 18:11:08 Found 'auths' section
2019-03-25 18:11:08 Auth data for https://index.docker.io/v1/ is absent. Client might be using a credentials store instead.
2019-03-25 18:11:08 Found one Lambda function with name 'tfdefaultroutefile'
2019-03-25 18:11:08 Invoking index.handler (nodejs8.10)
2019-03-25 18:11:08 No environment variables found for function 'tfdefaultroutefile'
2019-03-25 18:11:08 Environment variables overrides data is standard format
2019-03-25 18:11:08 Loading AWS credentials from session with profile 'default'
2019-03-25 18:11:08 Resolving code path. Cwd=/Users/user/projects/connect5-lambda-mediainfo/lambdas/mediainfo, CodeUri=.
2019-03-25 18:11:08 Resolved absolute path to code is /Users/user/projects/connect5-lambda-mediainfo/lambdas/mediainfo
2019-03-25 18:11:08 Code /Users/user/projects/connect5-lambda-mediainfo/lambdas/mediainfo is not a zip/jar file
2019-03-25 18:11:08 Skipping building an image since no layers were defined
2019-03-25 18:11:08 Trying paths: ['/Users/user/.docker/config.json', '/Users/user/.dockercfg']
2019-03-25 18:11:08 Found file at path: /Users/user/.docker/config.json
2019-03-25 18:11:08 Found 'auths' section
2019-03-25 18:11:08 Auth data for https://index.docker.io/v1/ is absent. Client might be using a credentials store instead.
2019-03-25 18:11:08 http://localhost:None "GET /v1.35/images/lambci/lambda:nodejs8.10/json HTTP/1.1" 200 None
2019-03-25 18:11:08 Looking for auth config
2019-03-25 18:11:08 Looking for auth entry for 'docker.io'
2019-03-25 18:11:08 Found 'https://index.docker.io/v1/'
2019-03-25 18:11:08 No auth config found
2019-03-25 18:11:09 http://localhost:None "POST /v1.35/images/create?tag=nodejs8.10&fromImage=lambci%2Flambda HTTP/1.1" 200 None

Fetching lambci/lambda:nodejs8.10 Docker container image......
2019-03-25 18:11:09 Mounting /Users/user/projects/connect5-lambda-mediainfo/lambdas/mediainfo as /var/task:ro inside runtime container
2019-03-25 18:11:09 http://localhost:None "POST /v1.35/containers/create HTTP/1.1" 201 90
2019-03-25 18:11:09 http://localhost:None "GET /v1.35/containers/774deb4e3a106fb54afd93528ff3c1490d998a5d547923bfe306c21e7685c5d8/json HTTP/1.1" 200 None
2019-03-25 18:11:09 http://localhost:None "GET /v1.35/containers/774deb4e3a106fb54afd93528ff3c1490d998a5d547923bfe306c21e7685c5d8/json HTTP/1.1" 200 None
2019-03-25 18:11:10 http://localhost:None "POST /v1.35/containers/774deb4e3a106fb54afd93528ff3c1490d998a5d547923bfe306c21e7685c5d8/start HTTP/1.1" 204 0
2019-03-25 18:11:10 Starting a timer for 240 seconds for function 'tfdefaultroutefile'
2019-03-25 18:11:10 http://localhost:None "GET /v1.35/containers/774deb4e3a106fb54afd93528ff3c1490d998a5d547923bfe306c21e7685c5d8/json HTTP/1.1" 200 None
2019-03-25 18:11:10 http://localhost:None "POST /containers/774deb4e3a106fb54afd93528ff3c1490d998a5d547923bfe306c21e7685c5d8/attach?stdout=1&stderr=1&logs=1&stream=1&stdin=0 HTTP/1.1" 101 0
START RequestId: a532a815-fc34-1203-07d4-70179e0debb5 Version: $LATEST
2019-03-26T01:11:11.221Z    a532a815-fc34-1203-07d4-70179e0debb5    {"errorMessage":"Test Error","errorType":"Error","stackTrace":["exports.handler (/var/task/index.js:24:9)"]}
END RequestId: a532a815-fc34-1203-07d4-70179e0debb5
REPORT RequestId: a532a815-fc34-1203-07d4-70179e0debb5  Duration: 977.93 ms Billed Duration: 1000 ms    Memory Size: 128 MMax Memory Used: 42 MB    
2019-03-25 18:11:11 http://localhost:None "GET /v1.35/containers/774deb4e3a106fb54afd93528ff3c1490d998a5d547923bfe306c21e7685c5d8/json HTTP/1.1" 200 None
2019-03-25 18:11:11 http://localhost:None "DELETE /v1.35/containers/774deb4e3a106fb54afd93528ff3c1490d998a5d547923bfe306c21e7685c5d8?v=False&link=False&force=True HTTP/1.1" 204 0

{"errorMessage":"Test Error","errorType":"Error","stackTrace":["exports.handler (/var/task/index.js:24:9)"]}
sriram-mv commented 5 years ago

What does your handler look like?

michaelgruber commented 5 years ago

Having this issue with local invoke and Go

Handler:

package main

import (
    "context"
    "errors"
    "github.com/aws/aws-lambda-go/lambda"
)

func HandleRequest(ctx context.Context, ev struct{}) (string, error) {
    return "", errors.New("FAIL")
}

func main() {
    lambda.Start(HandleRequest)
}

Full example:

$ sam --version
SAM CLI, version 0.15.0

$ git clone git@github.com:michaelgruber/aws-sam-cli-non-zero.git && cd aws-sam-cli-non-zero
$ make
$ echo "{}" | sam local invoke AWSSAMCLINonZero
2019-04-23 11:07:35 Reading invoke payload from stdin (you can also pass it from file with --event)
2019-04-23 11:07:35 Found credentials in shared credentials file: ~/.aws/credentials
2019-04-23 11:07:35 Invoking main (go1.x)
2019-04-23 11:07:35 Decompressing /Users/mgruber/Desktop/aws-sam-cli-non-zero/main.zip

Fetching lambci/lambda:go1.x Docker container image......
2019-04-23 11:07:36 Mounting /private/var/folders/6p/r4n9zccj1sl028w4_yym43g00000gn/T/tmp2majhmef as /var/task:ro,delegated inside runtime container
START RequestId: 496f2129-51a7-1e03-e917-edfaff706f09 Version: $LATEST
END RequestId: 496f2129-51a7-1e03-e917-edfaff706f09
REPORT RequestId: 496f2129-51a7-1e03-e917-edfaff706f09  Duration: 2.31 ms       Billed Duration: 100 ms Memory Size: 128 MB     Max Memory Used: 6 MB
{
  "errorMessage": "FAIL",
  "errorType": "errorString"
}

$ echo $?
0
jfuss commented 5 years ago

There is some grey area here. The command didn't actually fail, the invoke of your function did. Currently, we treat this as a successful command (as SAM CLI didn't crash or error out). There are defiantly two views to this so marking this as needs-feedback.

michaelgruber commented 5 years ago

As a sidenote, with the above example, running

$ echo '{}' | sam local invoke AWSSAMCLINonZero 2>err.log 1>out.log

Produces an empty out.log and the following err.log

2019-04-23 12:05:12 Reading invoke payload from stdin (you can also pass it from file with --event)
2019-04-23 12:05:12 Found credentials in shared credentials file: ~/.aws/credentials
2019-04-23 12:05:12 Invoking main (go1.x)
2019-04-23 12:05:12 Decompressing /Users/mgruber/Desktop/aws-sam-cli-non-zero/main.zip

Fetching lambci/lambda:go1.x Docker container image......
2019-04-23 12:05:13 Mounting /private/var/folders/6p/r4n9zccj1sl028w4_yym43g00000gn/T/tmpox_4l9xp as /var/task:ro,delegated inside runtime container
START RequestId: a561bbf3-c715-16a3-881c-128dd5edd3f3 Version: $LATEST
END RequestId: a561bbf3-c715-16a3-881c-128dd5edd3f3
REPORT RequestId: a561bbf3-c715-16a3-881c-128dd5edd3f3 Duration: 3.33 ms   Billed Duration: 100 ms Memory Size: 128 MB Max Memory Used: 6 MB   
{
  "errorMessage": "FAIL",
  "errorType": "errorString"
}

With the handler changed to

package main

import (
    "context"
    "github.com/aws/aws-lambda-go/lambda"
)

func HandleRequest(ctx context.Context, ev struct{}) (string, error) {
    return `{"success":true}`, nil
}

func main() {
    lambda.Start(HandleRequest)
}

out.log:

"{\"success\":true}"

err.log:

2019-04-23 12:08:23 Reading invoke payload from stdin (you can also pass it from file with --event)
2019-04-23 12:08:23 Found credentials in shared credentials file: ~/.aws/credentials
2019-04-23 12:08:23 Invoking main (go1.x)
2019-04-23 12:08:23 Decompressing /Users/mgruber/Desktop/aws-sam-cli-non-zero/main.zip

Fetching lambci/lambda:go1.x Docker container image......
2019-04-23 12:08:24 Mounting /private/var/folders/6p/r4n9zccj1sl028w4_yym43g00000gn/T/tmp6y6nv_b9 as /var/task:ro,delegated inside runtime container
START RequestId: b6ffb7fd-99b2-10b1-ad6d-d712e76b739e Version: $LATEST
END RequestId: b6ffb7fd-99b2-10b1-ad6d-d712e76b739e
REPORT RequestId: b6ffb7fd-99b2-10b1-ad6d-d712e76b739e Duration: 2.53 ms   Billed Duration: 100 ms Memory Size: 128 MB Max Memory Used: 6 MB   

If both are considered successful shouldn't the error JSON get sent to stdout?

jamesBrennan commented 5 years ago

I'm having trouble with this same behavior in a different context. I have a python lambda that raises an error. When I deploy the lambda to AWS and use the boto3 client to invoke the deployed function I receive details about the error in the response Payload. However, when I use the boto3 client to invoke the same function locally the Payload property is empty.

# BoomFunction
def lambda_handler(event, context):
    raise Exception('BOOM!')

Remote Behavior

remote = boto3.client('lambda')
remote_res = remote.invoke(
            FunctionName='BoomFunction',
            InvocationType='RequestResponse',
            Payload='{}'
    )

remote_payload = str(remote_res['Payload'].read(), 'utf-8')
print(remote_payload)
# {"errorMessage": "BOOM!", "errorType": "Exception", "stackTrace": ["  File \"/var/task/app.py\", line 37, in lambda_handler\n    raise Exception('BOOM!')\n"]}

Local Behavior

local = boto3.client('lambda', **{
        'endpoint_url': 'http://127.0.0.1:3001'
    })
local_res = local.invoke(
            FunctionName='BoomFunction',
            InvocationType='RequestResponse',
            Payload='{}'
    )

local_payload = str(local_res['Payload'].read(), 'utf-8')
print(local_payload)
# 

I do see the error message in the sam local logs.

2019-04-25 17:12:37 127.0.0.1 - - [25/Apr/2019 17:12:37] "POST /2015-03-31/functions/BoomFunction/invocations HTTP/1.1" 200 -
2019-04-25 17:15:43 Invoking app.lambda_handler (python3.7)

Fetching lambci/lambda:python3.7 Docker container image......
2019-04-25 17:15:45 Mounting /<redacted>/.aws-sam/build/BoomFunction as /var/task:ro inside runtime container
START RequestId: 52fdfc07-2182-154f-163f-5f0f9a621d72 Version: $LATEST
    raise Exception('BOOM!')ine 37, in lambda_handler
END RequestId: 52fdfc07-2182-154f-163f-5f0f9a621d72
REPORT RequestId: 52fdfc07-2182-154f-163f-5f0f9a621d72  Duration: 8.08 ms   Billed Duration: 100 ms Memory Size: 128 MB Max Memory Used: 23 MB
{
  "errorType": "Exception",
  "errorMessage": "BOOM!",
  "stackTrace": [
    "  File \"/var/task/app.py\", line 37, in lambda_handler\n    raise Exception('BOOM!')\n"
  ]
}
cfoehrdes commented 3 years ago

This is also causing an issue for us when using sam local invoke in combination with other tooling. It would be very helpful to get a Non-Zero exit code from sam local invoke in case the invoked function crashes with Non-Zero code.

jrr commented 3 years ago

I was hoping to use sam local invoke in CI with known input for a basic sanity check. I was disappointed that I can't seem to get sam to give me a failing return code.

So for now I've stitched together a fragile hack:

! sam local invoke --event events/event.json 2>&1 |grep -i error

It's not great, but with sam 1.18 and my current nodejs-based lambda this can catch unexpected failures.

Could we get something like sam local invoke --fail-on-error?