Lambda Logging in .NET Core
Some time ago I was trying to fix a problem with a Lambda function running .NET Core and found an interesting problem — I couldn’t find the exception that my code was clearly throwing and logging using standard Microsoft logging interfaces:
Lambda logger from Amazon.Lambda.Logging.AspNetCore would just log the message:
Critical Error calling serivce. Error: FooBut not the exception :/
In this post, I’ll cover how lambda logging works and how it should be used to get most out of it. Let’s start with Cloud Watch — where log messages are persisted.
CloudWatch
Cloud watch is Amazon's service for basic logging and I mean very basic. It’s basically a text file with dates :)
All AWS services use cloud watch by default, and that’s also where Amazon Lambda Logger saves its entries.
It’s not the easiest way of reading logs, especially when you have multiple requests hitting your lambda, but more about that later.
AWS Lambda dotnet
AWS provides a set of libraries for building lambdas and consuming its services (S3, SQS, ES, etc.) using .NET Core. They can be found on github:
One of those libraries is earlier mentioned Amazon.Lambda.Logging.AspNetCore which plugs in nicely into Microsoft’s logging. Unfortunately, it’s a little behind .NET Core libraries and features you would get using Microsoft loggers.
Below I’ll show how to configure it to get most of Lambda logger and what can be a temporary solution until AWS Lambda .NET Core catches up.
Setting up the entry point
First, let us cover some basics of setting up a .NET Core Lambda.
Each type of Lambda (SQS, S3, etc.) needs an entry point defined using attributes. If you also want to benefit from all the goodness that comes with dependency injection, that means setting up your DI container and using the service locator (anti-)pattern.
I do it by creating a lambda entry point class which gets the program entry point from DI.
The startup class sets up all the dependencies, configuration and logging.
Setting up Logger
Setting up lambda logging is pretty easy thanks to standardized classes and extension methods.
IncludeEventId and IncludeException are two parameters I’ve added in a recent PR to AWS Lambda. If they are set to true, logger will do what you expect — log event Id and the full exception text :)
At the time of writing, PR updating readme file and adding more features is still open.
Why exceptions weren’t logged?
That’s actually a good question to ask. Intuitively — it doesn’t make any sense for a logger to ignore probably the most important parameter passed in. I’m not sure what was Microsoft's decision around it, but I’m guessing they wanted to keep log entries succinct and exceptions tend to be quite large in the amount of produced text by .ToString() call.
The offending line of code can be found here:
https://github.com/aspnet/Extensions/blob/55518d79834d3319c91f40b449d028338b129ed6/src/Logging/Logging.Abstractions/src/LoggerMessage.cs#L406public static readonly Func<LogValues<T0, T1, T2>, Exception, string> Callback = (state, exception) => state.ToString();
The exception is just not used :/
Logging with scopes
When your lambda is handling more than 1 request at a time (which is probably true for most lambdas), than reading cloud watch logs gets difficult. There’s no way to tell which request is doing what or which call made lambda to fail.
Logging interfaces in .NET Core already solved this problem using Scopes.
The solution is pretty cool using BeginScope in a using block:
The result is that every message logged within the using statement will be prefixed with AwsRequestId, making it really easy to filter out log statements relevant to one request.
// Update 6/26/2019
Lambda Logger did not support scopes until late June 2019.
The pull request I’ve submitted to AWS lambda dotnet to add support for scopes was merged in June 2019.
Thanks for reading!
