In the last post, we touched on the topic of the application logging. We talked about the need for separation of the configuration information into two distinct categories: application and systemic. To emphasize this, we used one of the archetypical tasks in software engineering, the diagnostic information extraction in a debugging environment.

In this post we will explore in depth the best practices of application logging and extend it in the broader IoT space.

Sources and Sinks

Historically, the various logging libraries have been inspired by the hosting operating system underlying implementation. The reason for this is somewhat obvious if seen from the perspective of the hardware (device): the operating system itself is just a collection of applications, some of them running on the kernel space like drivers, and some in the user space, like any user application. In mission-critical applications, the related logging information might span a cross-section of OS components, drivers and other applications, so having a consolidated logging mechanism makes more sense.

And although minor differences existed between the different operating systems' logging infrastructure, all of them shared the same publisher/subscriber pattern: the log stream is published by sources, and sinks can subscribe to these sources.  On Windows, the inherent logging infrastructure is called ETW and on Linux LTTng, both of them the de facto best approach for platform-specific tracing.

Nowadays, in the era of cloud computing, anything that is platform-specific sounds like a bad idea, and rightfully so, people try to avoid it. Logging in the  .NET ecosystem has traditionally been confusing, with many alternatives and no clear winner so far. But at last, we have a clear winner! Today, Serilog is the second most popular nuget package right after Newtonsoft's JSON library. This practically means that the most important logging features are supported, and even if there is any missing feature or limitation in this library compared to other options, it's most probably a matter of time for the Serilog open source community to catch-up. As of now, most of the important tracing sinks exist, like for example flat files, databases, cloud managed tracing services etc.

Now let's see how this looks in source code. Let's modify the default .NET Core console app to use Serilog. To create a new Console app in .NET Core run:

mkdir Logging
dotnet new console

dotnet add package Microsoft.Extensions.Hosting

dotnet add package Serilog.Sinks.Console
dotnet add package Serilog.Settings.Configuration
dotnet add package Serilog.Enrichers.Thread

Replace the default Program.cs code with this:

using Microsoft.Extensions.Configuration;
using Serilog;
using Serilog.Context;

namespace Logging
{
    class Program
    {
        static void Main(string[] args)
        {
            IConfiguration configuration = new ConfigurationBuilder()
                .AddJsonFile("appsettings.json")
                .Build();

            Log.Logger = new LoggerConfiguration()
                .ReadFrom.Configuration(configuration)
                .CreateLogger();

            LogContext.PushProperty("ClassId", typeof(Program).Name);
            LogContext.PushProperty("FunctionId", nameof(Main));

            Log.Information("Hello World!");
            Log.Error("Something is wrong..");
            Log.Information("Goodbye!");
        }
    }
}

and add this appsettings.json file and set it to "copy if newer"

{
  "Serilog": {
    "Using": [ "Serilog.Sinks.Console" ],
    "MinimumLevel": {
      "Default": "Debug"
    },
    "WriteTo": [
      {
        "Name": "Console",
        "Args": {
          "outputTemplate": "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u3}] [{ModuleId}] [{ThreadId}] - {Message}{NewLine}{Exception}"
        }
      }
    ],
    "Enrich": [ "FromLogContext", "WithThreadId" ]
  }
}
Note: In VSCode you can copy to output the appsettings.json by adding this snippet in the .csproj file: 
  <ItemGroup>
    <None Update="appsettings.json">
      <CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
    </None>
  </ItemGroup>

Running this application, we see the following output:

A few important notes about the above example:

  1. We put the Serilog settings in the appsettings.json file. A better approach would be to to have a dedicated file, just for the purpose of logging.
  2. More elaborate log event enrichment alternatives exist, removing or adding more information to each log event is a matter of preference (and performance).
  3. We set the static Log.Logger property with the new logger. This way we can access the logger by simply doing Log.Information. This simple approach works well only if we have need a single logger instance in our entire application.

The canonical example

For a better control over the logger creation, a good logger example exists in the IoT Edge runtime source code. This example demonstrates a good way to remove the the Serilog specific implementation dependency from the rest of the source code by implementing the and the ILoggerFactory interface of the Microsoft.Extensions.Logging namespace and hiding the Serilog specific references behind this implementation.

A usage example of the above approach, using a slightly modified version of the aforementioned logger of the IoT Edge Runtime looks like:

using Microsoft.Extensions.Logging;

namespace Logging
{
    class Program1
    {
        static readonly ILogger Log = 
            Logger.Factory.CreateLogger(typeof(Program).Name);

        static void Main(string[] args)
        {
            Log.LogInformation("Hello World!");
            Log.LogError("Something is wrong..");
            Log.LogInformation("Goodbye!");
        }
    }
}
Note that there is no reference to the Serilog namespace anymore. The benefit of this is that we've made our code technology-agnostic, that is, we can replace the logging library by simply changing our Logger class implementation.

Running the above code produces a similar output

Besides the output logs style, the major difference between these two examples is that now we can pass this logger to third party libraries that use the same logging abstraction. This is a subtle difference, but it can prove to be very helpful in various scenarios, integrating with ASP.NET Core.

Note: we will see how this becomes important in the next post where we introduce dependency injection

Docker and Azure IoT Edge

So far, the focus has been intentionally limited in generating application logs and sending them to a console sink. Obviously, many other sink options exist, some of them pushing the logs in remote cloud sinks like Azure Event Hubs or Blob Storage. The console sink approach works well both in development environments and when deploying as a container, because Docker can be configured to save these logs in host flat files and then combine these logs on a system level with other OS logs.

The related IoT manifest section is:

"createOptions": {
    "HostConfig": {
        "LogConfig": {
            "Type": "json-file",
            "Config": {
                "max-size": "10m",
                "max-file": "3"
            }
        }
    }
}
Note: by default the Moby container engine does not set container log size limits!

Finally, a couple of notable Azure IoT Edge log features are the log collation and upload capability and the Azure Log Analytics integration module.

To summarize the logging story, the rules of thumb are:

  1. Use Serilog library for logging. If you configure Serilog via configuration, use a dedicated file. Write to at least a console sink.
  2. Reference and use the Serilog.Log if your code is relatively simple and does not integrate with other external libraries.
  3. Implement an ILoggerFactory and use dependency injection if you have integration with external libraries, like ASP.NET Core.
  4. Set a limit to the docker logs.
  5. Never push logs in the same application payload transport channel, use a dedicated transport channel if you push your logs to the upstream.
  6. If your Edge application is part of a broader distributed solution, use the Application Insights sink and correlation IDs.
  7. For ad hoc log retrieval use the log collation and upload capability.
  8. For continuous push edge log, use the Azure Log Analytics integration module.
  9. Configure the OS with a host management solution to retrieve the system logs.

In the next post, we will explore a dependency injection approach that combines all concepts we've seen so far in this mini-series .