A Serilog Logging Helper for Azure Functions

A quick look at a Serilog helper-class add Azure Function name and instance id to log entry properties.

Within the past week, I’ve written about dependency injection for Azure Functions and also dependency injection for Serilog logging. In this post I’m attempting to bring those together.

In fact, if you take the Serilog DI example and add the registration call to your Functions app, you can just [Inject] a Serilog ILogger into your Function and start logging. But much like the very transparent addition of IP logging properties for website use-cases shown in the Serilog article, I wanted to “enrich” (as Serilog calls it) Functions log entries with the name and instance id of the Function.

The static Prison

It’s unfortunate that Azure Functions are imprisoned inside static classes. Had Functions been designed around instanced classes, normal DI would just work, and I’d have to think of other topics to write about. As we saw in the earlier article, acheiving flexible, configurable DI in the world of Functions requires jumping through a lot of very annoying hoops, and these gyrations are directly attributable to the static class requirement.

The irony is that the underlying WebJobs system has supported DI for years. In fact, when you start adding parameters to your Function app signature, those are being injected by the WebJobs system. You’re just stuck using whatever Microsoft made available. (I still suspect it would be possible to leverage the WebJobs DI, but I realized you’d have to register everything through WebJobs, which is lacking some features such as scoped lifetimes. It also would have broken some DI-impelementation dependencies in more complicated parts of my utility libraries. WebJobs DI in its current state probably isn’t a good choice for general-purpose DI.)

My original idea was to register a WebJobs filter (you can see an example of this for scoped-lifetime service cleanup in the Functions DI article). After all, when a Function is about to start, the context sent to OnExecutingAsync supplies the function name and id. Unfortunately, I can’t find a way to store that information somewhere that it is recoverable from within the Functions static prison so that the ILogger can use it once Function execution begins.

After several hours of this, I concluded a clean, transparently-injected, ready-to-go Functions ILogger wasn’t going to happen. We were able to do this for IP logging because that whole stack is DI-friendly, but as far as I can tell, Functions is going to take marginally more work to use.

Only Halfway There

One of the objects Microsoft decided they’d let us inject at Functions runtime is ExecutionContext, and that also carries the function name and id. Consequently, my Functions logging helper requires the developer to declare a dependency on that, and then to provide that reference to the logging helper. All the helper really does is set up an “enricher”. I’m not too happy with it, but it’s still less work than setting up this kind of functionality without a helper.

The helper is accessed through the ILoggerWithFunctionId interface. It is distributed as a separate project since it carries WebJobs package dependencies that I didn’t want in non-Functions apps. We’ll show the code in the next section, but usage within the Function looks like this.

[FunctionName("FetchParseQueueListener")]
public static async Task Run(
    [ServiceBusTrigger("fetch-and-parse", AccessRights.Listen)]FetchParse message,
    [Inject] ILoggerWithFunctionId logger,
    ExecutionContext context)
{
    var log = logger.Logger(context);
    log.Information("Dear Microsoft, please give us real Functions DI.");
}
// omitted: DI service registration

The XML written to the database will contain FnName and FnId properties for every log entry generated by the Function.

<properties>
    <property key="FnName">FetchParseQueueListener</property>
    <property key="FnId">946378d6-7ee2-4bbc-8681-119bb16270ef</property>
</properties>

The Code

The interface requires that any implementation also implements the Serilog enricher interface.

public interface ILoggerWithFunctionId : ILogEventEnricher
{
    ILogger Logger(ExecutionContext context);
}

The logging helper declares a dependency on a regular Serilog ILogger instance, and the helper function that takes the ExecutionContext stores the context for later reference by the enricher, then adds the enricher to the ILogger and returns it.

private readonly ILogger logger;
public LoggerWithFunctionId(ILogger logger) => this.logger = logger;

private ExecutionContext context;
public ILogger Logger(ExecutionContext context)
{
    this.context = context;
    return logger.ForContext(this as ILogEventEnricher);
}

public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
{
    logEvent.AddPropertyIfAbsent(new LogEventProperty("FnName", new ScalarValue(context.FunctionName)));
    logEvent.AddPropertyIfAbsent(new LogEventProperty("FnId", new ScalarValue(context.InvocationId.ToString())));
}

Conclusion

I’m not especially satisified with this result. By exposing the ExecutionContext dependency and forcing the programmer to wire it up, this violates one of the core reasons to use DI in the first place, but as long as Functions use this weird pseudo-injection rather than normal DI, I suspect this is as good as it gets.