Serverless Logging Performance, Part 2

When thinking about serverless applications, one thing that comes to mind immediately is efficiency. Running code that gets the job done as swiftly and efficiently as possible means you spend less money, which means good coding practices suddenly directly impact your bottom line. How does logging play into this, though? Every logging action your application takes is within the scope of that same performance evaluation. Logging processes can also be optimized just like for any process your code spins up. In this series of posts, let’s dive into how you can think about logging in a serverless world.

In part 1, we examined the concerns around cold starts and message construction. Now, we’ll talk about how logging objects (structured logs) instead of text can affect the cost of your serverless architecture.

Part 2: Performance, Episode 2

Best practices for logging currently focus on structured log objects rather than text-based messages, mainly because machines, rather than humans, are the primary audience for logs in our world of automation. Serverless logging is no different, and it’s even more important than other systems considering the sheer volume of data a serverless architecture generates over a similar amount of time and the fact that the majority of serverless management tools rely on parsing log data to function. Alerts, monitoring, performance metrics, and even triggers for other actions all need to check logs and work off of them to help you manage your serverless systems.

Structured Logs

First, what are structured logs? Structured logs are data-enriched objects that enable machines to parse out relevant information without relying on regular expressions or other text processing. Think of a structured log as a text-based message (I’ve been calling them strings, but I know that the term can mean a lot of different things based on programming language) with associated metadata attached. The text-based message is for the human poking at the logs. The metadata, though, is really for the machine, and having that metadata ensures a machine will accurately identify a type of log line 100% of the time assuming the incoming data is accurate.

If you were only to use text-based logging, you run the risk of two messages being so similar that a regex-based parsing solution would flag them both as the same type when they are completely different. In addition, the extra processing time needed to parse a text-based message increases the cost associated with a serverless system. We’ve already explored that the time needed to run a serverless call is pretty well correlated with the cost of running that call, so we know that time is money here. However, is a structured log really more performant and therefore more cost-effective in a serverless world? To answer that, let’s revisit the Python example from the previous article.

Construction, Revisited

For structured logging with Python, there’s a lot of small libraries out there on PyPI we could explore. I chose to work with the standard logging library and a library called structlog. I did a similar benchmark test to the one I did last round using a few different configurations of structured logging:

Method	With 1 Variable (microsec)	With 2 Variables (microsec)	With Multiple Variables (microsec
text, fastest string	23.2711	23.6432	25.7583
structured, built-in	31.3718	33.7994	49.9785
structured, structlog	36.3576	40.0466	60.9309
structured, structlog performance run	12.8722	13.1769	20.8687

Time Context	Time Ran
real	3m23.373s
user	2m55.168s
sys	0m12.598s

In this case, the various methods are as follows:

• text, fastest string to provide a sort of control. This method was the %-formatting direct call from last round.
• structured, built-in is using the built-in standard logging library and the method found in the logging cookbook for generating a structured logging setup^1,2.
• structured, structlog is using the structlog library with a default setup.
• structured, structlog performance run is using the structlog library with a performance tune based on the structlog docs.³

I’m adding in the time to run the full script so you can see how long I ran the benchmark; the timing was generated by running time at the terminal. This addition is to ensure I’m running the script over a long enough period of time to account for system differences (e.g., silicon and hardware differences, I/O differences in tuning, OS processes).

You’ll notice that, believe it or not, the performance tune of structlog is significantly faster than even the fastest text-based logging method we had. That in and of itself is remarkable, especially considering the library still calls the standard library in its configuration. The likely scenario for this performance is twofold. First, the structlog library has a method called cache_logger_on_first_use that reduces build time. This choice is very similar to the performance boost you receive when you reduce your cold start times for the overall application. Second, the JSON serializer in the standard library is not all that fast compared to other libraries out there.⁴ The structlog docs encourage using a different JSON serializer. As I’m running this test on 3.7.4, I have access to RapidJSON’s port to Python from C++ and therefore switched the serializer to RapidJSON. Both of these performance boosts should explain the significantly faster run time.

The Meaning of Speed

To go back to why this matters specifically for serverless systems, we need to consider why structured logs are preferred for serverless systems. Automation triggered by events captured by logs need the consistency of structured logging. Most folks assume that generating the string is faster than generating an entire object that includes metadata, though, and therefore prefer generating the string. As is seen here, though, generating the structured logs in a specifically tuned manner can still give you the use you need with the cost savings that you want.

However, throughout the start of this series, we’ve only been considering speed. Another part of the equation that we haven’t considered is networking throughput. When we start talking about the differences in text-based logs and structured logs, we have to consider how serverless providers charge for network traffic. In the next few parts of the series, we’ll examine that angle along with understanding how much memory is required to build logging for your serverless application.

---

1. https://docs.python.org/3.7/howto/logging-cookbook.html#implementing-structured-logging ↩

2. Note that I used a slightly different call than the one in the most current docs as I’m running 3.7.4 for this series. ↩

3. https://www.structlog.org/en/stable/performance.html ↩

4. https://python-rapidjson.readthedocs.io/en/latest/benchmarks.html#serialization ↩