How to log MethodName when wrapping Log4net?

Question

I have wrapped Log4net in a static wrapper and want to log

loggingEvent.LocationInformation.MethodName
loggingEvent.LocationInformation.ClassName

However all I get is the name of my wrapper.

How can I log that info using a forwardingappender and a static wrapper class like

Logger.Debug("Logging to Debug");
Logger.Info("Logging to Info");
Logger.Warn("Logging to Warn");
Logger.Error(ex);
Logger.Fatal(ex);

Dispersant

If I remember well, log4net populates the LocationInformation from the Type you are passing to the LogManager.GetLogger(Type) call, so it is reasonable that presents the info from your wrapper (I am assuming that your wrapper does this: ILog log = LogManager.GetLogger(typeof(MyLogWrapper)). – Alfredalfreda

Actually i wrap it like LoggerManager.GetLogger(Assembly.GetCallingAssembly(),"MyDefaultLoggger"), in order to avoid it – Dispersant

Possible duplicate of When using wrapper, how to preserve class and method name for Log4Net to log? – Zhukov

Answer 1

Well the error was somewhere in my appender but for completeness ill include the answer to the best of my knowledge:

the Facade you need should wrap ILogger and NOT ILog

 public static class Logger
 {
    private readonly static Type ThisDeclaringType = typeof(Logger);
    private static readonly ILogger defaultLogger;

    static Logger()
    {
      defaultLogger =
        LoggerManager.GetLogger(Assembly.GetCallingAssembly(),"MyDefaultLoggger");

...

    public static void Info(string message)
    {
        if (defaultLogger.IsEnabledFor(infoLevel))
        {
            defaultLogger.Log(typeof(Logger), infoLevel, message, null);
        }
    }

Dispersant

I can't believe this information was so hard to find. Thanks! – Pelecypod

Answer 2

What about the %M and %C variables? http://logging.apache.org/log4net/log4net-1.2.11/release/sdk/log4net.Layout.PatternLayout.html

Usage, something like:

<layout type="log4net.Layout.PatternLayout">
  <conversionPattern value="%date [%thread] %-5level %logger [%M %C] - %message%newline" />
</layout>

Doesn't that do what you are after?

Lolitaloll

+1 for being (at least for me) what should be the answer to the question. Any comments as whether this would be more or less performant as the prior answer(s)? – Causerie

Note "when wrapping" in the subject. In the question author's example (when wrapping ILog) %M will be equivalent to "Debug", "Info", etc, which is not useful. – Vitalize

i am suprised that this has so many upvotes because it does not solve the problem. – Huba

Answer 3

I would simply use something like %stacktrace{2} as a conversion pattern.

Example of output:

MyNamespace.ClassName.Method > Common.Log.Warning

where MyNamespace.ClassName.Method is a method that is calling my wrapper and Common.Log.Warning is a method of the wrapper class.

Conversion patterns can be found here.

Vitalize

%stacktrace{2} heped me a lot - Thanks! – Gifted

Answer 4

Just declare your log variable like this...

private static readonly log4net.ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);

Then you can use it normaly.

Vertex

Answer 5

I implemented the following solution for this (.Net framework 4.5+) : the log4net wrapper methods (e.g. Info, Warn, Error) could make use of CallerMemberName and CallerFilePath to fetch the class and method name of the code from where the logs are being called. You can then aggregate these into a custom log4net property.

Feel free to use your log4net own wrapper implementation, the only important things here are: the signature of the Info and Error methods, and the implementation of the GetLogger method.

The 'memberName' and 'sourceFilePath' args should never be specified when calling the Logger.Info or Logger.Error methods, they are auto-filled-in by .Net.

public static class Logger
{
    private class LogSingletonWrapper
    {
        public ILog Log { get; set; }
        public LogSingletonWrapper()
        {
            Log = LogManager.GetLogger(GetType());
        }
    }

    private static readonly Lazy<LogSingletonWrapper> _logger = new Lazy<LogSingletonWrapper>();

    public static void Info(string message, [CallerMemberName] string memberName = "", [CallerFilePath] string sourceFilePath = "") 
        => GetLogger(memberName, sourceFilePath).Info(message);
    
    public static void Error(string message,Exception ex, [CallerMemberName] string memberName = "", [CallerFilePath] string sourceFilePath = "") 
        => GetLogger(memberName, sourceFilePath).Error(message, ex);

    private static ILog GetLogger(string memberName, string sourceFilePath)
    {
        var classname = sourceFilePath.Split('\\').Last().Split('.').First();
        log4net.ThreadContext.Properties["Source"] = $"{classname}.{memberName.Replace(".", "")}";
        return _logger.Value.Log;
    }
}

Then you would could use a log conversion pattern like this in your .config file :

<conversionPattern value="[%level][%date][Thd%thread: %property{Source}][Message: %message]%newline" />

This would result in logs looking like this:

[INFO][2019-07-03 16:42:00,936][Thd1: Application.Start][Message: The application is starting up ...]

[ERROR][2019-07-03 16:42:44,145][Thd6: DataProcessor.ProcessDataBatch][Message: Attempted to divide by zero.]

The following methods were called in the above example: the Start method of the Application class, and the ProcessDataBatch method of the DataProcessor class.

Bloody

Answer 6

This post helped me work out how to write my own wrapper so in return, thought you might like my complete class to wrap the logger which seems to work quite nicely and actually takes just over half as much time as using an ILog directly!

All that's required is the appropriate xml to set up the logging in the config file and

[assembly: log4net.Config.XmlConfigurator(Watch = true)] 

in your AssemblyInfo.cs and it should work easily.

One note: I'm using Log4NetDash with a seriously simple set-up so have cheated and put some information in the wrong fields (eg stack trace in Domain field), this still works for me as I don't care where the information is shown but you might want to fix this if you're setting stuff up properly if you spare time!

using System;
using System.ComponentModel;
using System.Diagnostics;
using System.Reflection;
using System.Threading;
using log4net;
using log4net.Core;

namespace Utility
{
    public class Logger
    {
        static Logger()
        {
            LogManager.GetLogger(typeof(Logger));
        }

        public static void Debug(string message, params object[] parameters)
        {
            Log(message, Level.Debug, null, parameters);
        }

        public static void Info(string message, params object[] parameters)
        {
            Log(message, Level.Info, null, parameters);
        }

        public static void Warn(string message, params object[] parameters)
        {
            Log(message, Level.Warn, null, parameters);
        }

        public static void Error(string message, params object[] parameters)
        {
            Error(message, null, parameters);
        }

        public static void Error(Exception exception)
        {
            if (exception==null)
                return;
            Error(exception.Message, exception);
        }

        public static void Error(string message, Exception exception, params object[] parameters)
        {
            string exceptionStack = "";

            if (exception != null)
            {
                exceptionStack = exception.GetType().Name + " : " + exception.Message + Environment.NewLine;
                Exception loopException = exception;
                while (loopException.InnerException != null)
                {
                    loopException = loopException.InnerException;
                    exceptionStack += loopException.GetType().Name + " : " + loopException.Message + Environment.NewLine;
                }
            }

            Log(message, Level.Error, exceptionStack, parameters);
        }



        private static void Log(string message, Level logLevel, string exceptionMessage, params object[] parameters)
        {
            BackgroundWorker worker = new BackgroundWorker();
            worker.DoWork += LogEvent;
            worker.RunWorkerAsync(new LogMessageSpec
                                      {
                                          ExceptionMessage = exceptionMessage,
                                          LogLevel = logLevel,
                                          Message = message,
                                          Parameters = parameters,
                                          Stack = new StackTrace(),
                                          LogTime = DateTime.Now
                                      });
        }

        private static void LogEvent(object sender, DoWorkEventArgs e)
        {
            try
            {
                LogMessageSpec messageSpec = (LogMessageSpec) e.Argument;

                StackFrame frame = messageSpec.Stack.GetFrame(2);
                MethodBase method = frame.GetMethod();
                Type reflectedType = method.ReflectedType;

                ILogger log = LoggerManager.GetLogger(reflectedType.Assembly, reflectedType);
                Level currenLoggingLevel = ((log4net.Repository.Hierarchy.Logger) log).Parent.Level;

                if (messageSpec.LogLevel<currenLoggingLevel)
                    return;

                messageSpec.Message = string.Format(messageSpec.Message, messageSpec.Parameters);
                string stackTrace = "";
                StackFrame[] frames = messageSpec.Stack.GetFrames();
                if (frames != null)
                {
                    foreach (StackFrame tempFrame in frames)
                    {

                        MethodBase tempMethod = tempFrame.GetMethod();
                        stackTrace += tempMethod.Name + Environment.NewLine;
                    }
                }
                string userName = Thread.CurrentPrincipal.Identity.Name;
                LoggingEventData evdat = new LoggingEventData
                                             {
                                                 Domain = stackTrace,
                                                 Identity = userName,
                                                 Level = messageSpec.LogLevel,
                                                 LocationInfo = new LocationInfo(reflectedType.FullName,
                                                                                 method.Name,
                                                                                 frame.GetFileName(),
                                                                                 frame.GetFileLineNumber().ToString()),
                                                 LoggerName = reflectedType.Name,
                                                 Message = messageSpec.Message,
                                                 TimeStamp = messageSpec.LogTime,
                                                 UserName = userName,
                                                 ExceptionString = messageSpec.ExceptionMessage
                                             };
                log.Log(new LoggingEvent(evdat));
            }
            catch (Exception)
            {}//don't throw exceptions on background thread especially about logging!
        }

        private class LogMessageSpec
        {
            public StackTrace Stack { get; set; }
            public string Message { get; set; }
            public Level LogLevel { get; set; }
            public string ExceptionMessage { get; set; }
            public object[] Parameters { get; set; }
            public DateTime LogTime { get; set; }
        }
    }
}

Camporee

Reflection is quite expensive specially for logging purposes. You don't want to say that your code is slow because of logging. I would rather use CallerMemberName and other similar attributes if using C# 5 – Azevedo

Very true. I tend to use the threaded version of Log where possible so that the logging happens away from the critical path. It's not always possible though, I should really look at updating my logging as this is well over five years old now. Ta – Camporee

Answer 7

How about C#4.5 feature callerinfo - http://msdn.microsoft.com/en-us/library/system.runtime.compilerservices.callermembernameattribute.aspx

Tuberous

Answer 8

The only thing I can think of doing (as I dont currently use log4net) is to request a stacktrace(new StackTrace), and go back a frame to get the info you need. However, I am unsure of the runtime performance impact of this.

Retrorse

log4net allready has this in LocationInformation class, but it does not work when wrapping Ilog – Dispersant

log4net is behind the scenes doing the same thing when the pattern layout contains the %m and %c variables. They warn against using them for obvious performance reasons. – Sultanate

Answer 9

I will just write more code of the correct answer of Claus

In the wrapper class

public static class Logger
{
   private static readonly ILogger DefaultLogger;

   static Logger()
   {
      defaultLogger = LoggerManager.GetLogger(Assembly.GetCallingAssembly(), "MyDefaultLoggger"); // MyDefaultLoggger is the name of Logger
   }

  public static void LogError(object message)
  {
      Level errorLevel = Level.Error;
      if (DefaultLogger.IsEnabledFor(errorLevel))
      {
          DefaultLogger.Log(typeof(Logger), errorLevel, message, null);
      }
  }

  public static void LogError(object message, Exception exception)
  {
      Level errorLevel = Level.Error;
      if (DefaultLogger.IsEnabledFor(errorLevel))
      {
          DefaultLogger.Log(typeof(Logger), errorLevel, message, exception);
      }
  }

and so on for the rest of methods.

in web.config or app.config log4net.Layout.PatternLayout you can use some Conversion Patterns like:

%location %method %line

<layout type="log4net.Layout.PatternLayout">
    <conversionPattern value="%date{dd/MM/yyyy hh:mm:ss.fff tt} [%thread] %level %logger [%location %method %line] [%C %M] - %newline%message%newline%exception"/>
  </layout>

Triviality

Answer 10

Click here to learn how to implement log4net in .NET Core 2.2

The following steps are taken from the above link, and break down how to add log4net to a .NET Core 2.2 project.

First, run the following command in the Package-Manager console:

Install-Package Log4Net_Logging -Version 1.0.0

Then add a log4net.config with the following information (please edit it to match your set up):

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
  </configSections>
  <log4net>
    <appender name="FileAppender" type="log4net.Appender.FileAppender">
      <file value="logfile.log" />
      <appendToFile value="true" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%d [%t] %-5p - %m%n" />
      </layout>
    </appender>
    <root>
      <!--LogLevel: OFF, FATAL, ERROR, WARN, INFO, DEBUG, ALL -->
      <level value="ALL" />
      <appender-ref ref="FileAppender" />
    </root>
  </log4net>
</configuration>

Then, add the following code into a controller (this is an example, please edit it before adding it to your controller):

public ValuesController()
{
    LogFourNet.SetUp(Assembly.GetEntryAssembly(), "log4net.config");
}
// GET api/values
[HttpGet]
public ActionResult<IEnumerable<string>> Get()
{
    LogFourNet.Info(this, "This is Info logging");
    LogFourNet.Debug(this, "This is Debug logging");
    LogFourNet.Error(this, "This is Error logging");    
    return new string[] { "value1", "value2" };
}

Then call the relevant controller action (using the above example, call /Values/Get with an HTTP GET), and you will receive the output matching the following:

2019-06-05 19:58:45,103 [9] INFO-[Log4NetLogging_Project.Controllers.ValuesController.Get:23] - This is Info logging

Bielefeld

Answer 11

In a similar situation, instead of relying on the stacktrace via reflection (as log4net does), I wanted to get the method name from [CallerMemberName] statically. With a bit of hair-pulling, I came up with a wrapper method like the following:

// Works with a pattern like: (%file.%method:%line) %message%newline
public void WriteLog(ILogger logger, Level level, object msg, Exception? ex = null, [CallerMemberName] string memberName = "", [CallerFilePath] string filePath = "", [CallerLineNumber] int lineNo = 0)
{
    if (!logger.IsEnabledFor(level)) { return; }

    RendererMap rendererMap = logger.Repository.RendererMap;
    string fileName = Path.GetFileNameWithoutExtension(filePath);
    LoggingEventData data = new LoggingEventData()
    {
        Level = level,
        Message = rendererMap.FindAndRender(msg),
        ExceptionString = ex is null ? "" : rendererMap.FindAndRender(ex),
        LoggerName = logger.Name,
        LocationInfo = new LocationInfo(fileName, memberName, fileName, lineNo.ToString(CultureInfo.InvariantCulture)),
        TimeStampUtc = DateTime.UtcNow,
    };

    const FixFlags flags = FixFlags.All & ~FixFlags.ThreadName;
    LoggingEvent e = new LoggingEvent(null, logger.Repository, data, flags);

    logger.Log(e);
}

@Quantum_Joe's answer might be simpler because it stores location info in ThreadContext.Properties rather than modifying the original. I had some constraint that prevented modifying the format pattern to include variables like %property{Source}, so that option wasn't available to me.

Whydah