Structured Logging In Microsoft's Azure Application Insights

One of the spots in OWASP's Top 10 list of web Application Security Risks is taken up by "Insufficient logging and monitoring." Deriving from the list and my personal experience, logging is indispensable for software systems of all shapes and sizes where reliability is even the slightest of concern. Sure, it comes at a cost, just like everything—time, maintenance, storage, analysis, reporting, and monetary inputs go into it. Still, the investment is worth it for both the developers and the business.

Thankfully, the number of logging and monitoring tools and advancements have grown substantially. This article will shed some light on the structured logging approach and tips proven beneficial in several projects and how it gels with Microsoft's Azure Application Insights/Azure Monitor.

Before Proceeding

We need to get some critical questions out of the way before commencing our logging endeavor.

Question One: What are the regulatory and compliance requirements to adhere to?

This becomes especially critical with automatic logging frameworks/SDKs like Application Insights. Azure Application Insights logs all the dependencies of an application automatically, including database queries and HTTP calls. Therefore, due diligence is warranted to make sure sensitive information is not logged.

For example, one of the legacy systems we worked with accepted, unfortunately, the password as part of the URL. One of the many ways of filtering in Azure Application Insights is implementing the interface ITelemetryProcessor and providing filters. Or it can simply be config setting based on LogLevel and the namespace like follows.

"Logging": {
       "LogLevel": {
       "Default": "Information",
       //Only the WARNING messages for HttpClient will be logged
       "System.Net.Http.HttpClient": "Warning" 
    }

Question Two: What should be the log retention policy?

By default, the life span of logs in Azure Application Insights is 90 days, and it can go up to 730 days. The decision can affect the costs quite significantly.

There are many other questions that we can ask and answer related to metadata, performance metrics. But, thankfully, Azure Application Insights takes care of most of them including performance metrics, timestamps, correlation IDs, operation IDs, Parent Ids, types of requests. For this reason, I'll focus more on the message format for custom logs to send to Azure.

Structured Logging With Application Insights

Structure logging is basically the serialization and formatting of the log message. What it helps with is querying and analysis.

Non-structured logging can use C#'s string interpolation but that will just show up as a single string message in Application Insights whereas the structured log message will also create custom attributes defined in the message which can later be queried. .NET Core and Azure Application Insights SDK provide an out-of-box way for structured logging using ILogger instead of external logging libraries like Serilog (great library). Consider the two logging statements where the latter uses Structured logging:

var userId = 101;

//with only string interpolation
//"log" is the the object of ILogger service 
log.LogInformation($"String Interpolation: The user id is {userId}");

//with structured logging
log.LogInformation("Structured Logging: The user id is {userId}", userId);

At a glance, those two statements might look identical in Azure Logs as follows:

However, upon diving further the "Structured Logging" statement has a custom attribute called prop__{propertyName} added to the log table which can be viewed and queried by diving further into event details under CustomDimensions, as shown by the following screenshot:

Now, the attribute can be queried as follows:

This makes it easier and effective to answer questions about activities by a user such as disputes or verifying claims.

JSON Attributes In Message

If there is a real use case, then it's also possible to send entire objects as JSON as a part of the log message. However, the process starts to become a bit more involved. The ILogger requires that the conversion be explicit; for example:

//The User object to log
public class User
    {
        public int Id { get; set; }

        public string OrderId { get; set; }

        public User(int id, string orderId)
        {
            Id = id;
            OrderId = orderId;
        }
    }

The above object is initialized followed by serialization using Newtonsoft.Json package and sent using ILogger service:

var user = new User(101, "O-001");
log.LogInformation("Json:The user is {user}", JsonConvert.SerializeObject(user));

In Azure, the customDimensions.prop__User is a JSON object as follows:

The following can be queried but required parsing of JSON back to an object:

Additional Tips

It's a good idea to map logging levels to the message type so that there is a standardized format for logging for consistency. Defining a clear difference between DEBUG vs. INFO and WARNING vs. ERROR helps avoid confusion and makes filtering messages easier.

As suggested in this lucid publication, INFO could be reserved for milestones or checkpoints. DEBUG for data samples and additional details, WARNING for errors from which the application can recover, and ERROR for critical failures.

• At the bare minimum, the log messages should answer, what happened and why.
• Standardizing templates for internal or business error codes for expected errors or event codes in case of information events.

Logging is not something to underrate in any reliable system. Standardization and consistency of log messages provide control over the system, making filtering and analysis much easier down the line. Structured logging has made it even easier and faster to answer questions from the Support Team.

<sub>References

Structured Logging: Crafting Useful Message Content</sub>