NLog如何设置LoggerName？答案

【问题标题】：How is NLog setting the LoggerName?NLog如何设置LoggerName？
【发布时间】：2020-07-18 23:14:35
【问题描述】：

我在 NLog 或者我使用它的方式上遇到了一个有趣的、显然是暂时的问题。

为了避免硬依赖，我正在尝试创建一个日志服务抽象，并且我已经在 NLog.FluentBuilder 类上建模了我的抽象。所以我有一对接口：


public interface ILog
    {
    IFluentLogBuilder Trace([CallerFilePath] string callerFilePath = null);
    IFluentLogBuilder Debug([CallerFilePath] string callerFilePath = null);
    IFluentLogBuilder Info([CallerFilePath] string callerFilePath = null);
    IFluentLogBuilder Warn([CallerFilePath] string callerFilePath = null);
    IFluentLogBuilder Error([CallerFilePath] string callerFilePath = null);
    IFluentLogBuilder Fatal([CallerFilePath] string callerFilePath = null);
    void Shutdown();
    }

public interface IFluentLogBuilder
    {
    IFluentLogBuilder Exception(Exception exception);
    IFluentLogBuilder LoggerName(string loggerName);
    IFluentLogBuilder Message(string message);
    IFluentLogBuilder Message(string format, params object[] args);
    IFluentLogBuilder Message(IFormatProvider provider, string format, params object[] args);
    IFluentLogBuilder Property(string name, object value);
    IFluentLogBuilder Properties(IDictionary<string,object> properties);
    IFluentLogBuilder TimeStamp(DateTime timeStamp);
    IFluentLogBuilder StackTrace(StackTrace stackTrace, int userStackFrame);
    void Write([CallerMemberName] string callerMemberName = null, [CallerFilePath] string callerFilePath = null,
        [CallerLineNumber] int callerLineNumber = default);
    void WriteIf(Func<bool> condition, [CallerMemberName] string callerMemberName = null,
        [CallerFilePath] string callerFilePath = null, [CallerLineNumber] int callerLineNumber = default);
    void WriteIf(bool condition, [CallerMemberName] string callerMemberName = null,
        [CallerFilePath] string callerFilePath = null, [CallerLineNumber] int callerLineNumber = default);
    }

这个想法是能够为不同的日志记录框架创建适配器，当然我所做的第一个是用于 NLog，因为这就是我打算使用的。该实现本质上是 NLog 流畅接口的精简克隆，所以这里是我的版本的部分抽象：

`ILog` 实现

    public sealed class LoggingService : ILog
        {
        private static readonly ILogger DefaultLogger = LogManager.GetCurrentClassLogger();

        static LoggingService()
            {
            LogManager.AutoShutdown = true;
            }

        public IFluentLogBuilder Trace([CallerFilePath] string callerFilePath = null)
            {
            return CreateLogBuilder(LogLevel.Trace, callerFilePath);
            }

        // Methods for other log levels elided for clarity...

        private IFluentLogBuilder CreateLogBuilder(LogLevel logLevel, string callerFilePath)
            {
            string name = !string.IsNullOrWhiteSpace(callerFilePath)
                ? Path.GetFileNameWithoutExtension(callerFilePath)
                : null;
            var logger = string.IsNullOrWhiteSpace(name) ? DefaultLogger : LogManager.GetLogger(name);
            var builder = new LogBuilder(logger, logLevel);
            return builder;
            }

        /// <inheritdoc />
        public void Shutdown() => LogManager.Shutdown();
        }

`IFluentLogBuilder` 实现

    internal sealed class LogBuilder : IFluentLogBuilder
    {
        private readonly LogEventInfo logEvent;
        private readonly ILogger logger;

        public LogBuilder(ILogger logger, LogLevel level)
        {
            if (logger == null)
                throw new ArgumentNullException(nameof(logger));
            if (level == null)
                throw new ArgumentNullException(nameof(level));
            this.logger = logger;
            logEvent = new LogEventInfo { LoggerName = logger.Name, Level = level };
        }

        /// <inheritdoc />
        public IFluentLogBuilder Exception(Exception exception)
        {
            logEvent.Exception = exception;
            return this;
        }

        /// <inheritdoc />
        public IFluentLogBuilder LoggerName(string loggerName)
        {
            logEvent.LoggerName = loggerName;
            return this;
        }

        /// <inheritdoc />
        public IFluentLogBuilder Message(string message)
        {
            logEvent.Message = message;
            return this;
        }

        // Some other builder methods elided for clarity... (they all follow the pattern).

        /// <inheritdoc />
        public void Write([CallerMemberName] string callerMemberName = null,
            [CallerFilePath] string callerFilePath = null,
            [CallerLineNumber] int callerLineNumber = default)
        {
            if (!logger.IsEnabled(logEvent.Level)) return;
            SetCallerInfo(callerMemberName, callerFilePath, callerLineNumber);
            logger.Log(logEvent);
        }

        private void SetCallerInfo(string callerMethodName, string callerFilePath, int callerLineNumber)
        {
            if (callerMethodName != null || callerFilePath != null || callerLineNumber != 0)
                logEvent.SetCallerInfo(null, callerMethodName, callerFilePath, callerLineNumber);
        }

        /// <summary>
        /// Builds and returns the <see cref="LogEventInfo"/> without writing it to the log.
        /// </summary>
        internal LogEventInfo Build() => logEvent;
    }

我省略了一些不会为问题添加任何额外信息的方法，基本上它们都遵循相同的模式。这与NLog.Fluent.LogBuilder 类中的内容非常相似，但并不完全相同。

所以它变得有趣了。

测试程序

我在我的库中包含了一个 .NET Core 3.0 控制台应用程序作为示例程序。

我已经完整地复制了这个，但是没有大量的 cmets，这只会得到在这里的方式。

程序只数到 1000，打印出每个数字，并产生一些让事情变得更有趣并展示语义日志记录的异常。

using System;
using System.Collections.Generic;
using System.Threading.Tasks;
using TA.Utils.Core;

namespace TA.Utils.Logging.NLog.SampleConsoleApp
    {
    class Program
        {
        static readonly List<int> SuperstitiousNumbers = new List<int> {13, 7, 666, 3, 8, 88, 888};

        async static Task Main(string[] args)
            {
            var log = new LoggingService();
            log.Info()
                .Message("Application stating - version {Version}", GitVersion.GitInformationalVersion)
                .Property("SemVer", GitVersion.GitFullSemVer)
                .Property("GitCommit", GitVersion.GitCommitSha)
                .Property("CommitDate", GitVersion.GitCommitDate)
                .Write();
            var seed = DateTime.Now.Millisecond;
            var gameOfChance = new Random(seed);
            log.Debug().Property("seed",seed).Write();

            for (int i = 0; i < 1000; i++)
                {
                try
                    {
                    log.Debug().Message("Starting iteration {iteration}", i).Write();
                    if (SuperstitiousNumbers.Contains(i))
                        {
                        throw new SuperstitiousNumberException($"Skipping {i} because it is a superstitious number");
                        }

                    // There's a small chance of a random "failure"
                    if (gameOfChance.Next(100) < 3)
                        throw new ApplicationException("Random failure");
                    }
                catch (SuperstitiousNumberException ex)
                    {
                    log.Warn()
                        .Message("Superstitious looking number: {number}", i)
                        .Exception(ex)
                        .Property("SuperstitiousNumbers", SuperstitiousNumbers)
                        .Write();
                    }
                catch (ApplicationException ae)
                    {
                    log.Error().Exception(ae).Message("Failed iteration {iteration}", i).Write();
                    }
                await Task.Delay(TimeSpan.FromMilliseconds(1000));
                log.Debug().Message("Finished iteration {iteration}", i).Write();
                }
            log.Info().Message("Program terminated").Write();
            log.Shutdown();
            }
        }
    }

此程序产生以下日志输出。

00:01:09.4823 | INFO  | LogBuilder                      | Application stating - version "1.1.1-beta.1+18.Branch.hotfix-1.1.1.Sha.8b8fa5a008c35d4fc21c99d0bd9a01f6d32c9a53"
00:01:09.5339 | DEBUG | LogBuilder                      |
00:01:09.5339 | DEBUG | LogBuilder                      | Starting iteration 0
00:01:10.5636 | DEBUG | LogBuilder                      | Finished iteration 0
00:01:10.5636 | DEBUG | LogBuilder                      | Starting iteration 1
00:01:11.5762 | DEBUG | LogBuilder                      | Finished iteration 1
00:01:11.5762 | DEBUG | LogBuilder                      | Starting iteration 2
00:01:12.5893 | DEBUG | LogBuilder                      | Finished iteration 2
00:01:12.5893 | DEBUG | LogBuilder                      | Starting iteration 3
00:01:12.5893 | WARN  | LogBuilder                      | Superstitious looking number: 3
00:01:13.6325 | DEBUG | LogBuilder                      | Finished iteration 3
00:01:13.6325 | DEBUG | LogBuilder                      | Starting iteration 4
00:01:14.6484 | DEBUG | LogBuilder                      | Finished iteration 4
00:01:14.6484 | DEBUG | LogBuilder                      | Starting iteration 5
00:01:15.6534 | DEBUG | LogBuilder                      | Finished iteration 5
00:01:15.6534 | DEBUG | LogBuilder                      | Starting iteration 6
00:01:16.6653 | DEBUG | LogBuilder                      | Finished iteration 6
00:01:16.6653 | DEBUG | LogBuilder                      | Starting iteration 7
00:01:16.6653 | WARN  | LogBuilder                      | Superstitious looking number: 7
00:01:17.6787 | DEBUG | LogBuilder                      | Finished iteration 7
00:01:17.6787 | DEBUG | LogBuilder                      | Starting iteration 8
00:01:17.6787 | WARN  | LogBuilder                      | Superstitious looking number: 8
00:01:18.6890 | DEBUG | LogBuilder                      | Finished iteration 8
00:01:18.6890 | DEBUG | LogBuilder                      | Starting iteration 9
00:01:19.6926 | DEBUG | LogBuilder                      | Finished iteration 9
00:01:19.6935 | DEBUG | LogBuilder                      | Starting iteration 10
00:01:20.7071 | DEBUG | LogBuilder                      | Finished iteration 10
00:01:20.7071 | DEBUG | LogBuilder                      | Starting iteration 11
00:01:21.7110 | DEBUG | LogBuilder                      | Finished iteration 11
00:01:21.7110 | DEBUG | LogBuilder                      | Starting iteration 12
00:01:22.7367 | DEBUG | LogBuilder                      | Finished iteration 12
00:01:22.7404 | DEBUG | LogBuilder                      | Starting iteration 13
00:01:22.7404 | WARN  | LogBuilder                      | Superstitious looking number: 13
00:01:23.7621 | DEBUG | LogBuilder                      | Finished iteration 13
00:01:23.7621 | DEBUG | LogBuilder                      | Starting iteration 14
00:01:24.7756 | DEBUG | Program                         | Finished iteration 14
00:01:24.7756 | DEBUG | Program                         | Starting iteration 15
00:01:25.7876 | DEBUG | Program                         | Finished iteration 15
00:01:25.7876 | DEBUG | Program                         | Starting iteration 16
00:01:26.8040 | DEBUG | Program                         | Finished iteration 16
00:01:26.8040 | DEBUG | Program                         | Starting iteration 17
00:01:27.8176 | DEBUG | Program                         | Finished iteration 17
00:01:27.8176 | DEBUG | Program                         | Starting iteration 18
00:01:28.8277 | DEBUG | Program                         | Finished iteration 18
00:01:28.8277 | DEBUG | Program                         | Starting iteration 19
00:01:29.8372 | DEBUG | Program                         | Finished iteration 19
00:01:29.8372 | DEBUG | Program                         | Starting iteration 20

所以这里是牛肉。为什么在迭代 14 中途源名称从 LogBuilder 更改为 Program？为什么是LogBuilder？

我问自己的一个问题是：“它总是在同一个地方改变吗？”答案是否定的。它以正负一次迭代变化。

我的猜测是这可能与我正在使用的缓冲日志目标有关...这是我的 NLog.config 文件：

<?xml version="1.0" encoding="utf-8"?>

<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       autoReload="true">
  <extensions>
    <add assembly="NLog.Targets.Seq"/>
  </extensions>

  <targets async="true" >
    <target xsi:type="ColoredConsole" name="console"
            layout="${time} | ${pad:padding=-5:inner=${uppercase:${level}}} | ${pad:padding=-31:inner=${callsite:className=true:fileName=false:includeSourcePath=false:methodName=false:includeNamespace=false}} | ${message}" >
      <highlight-row condition="level == LogLevel.Debug" foregroundColor="DarkGreen" />
      <highlight-row condition="level == LogLevel.Info" foregroundColor="White" />
      <highlight-row condition="level == LogLevel.Warn" foregroundColor="Yellow" />
      <highlight-row condition="level == LogLevel.Error" foregroundColor="Red" />
      <highlight-row condition="level == LogLevel.Fatal" foregroundColor="Red" backgroundColor="White" />
    </target>

    <target name="seq" xsi:type="BufferingWrapper" bufferSize="1000"
            flushTimeout="500" slidingTimeout="false">
      <target xsi:type="Seq" name="seq" serverUrl="http://seq.nowhere.com:5341" apiKey="imnotfallingforthatone">
        <!-- Augment the log data with some extra properties -->
        <property name="ProcessId" value="${processid}" />
        <property name="ProcessName" value="${processname}" />
        <property name="ThreadId" value="${threadid}" as="number" />
        <property name="Machine" value="${machinename}" />
        <property name="Host" value="${hostname}" />
        <property name="User" value="${environment-user}" />
      </target>
    </target>

    <target xsi:type="Trace" name="debug" rawWrite="true">
      <layout>${pad:padding=-5:inner=${uppercase:${level}}}|${pad:padding=-16:fixedLength=true:alignmentOnTruncation=right:inner=${callsite:className=true:fileName=false:includeSourcePath=false:methodName=false:includeNamespace=false}}| ${message}</layout>
    </target>
  </targets>

  <rules>
    <logger name="*" minlevel="Trace" writeTo="console" />
    <logger name="*" minlevel="Trace" writeTo="debug" />
    <logger name="*" minlevel="Trace" writeTo="seq" />
  </rules>
</nlog>

如果您能提供任何见解，我将不胜感激。如果您想克隆它并在您的 IDE 中检查它，请参考 project is open-source。

【问题讨论】：

我认为这个问题可能与我的主要方法被声明为public static async Task Main() 的事实有关。将async Task 替换为void 并在该方法的后面删除await 会得到更确定的结果。我还没有完全理解这一点，但它似乎肯定是问题的原因。

标签： .net logging .net-core nlog

【解决方案1】：

记录器名称创建如下：

当使用Logger.GetLogger(string name) 时，名称将不加更改地使用
使用LogManager.GetCurrentClassLogger() 时，会在堆栈跟踪中搜索类的名称。在某些情况下，这可能很棘手，因为内联和异步技巧很难找到正确的名称。

在这种情况下，LogManager.GetCurrentClassLogger() 的使用并不是真正需要的，我建议将其替换为 Logger.GetLogger(string name)

还请注意，您对 fluent API 的设计有点不合常规 - 至少对于您示例中添加的属性而言。

已经有了流畅的界面，见NLog.Fluent namespace
某些属性最好添加到上下文类中（例如 GDC、MDLC，参见 context in NLog）或添加为 custom layout renderer

【讨论】：

这是一个很好的建议，使用Logger.GetLogger 我会这样做。我知道 NLog 流利的界面，我是一个忠实的粉丝，但我不需要依赖于 NLog 的库。因此，为什么我要创建一个看起来有点类似于 NLog 流畅接口的抽象接口；-) 为什么你说我的接口是“非传统的”？我是在 NLog fluent interface 上建模的，所以我不太清楚你的意思是什么......？
我的意思是非常规的例子，一些属性在 GDC 等上会更好？（第二个项目符号）。
啊，好吧，我明白你的意思了。自从我发布这个问题以来，我实际上已经在我的ILog 界面上添加了几个成员，其中一个名为WithAmbientProperty，所以我想我们在那里有相同的想法。能够拥有全局属性绝对有用。我正在登录到 Seq，并且还使用配置文件来添加进程 ID 和计算机名称等内容。这是我第一次尝试正确的结构化日志记录，尽管我已经使用 NLog 多年了，我不敢相信我没有早点这样做！
哦，另外，我发现如果我渲染 ${logger} 属性而不是 ${callsite-whatever} 东西，那么我会得到可靠的结果。使用流利的界面时，呼叫站点似乎并没有得到一致的填充。我想这在事后看来确实是有道理的，尤其是在 async/await 混杂的情况下。
@TimLong NLog 5 将改进对来自 caller-member-attributes 的呼叫站点逻辑的支持。消除进行 StackTrace 捕获的开销。

ILog 实现

IFluentLogBuilder 实现

测试程序

`ILog` 实现

`IFluentLogBuilder` 实现