This never ends. Shortly after I finished writing about tracing in Azure Functions, I found Daryl “Always Raising” LaBar explaining how to use ExtendedOrganizationService wrapper to easily capture everything in your plugin:
Wouldn’t it be nice for debugging if your plugins automatically traced every IOrganzationService Request, along with the parameters and the time that it took? With the DLaB ExtenededOrganizationService, now you can… https://t.co/x3t2lZmK6N pic.twitter.com/XsegHMh2vZ
— Daryl LaBar (@ddlabar) July 17, 2018
The primary purpose of the tracing wrapper in Azure Functions is to reuse existing functionality you might already have implemented in a separate assemblies. If the existing code uses Trace then my wrapper works nicely redirecting the output to ILogger supplied by the function. But Daryl’s point is that the existing code, if it comes from plugins / workflows would have used ITracingService provided by the execution context. So we need our logger to understand ITracingService as well. Fear not, let me raise the LaBar by standing on his shoulders. We’ll take an extra parameter and implement the interface:
using Microsoft.Extensions.Logging; using Microsoft.Xrm.Sdk; using System.Diagnostics; namespace YourNamespace { // Log writter for working with Azure Functions public class TraceWriterListener : TraceListener, ITracingService { private ILogger _log; private ITracingService _tracer; public TraceWriterListener(string name, ILogger logger, ITracingService tracer = null) : base(name) { _log = logger; _tracer = tracer; } public TraceWriterListener(ILogger logger, ITracingService tracer = null) : base() { _log = logger; _tracer = tracer; } // 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); _trace?.Trace(message); } public override void WriteLine(string message) { _log?.LogTrace(message); _trace?.Trace(message); } // ITracingService implementation public void Trace(string fmt, params object[] args) { _log?.LogTrace(ftm, args); _trace?.Trace(fmt, args); } } }
Now, you can call your existing AwesomeMethod and pass the wrapper in. That way it will get logged as part of the Functions logging as well as go into the trace output of the Dynamics infrastructure.
public static void Run( [TimerTrigger("0 0 0 1 1 *")]TimerInfo myTimer, ILogger log) { // get your tracing service here var tracingService = ...; var logger = new TraceWriterListener( log, tracingService); Trace.Listeners.Add(logger); Trace.TraceInformation($"Information"); Trace.TraceWarning($"Warning"); Trace.TraceError($"Error"); Trace.WriteLine($"Level comes from ILogger"); YourSuperDuperExistingClass .AwesomeMethod(whatever, logger); }
(Facebook and Twitter cover photo by Caterina Beleffi on Unsplash)