C# ASP.NET Core Serilog add class name and method to log

Question

I recently added logging to my ASP.Net Core project. Currently the log writes to a .txt file in this format:

{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level}] {Message}{NewLine}{Exception}

For example:

2017-11-30 13:58:22.229 +01:00 [Information] Item created in database.

This is fine but I would like to have the name of the class that logs and the method that is being executed to this .txt file. For example when Class A writes something to the database using Method B and logs this, I would like to see something like

ClassA.MethodB: Item created in database

All the classes that log have their Logger injected into their constructors like

public class ClassA
{
    private readonly ILogger _log;

    public ClassA(ILogger<ClassA> log){
        _log = log;
    }

    public void AddItemToDb(Item item){
        //Add item
        //On success: 
        _log.LogInfo("Added item to db.");
    }
}

I'm currently using Serilog and using the following LoggerConfiguration:

var logger = new LoggerConfiguration()
    .MinimumLevel.Verbose()
    .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
    .WriteTo.RollingFile(Configuration.GetValue<string>("LogFilePath") + "-{Date}.txt", LogEventLevel.Information)
    .CreateLogger();

How can I add the class and method to my logs?

Edit

I added a custom outputTemplate to the .WriteTo.Rollingfile() method like so:

"{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level}] ({SourceContext}) {Message}{NewLine}{Exception}")

Which resulted in the namespace plus the class to be added in the log, only the method is missing now

Solution 1

I solved this issue by using a combination of Jordan's answer and this answer.

I changed my Loggerconfiguration by adding the logcontext through enrichment and I added the property 'method' to my outputTemplate:

var logger = new LoggerConfiguration()
    .MinimumLevel.Verbose()
    .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
    .Enrich.FromLogContext()
    .WriteTo.RollingFile(Configuration.GetValue<string>("LogFilePath") + "-{Date}.txt", LogEventLevel.Information, 
        outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level}] ({SourceContext}.{Method}) {Message}{NewLine}{Exception}")
    .CreateLogger();

The Enrich.FromLogContext enables properties to be pushed to the outputTemplate by using the LogContext.PushProperty() method. In this case for the 'method' property (notice the {Method} in the outputTemplate).

Example for async methods:

using (LogContext.PushProperty("Method", new LogAsyncMethods().GetActualAsyncMethodName()))
{
    _log.LogInformation("Log message.");
}

Where GetActualAsyncMethodName() is written like this:

public static string GetActualAsyncMethodName([CallerMemberName]string name = null) => name;

This works fine for async methods.

Now for non-async methods this works fine:

using (LogContext.PushProperty("Method", System.Reflection.MethodBase.GetCurrentMethod().Name))
{
    _log.LogInformation("Changing of customer name succeeded");
}

Now the method name is being displayed in the logging. The SourceContext adds the namespace + the class and by adding ".{Method}" it will result in:

Namespace.ClassName.MethodName

Solution 2

Using SeriLog with ASP.NET Core is lagging a bit behind the full .NET F/W if you are using the built-in logger factory. You can solve this by writing a series of extension methods like this:

public static class LoggerExtensions
{
    public static void LogAppError<T>(this ILogger<T> logger, EventId eventId, Exception exception, string message,
        [CallerMemberName] string memberName = "",
        [CallerFilePath] string sourceFilePath = "",
        [CallerLineNumber] int sourceLineNumber = 0)
    {
        using (var prop = LogContext.PushProperty("MemberName", memberName))
        {
            LogContext.PushProperty("FilePath", sourceFilePath);
            LogContext.PushProperty("LineNumber", sourceLineNumber);
            logger.LogError(eventId, exception, message);
        }
    }
}

The calling it from you code like this:

public PeopleController(ILogger<PeopleController> logger)
{
    _logger.LogAppError("Ctor");
}

This assumes that you have an output template similar to this:

private static string outputTemplate =
    @"[{Timestamp:HH:mm:ss} {Level}] {SourceContext}{NewLine}Message:{Message}{NewLine}in method {MemberName} at {FilePath}:{LineNumber}{NewLine}{Exception}{NewLine}";

When you call into the extension method, the method, file, and line number are picked up by the respective attributes. Pushing a property onto the LogContext return an IDisposable that will remove that property and any property added after it. So, by wrapping the call in the using statement, once the LogError method is called on the logger, the properties are removed from the context and won't pollute any other logging calls.

Solution 3

In your logger configuration, you will need to enrich with the LogContext:

var logger = new LoggerConfiguration()
    .MinimumLevel.Verbose()
    .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
    .Enrich.FromLogContext()
    .WriteTo.RollingFile(
        Configuration.GetValue<string>("LogFilePath") + "-{Date}.txt", 
        LogEventLevel.Information)
    .CreateLogger();

But, to be honest, I don't recall if it logs the method name.

Comments

[Jeroen]

Looking through the documentation I can't find anything to get the method name unfortunately

[Jordan S. Jones]

So I just noticed your edit where you mentioned that it was logging the namespace, but not the method, so my answer my be incorrect.

[Jordan S. Jones]

You may have to be explicit with something like this using (LogContext.PushProperty("Method", MethodBase.GetCurrentMethod().Name)) { // Your log stuff }

[Jeroen]

This will work with normal methods. With async methods however this won't work right. It will use the 'MoveNext' method as explained here

[Jeroen]

Using this solution works for async methods. However I don't like it. For log4net just has this implemented in it's core.

[Nicholas Blumhardt]

Keep in mind it's going to be expensive to get the current method via reflection at runtime; an efficient alternative that you might be able to adapt to your scenario is discussed here: stackoverflow.com/questions/29470863/… HTH!