How to retain callsite information when wrapping NLog

Question

I have a class that wraps NLog (called NLogger). My logs are saved to my database. The thing I'm having a problem with is how do I show where the logging occured. I have this

<parameter name="@Logger" layout="${callsite}"/>  

but this just shows Core.Logging.Loggers.NLogLogger.Log which is my NlogWrapper not the class which calls my wrapper.

This is my wrapper method

        public void Log(LogType messageType, Type context, string message, Exception exception)
        {
            NLog.Logger logger = NLog.LogManager.GetLogger(context.Name);
            LogLevel logLevel = LogLevel.Info; // Default level to info

            switch (messageType)
            {
                case LogType.Debug:
                    logLevel = LogLevel.Debug;
                    break;
                case LogType.Info:
                    logLevel = LogLevel.Info;
                    break;
                case LogType.Warning:
                    logLevel = LogLevel.Warn;
                    break;
                case LogType.Error:
                    logLevel = LogLevel.Error;
                    break;
                case LogType.Fatal:
                    logLevel = LogLevel.Fatal;
                    break;
                default:
                    throw new ArgumentException("Log message type is not supported");                    
            }

            logger.Log(logLevel, message, exception);
        }

Answer 1

The problem is that your wrapper is not wrapping correctly. Here is an example of how to wrap NLog correctly, taken directly from the source tree of NLog:

using System;
using System.Text;
using NLog;

namespace LoggerWrapper
{    
  /// <summary>    
  /// Provides methods to write messages with event IDs - useful for the Event Log target.    
  /// Wraps a Logger instance.    
  /// </summary>    
  class MyLogger    
  {        
    private Logger _logger;        

    public MyLogger(string name)        
    {            
      _logger = LogManager.GetLogger(name);        
    }        

    public void WriteMessage(string eventID, string message)           
    {            
      ///            
      /// create log event from the passed message            
      ///             
      LogEventInfo logEvent = new LogEventInfo(LogLevel.Info, _logger.Name, message);


      //
      // set event-specific context parameter            
      // this context parameter can be retrieved using ${event-context:EventID}            
      //            
      logEvent.Context["EventID"] = eventID;            
      //             
      // Call the Log() method. It is important to pass typeof(MyLogger) as the            
      // first parameter. If you don't, ${callsite} and other callstack-related             
      // layout renderers will not work properly.            
      //            
      _logger.Log(typeof(MyLogger), logEvent);        
    }    
  }
}

The key is passing the type of your logger wrapper to the call to Log. When NLog tries to find the callsite, it goes up the stack until the first calling method whose declaring type is NOT the type passed to the Log call. This will be the code that is actually calling your wrapper.

In your case, your logger would look something like this:

    public void Log(LogType messageType, Type context, string message, Exception exception)
    {
        NLog.Logger logger = NLog.LogManager.GetLogger(context.Name);
        LogLevel logLevel = LogLevel.Info; // Default level to info

        switch (messageType)
        {
            case LogType.Debug:
                logLevel = LogLevel.Debug;
                break;
            case LogType.Info:
                logLevel = LogLevel.Info;
                break;
            case LogType.Warning:
                logLevel = LogLevel.Warn;
                break;
            case LogType.Error:
                logLevel = LogLevel.Error;
                break;
            case LogType.Fatal:
                logLevel = LogLevel.Fatal;
                break;
            default:
                throw new ArgumentException("Log message type is not supported");                    
        }

        //
        // Build LogEvent here...
        //
        LogEventInfo logEvent = new LogEventInfo(logLevel, context.Name, message);
        logEvent.Exception = exception;

        //
        // Pass the type of your wrapper class here...
        //
        logger.Log(typeof(YourWrapperClass), logEvent);
    }

Answer 2

To skip few frames and dive into wrapper callers context, set up in the App.config, or in program the famous modifier:

skipFrames=1

Examples: See this page for ${callsite:skipFrames=Integer} and this page for ${callsite-linenumber:skipFrames=Integer}

I recommend you to use this format in your wrapper:

${callsite:fileName=true:includeSourcePath=false:skipFrames=1}

The output from this setting will be as follows:

... {LicenseServer.LSCore.MainThreadFunction(LSCore.cs:220)} ...

Answer 3

internal string GetCallingMethodName()
{
  string result = "unknown";
  StackTrace trace = new StackTrace(false);
  for (int i = 0; i < trace.FrameCount; i++)
  {
    StackFrame frame = trace.GetFrame(i);
    MethodBase method = frame.GetMethod();
    Type dt = method.DeclaringType;
    if (!typeof(ILogger).IsAssignableFrom(dt) && method.DeclaringType.Namespace != "DiagnosticsLibrary")
    {
      result = string.Concat(method.DeclaringType.FullName, ".", method.Name);
      break;
    }
  }
  return result;
}

Source : http://slf.codeplex.com/discussions/210075

I used the posted code above to simply extract the calling method name and pass that as part of the "message" parameter to the layout. This lets me have the original method name where the log wrapper was called be written to the log file (rather than the log wrapper's class name).

Answer 4

I have been fighting with this problem a while now.

Really improtant was the Callsite (FullyQualified Namespace) within the logfiles.

First, i tryed to get the right logger out of the Stacktrace:

    [MethodImpl(MethodImplOptions.NoInlining)]
    private static NLog.Logger GetLogger()
    {
        var stackTrace = new StackTrace(false);
        StackFrame[] frames = stackTrace.GetFrames();
        if (null == frames) throw new ArgumentException("Stack frame array is null.");
        StackFrame stackFrame;
        switch (frames.Length)
        {
            case 0:
                throw new ArgumentException("Length of stack frames is 0.");
            case 1:
            case 2:
                stackFrame = frames[frames.Length - 1];
                break;
            default:
                stackFrame = stackTrace.GetFrame(2);
                break;
        }

        Type declaringType = stackFrame.GetMethod()
                                       .DeclaringType;

        return declaringType == null ? LogManager.GetCurrentClassLogger() :                 LogManager.GetLogger(declaringType.FullName);
    }

But sadly, the Stacktrace with MEF is very long and i cannot clearly identify the correct caller for the Requester of the ILogger.

So, instead of injecting the ILogger Interface via Constructor Injection, i have created a ILogFactory Interface, that can get injected via Constructor Injection and call then the Create Method on the Factory

    public interface ILogFactory
    {
        #region Public Methods and Operators

        /// <summary>
        ///     Creates a logger with the Callsite of the given Type
        /// </summary>
        /// <example>
        ///     factory.Create(GetType());
        /// </example>
        /// <param name="type">The type.</param>
        /// <returns></returns>
        ILogger Create(Type type);

        #endregion
    }

And implemented it:

    using System;
    using System.ComponentModel.Composition;

    [Export(typeof(ILogFactory))]
    [PartCreationPolicy(CreationPolicy.Shared)]
    public class LogFactory : ILogFactory
    {
        #region Public Methods and Operators

        public ILogger Create(Type type)
        {
            var logger = new Logger().CreateLogger(type);
            return logger;
        }

        #endregion
    }

With the ILogger:

    public interface ILogger
    {
        #region Public Properties

        bool IsDebugEnabled { get; }

        bool IsErrorEnabled { get; }

        bool IsFatalEnabled { get; }

        bool IsInfoEnabled { get; }

        bool IsTraceEnabled { get; }

        bool IsWarnEnabled { get; }

        #endregion

        #region Public Methods and Operators

        void Debug(Exception exception);
        void Debug(string format, params object[] args);
        void Debug(Exception exception, string format, params object[] args);
        void Error(Exception exception);
        void Error(string format, params object[] args);
        void Error(Exception exception, string format, params object[] args);
        void Fatal(Exception exception);
        void Fatal(string format, params object[] args);
        void Fatal(Exception exception, string format, params object[] args);
        void Info(Exception exception);
        void Info(string format, params object[] args);
        void Info(Exception exception, string format, params object[] args);
        void Trace(Exception exception);
        void Trace(string format, params object[] args);
        void Trace(Exception exception, string format, params object[] args);
        void Warn(Exception exception);
        void Warn(string format, params object[] args);
        void Warn(Exception exception, string format, params object[] args);

        #endregion
    }

and Implementation of:

    using System;

      using NLog;
      using NLog.Config;

      /// <summary>
      ///     The logging service.
      /// </summary>
      public class Logger : NLog.Logger, ILogger
      {
          #region Fields

          private string _loggerName;

          #endregion

          #region Public Methods and Operators

          /// <summary>
          ///     The get logging service.
          /// </summary>
          /// <returns>
          ///     The <see cref="ILogger" />.
          /// </returns>
          public ILogger CreateLogger(Type type)
          {
              if (type == null) throw new ArgumentNullException("type");               

              _loggerName = type.FullName;

              var logger = (ILogger)LogManager.GetLogger(_loggerName, typeof(Logger));

              return logger;
          }

To use it... just inject the ILogFactory and calle the Create Method in a Mefed Importing Constructor:

      [ImportingConstructor]
      public MyConstructor(          
        ILogFactory logFactory)
       {
        _logger = logFactory.Create(GetType());
        }

hope this helps

Answer 5

Nowadays a more simple approach to fix the callsite, is to use LogManager.AddHiddenAssembly(Assembly)

e.g.

LogManager.AddHiddenAssembly(yourAssembly);

This will fix the callsite and no need to do manual stack walking etc.