spring-cloud-function-adapter-aws fails on local development with SAM Local

[drissamri]

When using aws-sam-local , official framework for developing/testing locally for AWS Lambda, the requests fails with the following error:

PROBLEM:

➜  spring-cloud-functions git:(master) ✗ sam local start-api
2018-06-24 16:24:18 Mounting ReportLambda at http://127.0.0.1:3000/report [POST]
2018-06-24 16:24:18 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
2018-06-24 16:24:18  * Running on http://127.0.0.1:3000/ (Press CTRL+C to quit)
2018-06-24 16:24:31 Invoking be.drissamri.serverless.ServerlessApplication (java8)
2018-06-24 16:24:31 Found credentials in shared credentials file: ~/.aws/credentials
2018-06-24 16:24:31 Decompressing /Users/drissamri/workspace/drissamri/aws-serverless-starter/spring-cloud-functions/target/spring-example-1.0.0-aws.jar

Fetching lambci/lambda:java8 Docker container image......
2018-06-24 16:24:37 Mounting /private/var/folders/pd/drhx_tzd4xn9_766g7223f080000gn/T/tmpAlydJ7 as /var/task:ro inside runtime container
START RequestId: 7139c8de-6d1c-4058-bedb-b443d818a0c0 Version: $LATEST
END RequestId: 7139c8de-6d1c-4058-bedb-b443d818a0c0
REPORT RequestId: 7139c8de-6d1c-4058-bedb-b443d818a0c0	Duration: 8168.78 ms	Billed Duration: 8200 ms	Memory Size: 1024 MB	Max Memory Used: 17 MB
14:24:39.723 [main] INFO org.springframework.cloud.function.adapter.aws.SpringFunctionInitializer - Searching manifests: [jar:file:/var/runtime/lib/LambdaJavaRTEntry-1.0.jar!/META-INF/MANIFEST.MF, jar:file:/var/runtime/lib/aws-lambda-java-core-1.2.0.jar!/META-INF/MANIFEST.MF, file:/var/task/META-INF/MANIFEST.MF]
14:24:39.747 [main] INFO org.springframework.cloud.function.adapter.aws.SpringFunctionInitializer - Searching manifest: jar:file:/var/runtime/lib/LambdaJavaRTEntry-1.0.jar!/META-INF/MANIFEST.MF
14:24:39.749 [main] INFO org.springframework.cloud.function.adapter.aws.SpringFunctionInitializer - Searching manifest: jar:file:/var/runtime/lib/aws-lambda-java-core-1.2.0.jar!/META-INF/MANIFEST.MF
14:24:39.750 [main] INFO org.springframework.cloud.function.adapter.aws.SpringFunctionInitializer - Searching manifest: file:/var/task/META-INF/MANIFEST.MF
14:24:39.768 [main] INFO org.springframework.cloud.function.adapter.aws.SpringFunctionInitializer - Main class: class be.drissamri.serverless.ServerlessApplication
14:24:40.430 [main] INFO org.springframework.cloud.function.adapter.aws.SpringFunctionInitializer - Initializing: class be.drissamri.serverless.ServerlessApplication

... more logs ...

{"statusCode":200,"body":"{\"result\":\"PROCESSED: Report me\"}"}
2018-06-24 14:24:48.575  INFO 1 --- [       Thread-2] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@130f889: startup date [Sun Jun 24 14:24:43 UTC 2018]; root of context hierarchy2018-06-24 16:24:50 Function returned an invalid response (must include one of: body, headers or statusCode in the response object). Response received: 2018-06-24 14:24:48.579  INFO 1 --- [       Thread-2] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown
2018-06-24 16:24:50 127.0.0.1 - - [24/Jun/2018 16:24:50] "POST /report HTTP/1.1" 502 -

After looking around, the same issue was encountered here: aws/serverless-java-container#134 and looks like it has to do with Spring Boot printing a shutdown messages after the output is already printed.

SOLUTION (workaround):
Add a application.properties and minimize logging with logging.level.root=WARN

sam local start-api
2018-06-24 16:29:21 Mounting ReportLambda at http://127.0.0.1:3000/report [POST]
2018-06-24 16:29:21 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
2018-06-24 16:29:21  * Running on http://127.0.0.1:3000/ (Press CTRL+C to quit)
2018-06-24 16:29:32 Invoking be.drissamri.serverless.ServerlessApplication (java8)
2018-06-24 16:29:32 Found credentials in shared credentials file: ~/.aws/credentials
2018-06-24 16:29:32 Decompressing /Users/drissamri/workspace/drissamri/aws-serverless-starter/spring-cloud-functions/target/spring-example-1.0.0-aws.jar

Fetching lambci/lambda:java8 Docker container image......
2018-06-24 16:29:38 Mounting /private/var/folders/pd/drhx_tzd4xn9_766g7223f080000gn/T/tmpZHZpPi as /var/task:ro inside runtime container
START RequestId: bdbb922c-5ff8-4d4c-bc59-c38695f4fdcf Version: $LATEST
END RequestId: bdbb922c-5ff8-4d4c-bc59-c38695f4fdcf
REPORT RequestId: bdbb922c-5ff8-4d4c-bc59-c38695f4fdcf	Duration: 7596.60 ms	Billed Duration: 7600 ms	Memory Size: 1024 MB	Max Memory Used: 17 MB
14:29:39.602 [main] INFO org.springframework.cloud.function.adapter.aws.SpringFunctionInitializer - Searching manifests: [jar:file:/var/runtime/lib/LambdaJavaRTEntry-1.0.jar!/META-INF/MANIFEST.MF, jar:file:/var/runtime/lib/aws-lambda-java-core-1.2.0.jar!/META-INF/MANIFEST.MF, file:/var/task/META-INF/MANIFEST.MF]
14:29:39.627 [main] INFO org.springframework.cloud.function.adapter.aws.SpringFunctionInitializer - Searching manifest: jar:file:/var/runtime/lib/LambdaJavaRTEntry-1.0.jar!/META-INF/MANIFEST.MF
14:29:39.628 [main] INFO org.springframework.cloud.function.adapter.aws.SpringFunctionInitializer - Searching manifest: jar:file:/var/runtime/lib/aws-lambda-java-core-1.2.0.jar!/META-INF/MANIFEST.MF
14:29:39.629 [main] INFO org.springframework.cloud.function.adapter.aws.SpringFunctionInitializer - Searching manifest: file:/var/task/META-INF/MANIFEST.MF
14:29:39.644 [main] INFO org.springframework.cloud.function.adapter.aws.SpringFunctionInitializer - Main class: class be.drissamri.serverless.ServerlessApplication
14:29:40.067 [main] INFO org.springframework.cloud.function.adapter.aws.SpringFunctionInitializer - Initializing: class be.drissamri.serverless.ServerlessApplication

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::

2018-06-24 16:29:49 No Content-Type given. Defaulting to 'application/json'.
2018-06-24 16:29:49 127.0.0.1 - - [24/Jun/2018 16:29:49] "POST /report HTTP/1.1" 200 -

I'm not sure if this can be fixed in the framework, but otherwise this might need to be documented?

[olegz]

Many improvements went into AWS recently and documentation has been updated. Given the age if this issue I am going to close it with no action, but feel free to raise new issue as you discover them.