EDIT: Added test method.
EDIT: Added sample code and more detailed explination of the problem.
How do I prevent a Python 3.8 AWS Lambda from logging an unhandled exception?
We have a Python 3.8 AWS Lambda function that is only invoked directly, not via API Gateway or any other AWS service. We have custom logging that formats it correctly for a third party service to consume.
Simplified sample code
custom_logging.py
import json
import logging
from contextlib import contextmanager
from typing import Generator, List
metadata_stack: List[dict] = [{}]
@contextmanager
def add_metadata(metadata: dict) -> Generator[None, None, None]:
metadata_stack.append({ **metadata_stack[-1], **metadata})
yield
metadata_stack.pop()
class CustomFormatter(logging.Formatter):
def formatMessage(self, record: logging.LogRecord) -> str:
record.message = json.dumps(
{
'status': record.levelname,
'message': record.message,
'metadata': metadata_stack[-1],
},
separators=(',',':'),
default=str,
)
return super().formatMessage(record)
def _init_root_logger():
logger = logging.root
logger.setLevel(logging.DEBUG)
if logger.hasHandlers():
handler = logger.handlers[0]
class_name = handler.__class__.__name__
if (class_name == 'LambdaLoggerHandler'):
handler.setFormatter(CustomFormatter())
logger.info('Identified AWS Lambda logger')
else:
logger.info('Unidentified logger handler: ' + class_name)
else:
logger.info('Identified no logger. Assuming logging to console.')
_init_root_logger()
lambda-handler.py
import logging
import custom_logging
class LambdaHandler:
def __init__(self, logger):
self.logger = logger
def handle(self, event, context):
with custom_logging.add_metadata({ 'foo': 'bar' }):
try:
self.logger.info('Lambda initialised.')
self.main()
except:
self.logger.exception('An error occurred.')
raise
def main(self):
raise ValueError('I have no values.')
def handle(event, context):
logger = logging.getLogger('LambdaHandler')
return LambdaHandler(logger).handle(event, context)
Execution
When this lambda has an exception, we want it to fail. For testing, I'm executing this from the CLI with the command:
aws lambda invoke --function-name mylambda response.json &&
cat response.json | jq .
The invocation response (output of first command) is:
{
"StatusCode": 200,
"FunctionError": "Unhandled",
"ExecutedVersion": "$LATEST"
}
And the returned payload (output of second command) is:
{
"errorMessage": "I have no values.",
"errorType": "ValueError",
"requestId": "526834fc-4bf8-4b39-b695-6c0525aecead",
"stackTrace": [
" File \"/var/task/lambda_handler.py\", line 22, in handle\n return LambdaHandler(logger).handle(event, context)\n",
" File \"/var/task/lambda_handler.py\", line 12, in handle\n self.main()\n",
" File \"/var/task/lambda_handler.py\", line 18, in main\n raise ValueError('I have no values.')\n"
]
}
This is great, except when Python crashes, AWS logs this exception using the default AWS logger (which I suspect is stderr), not our custom one. This disrupts integration with our third party log aggregator.
Logs
This produces the following logs.
INIT_START Runtime Version: python:3.9.v23 Runtime Version ARN: arn:aws:lambda:ap-southeast-2::runtime:bf3c2cf12ad277455c3732549ac6b43321b08f1eb445e825bd941721e0415621
{
"status": "INFO",
"message": "Identified AWS Lambda logger",
"metadata": {}
}
START RequestId: 526834fc-4bf8-4b39-b695-6c0525aecead Version: $LATEST
{
"status": "INFO",
"message": "Lambda initialised.",
"metadata": {
"foo": "bar"
}
}
This next one needs some work to include the exception in the JSON, but that's for another question. It's not breaking our integration.
{
"status": "ERROR",
"message": "An error occurred.",
"metadata": {
"foo": "bar"
}
}
Traceback (most recent call last):
File "/var/task/lambda_handler.py", line 12, in handle
self.main()
File "/var/task/lambda_handler.py", line 18, in main
raise ValueError('I have no values.')
ValueError: I have no values.
This one we want gone. It's being generated by AWS's bootstrap.py
.
[ERROR] ValueError: I have no values.
Traceback (most recent call last):
File "/var/task/lambda_handler.py", line 22, in handle
return LambdaHandler(logger).handle(event, context)
File "/var/task/lambda_handler.py", line 12, in handle
self.main()
File "/var/task/lambda_handler.py", line 18, in main
raise ValueError('I have no values.')
END RequestId: 526834fc-4bf8-4b39-b695-6c0525aecead
Attempted Remedy
We can wrap the whole lambda function in a try
/except
and log it explicitly, but this removes the "FunctionError": "Unhandled"
in the client response. Return a payload with "statusCode": 500
has no effect. It just makes that the returned payload.
Response:
{
"StatusCode": 200,
"ExecutedVersion": "$LATEST"
}
Payload:
{
"statusCode": 500
}
This breaks out-of-the-box behaviours with AWS SDK and Step Function state machines.
How can we keep the "FunctionError"
attribute without triggering an automatic error log?