API Gateway + Lambda: where's my print output?

Question

I'm learning API Gateway. I set up a Lambda function to be the implementation of one of the routes. I put some print statements in the Lambda function, looking to see the exact form of the event object that comes in. If I press the Test button within the Lambda screen, it shows a concise log that includes the output of my print statements. But if I press the Test button within the API screen, having properly set up test parameters, I get a detailed log that does not seem to include the output of my print statements. And for those calls, if I look under the appropriate log group in Cloudwatch, I don't see the output of my print statements in that log either.

Is there any way to get that output? Do I need to be using a logger interface instead? The only way I know I'm even calling the same function is that I got the same syntax errors when I had them. My test code is this simple:

def lambda_handler(event, context):
    print("hello")
    print("hello")
    print(event)
    print("hello")
    print("hello")
    return event

The log from Lambda:

**Function Logs**
START RequestId: 5a981182-0c07-47ab-9870-a126077a47fb Version: $LATEST
hello
hello
{'key1': 'value1', 'key2': 'value2', 'key3': 'value3'}
hello
hello
END RequestId: 5a981182-0c07-47ab-9870-a126077a47fb
REPORT RequestId: 5a981182-0c07-47ab-9870-a126077a47fb  Duration: 1.59 ms   Billed Duration: 2 ms   Memory Size: 128 MB Max Memory Used: 72 MB  Init Duration: 359.06 ms

The log from the API test screen:

Execution log for request 9e9fc8df-5865-4511-b98c-170dc200cdbf
Tue Oct 17 21:24:07 UTC 2023 : Starting execution for request: 9e9fc8df-5865-4511-b98c-170dc200cdbf
Tue Oct 17 21:24:07 UTC 2023 : HTTP Method: POST, Resource Path: /blast-jobs
Tue Oct 17 21:24:07 UTC 2023 : Method request path: {}
Tue Oct 17 21:24:07 UTC 2023 : Method request query string: {id=12543}
Tue Oct 17 21:24:07 UTC 2023 : Method request headers: {}
Tue Oct 17 21:24:07 UTC 2023 : Method request body before transformations: 
Tue Oct 17 21:24:07 UTC 2023 : Endpoint request URI: https://lambda.us-west-2.amazonaws.com/2015-03-31/functions/arn:aws:lambda:us-west-2:680678151940:function:blast-job-create/invocations
Tue Oct 17 21:24:07 UTC 2023 : Endpoint request headers: {x-amzn-lambda-integration-tag=9e9fc8df-5865-4511-b98c-170dc200cdbf, Authorization=***********************************************************************************************************************************************************************************************************************************************************************************************************5b1b40, X-Amz-Date=20231017T212407Z, x-amzn-apigateway-api-id=z7p03y8fsl, X-Amz-Source-Arn=arn:aws:execute-api:us-west-2:680678151940:z7p03y8fsl/test-invoke-stage/POST/blast-jobs, Accept=application/json, User-Agent=AmazonAPIGateway_z7p03y8fsl, X-Amz-Security-Token=IQoJb3JpZ2luX2VjEHwaCXVzLXdlc3QtMiJGMEQCIFAlRNi2qWdb/t4Ns7aPhBEL4xS8S+RNosv3YDwwPZ62AiBtBEDMynu2sHifcWuRMp1ENJkn0Lw6A4NpHc+kiCPjiCq5BQiV//////////8BEAUaDDEwOTM1MTMwOTQwNyIM0aToxb8NiSJg8PjnKo0FV/S77p/giiwY1oGpDmFGbblLZN1SiE5M4XQr7DmilAwgielGxojWaFxi84R7A3W+0wcuB4kDcLomVgp2I+K4T3BdTqytzi+fr41UvYkVdfrzEjymAWrR+JtzgFjSaD+3W7cX3Mfl+0W/uj0YVQ9P+TUTOsu5Wk [TRUNCATED]
Tue Oct 17 21:24:07 UTC 2023 : Endpoint request body after transformations: 
Tue Oct 17 21:24:07 UTC 2023 : Sending request to https://lambda.us-west-2.amazonaws.com/2015-03-31/functions/arn:aws:lambda:us-west-2:680678151940:function:blast-job-create/invocations
Tue Oct 17 21:24:08 UTC 2023 : Received response. Status: 200, Integration latency: 513 ms
Tue Oct 17 21:24:08 UTC 2023 : Endpoint response headers: {Date=Tue, 17 Oct 2023 21:24:08 GMT, Content-Type=application/json, Content-Length=2, Connection=keep-alive, x-amzn-RequestId=f7561b7d-f61e-4b8d-b55b-9cf1b77f819a, x-amzn-Remapped-Content-Length=0, X-Amz-Executed-Version=$LATEST, X-Amzn-Trace-Id=root=1-652efb77-e9cf5f6c51fdabede9c58813;sampled=0;lineage=1dc83a0a:0}
Tue Oct 17 21:24:08 UTC 2023 : Endpoint response body before transformations: {}
Tue Oct 17 21:24:08 UTC 2023 : Method response body after transformations: {}
Tue Oct 17 21:24:08 UTC 2023 : Method response headers: {X-Amzn-Trace-Id=Root=1-652efb77-e9cf5f6c51fdabede9c58813;Sampled=0;lineage=1dc83a0a:0, Content-Type=application/json}
Tue Oct 17 21:24:08 UTC 2023 : Successfully completed execution
Tue Oct 17 21:24:08 UTC 2023 : Method completed with status: 200

Answer 1

I'm not sure what was going wrong, but this answer to another question is giving me what I really needed. An easy way to view the right, latest log. Here's my version of that script:

LOG_GROUP=/aws/lambda/$1
LOG_STREAM=`aws logs describe-log-streams --log-group-name $LOG_GROUP --max-items 1 --order-by LastEventTime --descending --query logStreams[].logStreamName --output text | head -n 1`

aws logs get-log-events --log-group-name $LOG_GROUP --log-stream-name $LOG_STREAM --query events[].message --output text

Answer 2

You API Gateway integration (the thing that is receiving the requests and returning the responses) is a black box for the API Gateway. It has no way of seeing anything that is happening there except what's coming out through the HTTP stream.

Lambda, on the other side, listens to the runtime container stdout and transforms it into CloudWatch events, one per line. Unless you have explicitly denied CloudWatch permissions to the role your lambda is running as, all your print statements should be in CloudWatch.

And for those calls, if I look under the appropriate log group in Cloudwatch, I don't see the output of my print statements in that log either.

Is the "appropriate log group" the Lambda function log group or the API Gateway log group? Your print statements should be in the former but not the latter. If they are not there, you should check your Lambda function's permissions.