Tuesday, April 20, 2021

Azure @ Enterprise - Tracing to Console in different Azure SDKs for .Net

Introduction

Microsoft constantly improves the SDKs. As a side effect, we have to work with new SDKs. Earlier SDK names start with MicsoftAzure or WindowsAzure, next it was Microsoft.Azure. The recent one starts with Azure. Sometimes it's easy to migrate to the latest SDK, but sometimes it's difficult. There is one full post about the dilemma of choosing the Azure SDKs.

The best practice is to be with the latest and greatest version of SDKs

Every time the SDK changes, the logging mechanism also may change. This post is to discuss differences in SDK logging. For simplicity, we are going to look at the logging mechanism that outputs into the console. The same mechanism can be leveraged to write into any other persistent storage.

Why logging is important?

It really depends on the time developers are getting to release products in quality. But whatever the case today or tomorrow we as developers will end up debugging why our code failed in certain situations. The Azure works by HTTP WebAPIs and these SDKs are mainly wrapping that HTTP requests. If we are running in an unrestricted environment, we may not encounter any issues. But if it is from an enterprise environment that has its own hardening policies and restrictions, we will definitely encounter issues and end up debugging. If we are able to see the requests payloads in the console, it would be easy to debug at least in development time. Or just be use our friend Fiddler.

Azure.*

Let us start with the latest SDK as of today. Not sure if it's V12(Storage Blobs) or V4(KeyVault Secrets) or V7 (ServiceBus). The nuget packages are all starting with Azure. are the latest. It all starts from this GitHub repo where the source code lives. There is a documentation page that explains how the logging can be achieved using these SDKs. The essence of the approach is as follows.
using (AzureEventSourceListener listener = AzureEventSourceListener.CreateConsoleLogger())
{
        // Write code that uses SDK here to get it traced into Console.
}
We create a Logger object in the context and it listens to all the logs and outputs into the console.

Microsoft.Azure.* SDKs

These SDKs internally use 'Microsoft.Rest' packages to issue HTTP requests. Intercepting those requests helps us to write into the console. The code goes below

ServiceClientTracing.IsEnabled = true;

ServiceClientTracing.AddTracingInterceptor(new ConsoleTracer());

// Write code here to get it traced into Console.

The implementation of ConsoleTracer goes below. Not sure the SDK has a built-in console logger class. Implementing the interface is relatively easy.

    class ConsoleTracer : IServiceClientTracingInterceptor
    {
        public const ConsoleColor VerboseColor = ConsoleColor.Cyan;
        void IServiceClientTracingInterceptor.Information(string message)
        {
            Output.WriteLine(VerboseColor, message);
        }
        void IServiceClientTracingInterceptor.TraceError(string invocationId, Exception exception)
        {
            Output.WriteLine(ConsoleColor.Red, "Exception in {0}: {1}", invocationId, exception);
        }
        void IServiceClientTracingInterceptor.Configuration(string source, string name, string value)
        {
            Output.WriteLine(VerboseColor, "Configuration: source={0}, name={1}, value={2}", source, name, value);
        }
        void IServiceClientTracingInterceptor.EnterMethod(string invocationId, object instance, string method, IDictionary<string, object> parameters)
        {
            Output.WriteLine(VerboseColor, "EnterMethod - invocationId: {0},instance: {1},method: {2},parameters: {3}",
                invocationId, instance, method, parameters.AsFormattedString());
        }
        void IServiceClientTracingInterceptor.ExitMethod(string invocationId, object returnValue)
        {
            string returnValueAsString = (returnValue == null ? string.Empty : returnValue.ToString());
            Output.WriteLine(VerboseColor, "Exit with invocation id {0}, the return value is {1}",
                invocationId, returnValueAsString);
        }
        void IServiceClientTracingInterceptor.ReceiveResponse(string invocationId, HttpResponseMessage response)
        {
            Output.WriteLine(VerboseColor, $"ReceiveResponse - status code:{response.StatusCode}");
        }
        void IServiceClientTracingInterceptor.SendRequest(string invocationId, HttpRequestMessage request)
        {
            Output.WriteLine(VerboseColor, $"sendRequest - status code:{request.RequestUri}");
        }
    }
}

Update 2021-10-30

MSAL.Net

MSAL.Net follows another model for logging. Please refer to the official documentation for more details.

One another way is to use the system.diagnostics listeners. If there are better ways to achieve this, please comment. Happy logging... 

No comments: