Tip #1142: Tracing in Azure Functions MkII

When describing tracing  in Azure Functions previously, I dropped almost in passing that to capture .NET traces in Azure Functions is easy – just create your own TraceListener. I also added that

the code takes a shortcut with log.Info and requires a bit of tuning like mapping logging levels from Connector to TraceWriter but those are the details we can live without

On one of the existing projects, that extensively uses Trace, I had an opportunity to eat my own words. Turns out, we cannot live without those pesky details because logging level will be totally useless in that implementation.

Getting levels under control turned out to be a small challenge because, technically speaking, listener is just that and shouldn’t concern itself with the logging level – you do what you’re told, basically. After some table bending up-and-down head movements, I managed to come up with TraceWriterListener class that takes Azure Functions log interface as a parameter and correctly intercepts all levels of tracing, emitting the appropriate statements. Here is the class in all its glory:

using Microsoft.Extensions.Logging;
using System.Diagnostics;

namespace YourNamespace
{
  // Log writter for working with Azure Functions 
  public class TraceWriterListener : TraceListener
  {
    private ILogger _log;

    public TraceWriterListener(string name, 
          ILogger logger) : base(name)
    {
      _log = logger;
    }

    public TraceWriterListener(ILogger logger) : base()
    {
      _log = logger;
    }

    // this is the one we have to overwrite to get 
    // the logging level right
    public override void TraceEvent(
          TraceEventCache eventCache, 
          string source, TraceEventType eventType, 
          int id, string message)
    {
      switch(eventType)
      {
        case TraceEventType.Verbose: 
          _log?.LogDebug(message); 
          break;
        case TraceEventType.Information: 
          _log?.LogInformation(message);
          break;
        case TraceEventType.Warning: 
          _log?.LogWarning(message); 
          break;
        case TraceEventType.Error: 
          _log?.LogError(message); 
          break;
        case TraceEventType.Critical: 
          _log?.LogCritical(message); 
          break;
        default:break;
      }
    }

    public override void Write(string message)
    {
      _log?.LogTrace(message);
    }

    public override void WriteLine(string message)
    {
      _log?.LogTrace(message);
    }
  }
}

If you add this class to your function project (or drop as csx into your function environment if you are not using projects), then the function code can use something like:

public static void Run(
  [TimerTrigger("0 0 0 1 1 *")]TimerInfo myTimer, 
  ILogger log)
{
   var logger = new TraceWriterListener(log);
   Trace.Listeners.Add(logger);
   Trace.TraceInformation($"Information");
   Trace.TraceWarning($"Warning");
   Trace.TraceError($"Error");
   Trace.WriteLine($"Level comes from ILogger");
}

which makes migration of the existing code fairly easy.

Bonus

You probably noticed the use of ILogger interface where previously TraceWriter was sitting. As of recently quite some time ago, functions now have support for logging through the Microsoft.Extensions.Logging.ILogger interface. As per documentation: at a high level, this is not much different than logging via the TraceWriter: logs continue to go to the file system and will also go to Application Insights (currently in Preview) if the APPINSIGHTS_INSTRUMENTATIONKEY app setting is set. The main advantage of using ILogger is that you get support for structured logging via Application Insights, which allows for richer Analytics support. To use ILogger as your logging interface, simply add a parameter to your function signature and use any of the logger extensions.

Leave a Reply

Your email address will not be published.