A Better Structlog Processor for Python for CloudWatch Logs Using AWS Lambda

A Better Structlog Processor for Python for CloudWatch Logs Using AWS Lambda

I was introduced to structured logs at work, and this ol’ hacker thinks that is a darn good idea.
For a new program I’m writing, I wanted to put that into use.
The program uses AWS Lambdas, and the log entries for the Lambdas end up in CloudWatch Logs.
Unfortunately, in its default configuration, the output is less than useful:
Default configuration structured logs
AWS has configured the default Python logger in the Lambdas to automatically put the timestamp and the HTTP API request ID from the context in the display when the log line is collapsed.
When you expand the log line, you can see the additional detail in structured JSON.
That timestamp is duplicated in the column to the left, and the UUID is really not useful in this context.
What I’d rather see is the
event
that caused the line to be logged and any corresponding
error message
.
Enhanced configuration structured logs
It took some trial and error to make this happen.
This post describes that process in case I or anyone else needs this in the future.
The Usefulness of Structured Logs
I believe the widespread use of format strings in logging is based on two presumptions:
The first level consumer of a log message is a human.
The programmer knows what information is needed to debug an issue.
I believe these presumptions are
no longer correct
in server side software.
—
Paul Querna
This quote is from a 2011 blog post.
It’s only now that I’m getting involved with troubleshooting distributed systems running on AWS that I appreciate the value of Paul’s insight.
The ability to
search
the contents of log files combined with the ability to correlate log messages from disparate programs is a real game-changer.
(This coming from a programmer who still feels most comfortable trolling through
/var/log
with liberal
grep
and
awk
commands.)
I’ve seen the light.
And so with this new effort, I’m using the Python
Structlog package
to simplify the building of the stuctured logs.
The problem is that AWS is too smart for its own good.
When you use the AWS-supplied Python installation, it:
Sets the log level to WARN, and
Sets the format string to include the timestamp and UUID of the Lambda call in front of anything you want to log.
Both of those are really annoying.
The way to get around the first is somewhat cumbersome, as
this answer on Stack Overflow describes
.
The nicest solution—if you are using Python 3.8 or higher—is to use the
force=true
on the
logging.basicConfig
call:
1
2
3
4
5
6
logging
.
basicConfig
(
format
=
»
%(message)s
»
,
stream
=
sys
.
stdout
,
level
=
logging
.
DEBUG
,
force
=
True
,
)
The second line of this code snippet is the start of the solution to address the second problem described above—it clears out the AWS-supplied formatting string.
In its place, we will put our own formatted string.
Tricking CloudWatch to Display Useful Content
I couldn’t find this documented anywhere, but th…