NLog 自定义 LayoutRenderer 将日志事件呈现为空字符串

Question

这是我的环境：

• Visual Studio 2017
• 项目的.NET运行时间版本是4.6.2
• XUnit 版本 2.3.1
• NLog 版本 4.4.12
• 流畅断言 4.19.4

问题

从下面可以运行重现问题的示例代码中，我们有 2 个自定义 LayoutRenderer：RendererOne 和 RendererTwo。然后，这 2 个分别用于测试 TestA 和 TestB。当我 运行 一次测试一个时，我没有遇到任何问题。但是，如果通过 XUnit 的 "Run All" 按钮一次性 运行 它们，我会得到失败的断言，如下图所示：

当附加到目标的渲染器在 LayoutRenderer 的 Append 方法中遇到 LogEventInfo 对象时，它似乎正在生成空字符串（输出中的 ""） .从示例代码中可以看出，我启用了 InternalLogger 但是，它并没有告诉我可能出了什么问题。我认为我已经正确地完成了关于如何使用自定义渲染器的所有事情：

• 注册渲染器（参考：TestA 和 TestB 的构造函数）
• 将它们分配给相关的 TestTarget（参考：Log 的构造函数）

我不知道为什么没有正确处理日志事件的布局没有被注册。这是另一个说明这种情况的屏幕截图：

请注意，以上屏幕截图不相关，但用于说明情况。任何类型的 explanation/fix/how-to-troubleshoot 问题都将受到欢迎。

"Ready" 到 运行 代码

using FluentAssertions;
using NLog;
using NLog.Common;
using NLog.Config;
using NLog.LayoutRenderers;
using NLog.Layouts;
using NLog.Targets;
using System;
using System.Collections.Concurrent;
using System.IO;
using System.Text;
using Xunit;

namespace LoggingTests
{
    [Target("test-target")]
    class TestTarget : TargetWithLayout
    {
        public ConcurrentBag<string> Messages = new ConcurrentBag<string>();

        public TestTarget(string name)
        {
            Name = name;
        }

        protected override void Write(LogEventInfo logEvent)
        {
            Messages.Add(Layout.Render(logEvent));
        }
    }

    class Log
    {
        private string _target_name;

        public Log(Layout layout,
                   string target_name)
        {
            if (LogManager.Configuration == null)
            {
                LogManager.Configuration = new LoggingConfiguration();
                InternalLogger.LogFile = Path.Combine(Environment.CurrentDirectory,
                                                      "nlog.debug.txt");
                InternalLogger.LogLevel = LogLevel.Trace;
            }

            _target_name = target_name;
            if (LogManager.Configuration.FindTargetByName<TestTarget>(_target_name) == null)
            {
                // Create the target:
                TestTarget target = new TestTarget(_target_name);

                // Register the target:
                Target.Register<TestTarget>(_target_name);

                // Assign layout to target:
                target.Layout = layout;

                // Add the target to the configuration:
                LogManager.Configuration.AddTarget(_target_name,
                                                   target);

                // Add a logging rule pertaining to the above target:
                LogManager.Configuration.AddRule(LogLevel.Trace,
                                                 LogLevel.Fatal,
                                                 target);

                // Because configuration has been modified programatically, we have to reconfigure all loggers:
                LogManager.ReconfigExistingLoggers();
            }
        }

        public void AssertLogContains(string message)
        {
            TestTarget target = LogManager.Configuration
                                          .FindTargetByName<TestTarget>(_target_name);
            target.Messages.Should().Contain(message);
        }
    }

    class Loggable
    {
        private Logger _logger;

        public Loggable()
        {
            _logger = LogManager.GetCurrentClassLogger();
        }

        public void Error(string message)
        {
            _logger.Error(message);
        }

        public void Info(string message)
        {
            _logger.Info(message);
        }
    }

    [LayoutRenderer("renderer-one")]
    class RendererOne : LayoutRenderer
    {
        protected override void Append(StringBuilder builder,
                                       LogEventInfo logEvent)
        {
            builder.AppendFormat($"{GetType().Name} - {logEvent.Level.Name}: {logEvent.Message}");
        }
    }

    [LayoutRenderer("renderer-two")]
    class RendererTwo : LayoutRenderer
    {
        protected override void Append(StringBuilder builder,
                                       LogEventInfo logEvent)
        {
            builder.AppendFormat($"{GetType().Name} - {logEvent.Level.Name} -> {logEvent.Message}");
        }
    }

    public class TestA
    {
        private Log _log;

        public TestA()
        {
            LayoutRenderer.Register<RendererOne>("renderer-one");
            _log = new Log("${renderer-one}", GetType().Name);
        }

        [Fact]
        public void SomeTest()
        {
            Loggable l = new Loggable();
            l.Info("Test A - SomeTest");
            l.Error("Test A - SomeTest");
            _log.AssertLogContains("RendererOne - Info: Test A - SomeTest");
            _log.AssertLogContains("RendererOne - Error: Test A - SomeTest");
        }

        [Fact]
        public void AnotherTest()
        {
            Loggable l = new Loggable();
            l.Info("Test A - AnotherTest");
            l.Error("Test A - AnotherTest");
            _log.AssertLogContains("RendererOne - Info: Test A - AnotherTest");
            _log.AssertLogContains("RendererOne - Error: Test A - AnotherTest");
        }
    }
    public class TestB
    {
        private Log _log;

        public TestB()
        {
            LayoutRenderer.Register<RendererTwo>("renderer-two");
            _log = new Log("${renderer-two}", GetType().Name);
        }

        [Fact]
        public void SomeTest()
        {
            Loggable l = new Loggable();
            l.Info("Test B - SomeTest");
            l.Error("Test B - SomeTest");
            _log.AssertLogContains("RendererTwo - Info -> Test B - SomeTest");
            _log.AssertLogContains("RendererTwo - Error -> Test B - SomeTest");
        }
    }
}

请注意，您必须安装本问题 "Environment" 部分中提到的依赖库才能 运行 它。此外，您可能必须 运行 代码几次才能使其失败，如上所示。提前致谢。

Answer 1

我在 GitHub 上的 NLog 问题页面上发布了这个问题（参考：https://github.com/NLog/NLog/issues/2525）。 Rolf 建议通过此行明确禁用 Xunit 的并行执行：

[assembly: Xunit.CollectionBehavior(DisableTestParallelization = true)]

在 AssemblyInfo.cs 中解决了问题。请注意，即使我在 XUnit 的 Visual Studio Runner 中明确指示不要进行并行运行，这在上述环境中也是必需的。