Log custom object in Application Insights from Function App ILogger (C#)
Asked Answered
E

4

6

I have a C# .NET Core Azure Function App, and I am using the ILogger to send logs to Application Insights. This is working well so far.

Function header:

public static void Run([TimerTrigger("0 30 * * * *")] TimerInfo myTimer, ILogger log, ExecutionContext context)

ILogger usage:

log.LogInformation($"MyFunction trigger function executed at: {DateTime.Now}");

In App Insights, I see the log which has default information like which Function App it came from, as well as the message which contains the above string.

However, now I want to log a custom log. I have an IEnumerable<IDictionary<string, string>> and I want each dictionary element of the list to be a separate log. Ideally, I could have a log with each field being a key from the dictionary, and its value to be the corresponding value. Alternatively, I would be fine with some sort of customDimensions field in the log, which would be an object containing all the key-value pairs from 1 dictionary in the list.

The intent is to make the logs simple to query in Kusto. I want to avoid having to parse them when querying them in App Insights.

Notes:

  • since I already use the ILogger for existing logging, is there a way to do the above object-logging with the ILogger interface?
  • if not, how can I log an object like mentioned above with a different logger?

I looked at numerous other similar posts, but none of them seemed to be fully answered.

Earhart answered 8/7, 2021 at 16:23 Comment(2)
Create a logger scope (log.BeginScope()) and pass it your dictionary. Alternatively add your dictionary to Activity.Current's Baggage/Tags. App insights will add custom dimensions for either scenario. For Activity, if one doesn't exist then start a new one. Everything else is automagicStickup
For me Activity.Current.AddBaggage() worked but AddTag() did not.Zettazeugma
Z
5

To elaborate on the comment from @pinkfloydx33: you can do it via

_logger.BeginScope( < your state here > )
{
    // All log methods here include state, regardless 
    // of which ILogger object is used. 
}

or by using

System.Diagnostics.Activity.Current.AddBaggage()

This works without additional configuration (e.g. scopes are already enabled by default on AI).

For example, here's a middleware class to log tenant information that shows both methods:

using Microsoft.AspNetCore.Builder;
using Microsoft.AspNetCore.Http;
using Microsoft.Extensions.Logging;
using System.Collections.Generic;
using System.Threading.Tasks;

namespace MyApp
{

    public static class StoreTenantForLoggingMiddlewareExtensions
    {
        /// <summary>
        /// Register StoreTenantForLoggingMiddleware as middleware.
        /// Call this from Configure() in Startup, as: 
        /// app.UseStoreTenantForLogging()
        /// </summary>
        /// <param name="builder"></param>
        /// <returns></returns>
        public static IApplicationBuilder UseStoreTenantForLogging(
            this IApplicationBuilder builder)
        {
            return builder.UseMiddleware<StoreTenantForLoggingMiddleware>();
        }
    }

    /// <summary>
    /// Middleware to log the Tenant's domain to Application 
    /// Insights as a customDimension
    /// </summary>
    public class StoreTenantForLoggingMiddleware
    {
        private readonly RequestDelegate _next;
        private readonly ILogger<StoreTenantForLoggingMiddleware> _logger;

        public StoreTenantForLoggingMiddleware(RequestDelegate next,
                    ILogger<StoreTenantForLoggingMiddleware> logger)
        {
            _next = next;
            _logger = logger;
        }

        // Here TenantContext is my own class that gets the state
        // I want to be logged. You'd replace with your own object 
        // or just call a method on httpContext.
        public async Task InvokeAsync(HttpContext httpContext, TenantContext tenantContext)
        {
            // Example 1: Add data to current activity. AI will pick this
            // up and add as a customDimension in traces logs.
            var currentActivity = System.Diagnostics.Activity.Current;
            if (currentActivity != null)
            {
                currentActivity.AddBaggage("TenantDomain1", tenantContext?.Domain);
            }

            // Example 2: Use a scope. 
            // If you go with option 1, remove this 'using' but still  
            // call await _next(httpContext);
            using ( var scope = _logger.BeginScope(new Dictionary<string, object>() 
                                 { { "TenantDomain2", tenantContext?.Domain } }))
            {    
                await _next(httpContext);
            }
        }
    }
}

I'm not sure which is best. The Activity one appeals slightly more to me, plus I'm guessing the data might persist a bit later in the pipeline.

For bonus points if you use nlog and want to be able to log the property there you can add this line at the start of Invoke() above and then use ${mdlc:item=TenantDomain} within your nlog.config file.

NLog.MappedDiagnosticsLogicalContext.Set("TenantDomain", tenantContext?.Domain);

You can probably use https://github.com/NLog/NLog.DiagnosticSource as an alternative but I've not tried.

Zettazeugma answered 4/12, 2021 at 23:20 Comment(0)
C
6

UPDATE 2022 and .NET 6

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

Activity.Current?.AddBaggage(nameof(foodMenuALModelCreate), JsonConvert.SerializeObject(foodMenuALModelCreate));
logger.LogInformation(nameof(CreateFoodMenuAutomaticLocalizationsAsync));

Application Insights query:

traces
| where message contains "CreateFoodMenuAutomaticLocalizationsAsync"
| order by timestamp desc

The result looks like this:

enter image description here

Cyclostyle answered 18/3, 2022 at 8:27 Comment(1)
can you explain this a bit more? I've tried this but the Baggage doesn't show up in ApplicationInsights. I have an .Net 6 Azure function app running in isolated mode. I've been testing locally and my activity is not null but for some reason my tags/baggage doesn't show in Application InsightsCoverage
Z
5

To elaborate on the comment from @pinkfloydx33: you can do it via

_logger.BeginScope( < your state here > )
{
    // All log methods here include state, regardless 
    // of which ILogger object is used. 
}

or by using

System.Diagnostics.Activity.Current.AddBaggage()

This works without additional configuration (e.g. scopes are already enabled by default on AI).

For example, here's a middleware class to log tenant information that shows both methods:

using Microsoft.AspNetCore.Builder;
using Microsoft.AspNetCore.Http;
using Microsoft.Extensions.Logging;
using System.Collections.Generic;
using System.Threading.Tasks;

namespace MyApp
{

    public static class StoreTenantForLoggingMiddlewareExtensions
    {
        /// <summary>
        /// Register StoreTenantForLoggingMiddleware as middleware.
        /// Call this from Configure() in Startup, as: 
        /// app.UseStoreTenantForLogging()
        /// </summary>
        /// <param name="builder"></param>
        /// <returns></returns>
        public static IApplicationBuilder UseStoreTenantForLogging(
            this IApplicationBuilder builder)
        {
            return builder.UseMiddleware<StoreTenantForLoggingMiddleware>();
        }
    }

    /// <summary>
    /// Middleware to log the Tenant's domain to Application 
    /// Insights as a customDimension
    /// </summary>
    public class StoreTenantForLoggingMiddleware
    {
        private readonly RequestDelegate _next;
        private readonly ILogger<StoreTenantForLoggingMiddleware> _logger;

        public StoreTenantForLoggingMiddleware(RequestDelegate next,
                    ILogger<StoreTenantForLoggingMiddleware> logger)
        {
            _next = next;
            _logger = logger;
        }

        // Here TenantContext is my own class that gets the state
        // I want to be logged. You'd replace with your own object 
        // or just call a method on httpContext.
        public async Task InvokeAsync(HttpContext httpContext, TenantContext tenantContext)
        {
            // Example 1: Add data to current activity. AI will pick this
            // up and add as a customDimension in traces logs.
            var currentActivity = System.Diagnostics.Activity.Current;
            if (currentActivity != null)
            {
                currentActivity.AddBaggage("TenantDomain1", tenantContext?.Domain);
            }

            // Example 2: Use a scope. 
            // If you go with option 1, remove this 'using' but still  
            // call await _next(httpContext);
            using ( var scope = _logger.BeginScope(new Dictionary<string, object>() 
                                 { { "TenantDomain2", tenantContext?.Domain } }))
            {    
                await _next(httpContext);
            }
        }
    }
}

I'm not sure which is best. The Activity one appeals slightly more to me, plus I'm guessing the data might persist a bit later in the pipeline.

For bonus points if you use nlog and want to be able to log the property there you can add this line at the start of Invoke() above and then use ${mdlc:item=TenantDomain} within your nlog.config file.

NLog.MappedDiagnosticsLogicalContext.Set("TenantDomain", tenantContext?.Domain);

You can probably use https://github.com/NLog/NLog.DiagnosticSource as an alternative but I've not tried.

Zettazeugma answered 4/12, 2021 at 23:20 Comment(0)
C
3

Here is a pattern I have used previously:

public class LogService : ILogService
{
    private readonly ILogger<LogService> _log;
    
    private readonly Dictionary<string, object> _customProperties = new Dictionary<string, object>();

    public LogService(ILogger<LogService> log)
    {
        _log = log;
    }
    
    public void SetCustomProperty(string key, object value)
    {
        _customProperties.Add(key, value);
    }

    public void LogInformation(string message, params object[] args)
    {
        Log(LogLevel.Information, message, args);
    }

    public void LogWarning(string message, params object[] args)
    {
        Log(LogLevel.Warning, message, args);
    }
    
    ...etc 

    private void Log(LogLevel logLevel, string message, params object[] args)
    {
        using (_log.BeginScope(_customProperties))
        {
            _log.Log(logLevel, message, args);
        }
    }
}

The important bit is the last method Log(LogLevel logLevel, string message, params object[] args). It wraps the _log.Log() in a using and uses the _log.BeginScope() to add the custom properties to the log message which should be visible in the Application Insights "Custom Properties" section.

Complice answered 9/7, 2021 at 12:6 Comment(0)
T
0

Link the message with the custom object you are logging.

_logger.LogWarning("This is me! Logging some custom properties {properties}", customProps);

I noted that my custom properties aren't appearing when I'm not including {properties} in my string.

// you can include properties coming from somewhere else...
    
string stringValue = "Value from a string";
int answer = 42;
    
object customProps = new
    {
        property1 = "something",
        name = "Bob",
        magicNumber = answer,
        favoriteString = stringValue
    };
    
    _logger.LogWarning("This is me! Logging some custom properties {properties}", customProps);

Will result in:

enter image description here

Full exception details:

enter image description here

Or you can use the begin scope method

    using (_logger.BeginScope(customProps))
    {
        _logger.LogWarning("Test message custom properties using a scope");
    }

Will result in:

enter image description here

Tacky answered 14/7, 2023 at 10:9 Comment(1)
Anyone know how to create separate "custom properties" in insights for each property? Right now they are all in one property as an object.Tacky

© 2022 - 2024 — McMap. All rights reserved.