.net - log4net LogicalThreadContext不起作用

Question

我遇到的问题既不是log4net的错误，还是我的误解。

我正在尝试使用LogicalThreadContext将某些数据与调用上下文相关联，并将其传播到该上下文中任何线程创建的任何日志语句中。这就是LogicalThreadContext优于ThreadContext的据称优势。

我无法使传播正常工作，因此我进行了一个简单的单元测试，以查看其是否有效，但无效。这里是:

[Fact]
public void log4net_logical_thread_context_test()
{
    XmlConfigurator.Configure();
    var log = LogManager.GetLogger(GetType());
    var waitHandle = new ManualResetEvent(false);

    using (LogicalThreadContext.Stacks["foo"].Push("Some contextual info"))
    {
        log.Debug("START");

        ThreadPool.QueueUserWorkItem(delegate
        {
            log.Debug("A DIFFERENT THREAD");
            waitHandle.Set();
        });

        waitHandle.WaitOne();
        log.Debug("STOP");
    }
}

我的log4net配置看起来像这样:

<?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="log.txt" />
            <appendToFile value="true" />
            <layout type="log4net.Layout.PatternLayout">
                <conversionPattern value="[%thread]|[%property{foo}]|%message%newline"/>
            </layout>
        </appender>

        <root>
            <level value="DEBUG" />
            <appender-ref ref="FileAppender" />
        </root>
    </log4net>
</configuration>

我的输出看起来像这样:

[xUnit.net STA Test Execution Thread]|[Some contextual info]|START
[32]|[(null)]|A DIFFERENT THREAD
[xUnit.net STA Test Execution Thread]|[Some contextual info]|STOP

如您所见，我推送到LTC堆栈的数据仅存在于同一线程上的日志记录语句中。后台线程发出的log语句缺少上下文数据。通过测试调试，我可以看到，确实，后台线程上的 LogicalThreadContext.Stacks.Count为零。

深入研究log4net源代码，我发现它使用了 CallContext 类。此类完成了其在锡 jar 上所说的操作-它允许存储和检索当前“调用”的上下文。我不知道它是如何在较低的水平上实现的。
CallContext具有两组可用于存储和检索上下文信息的方法: GetData/ SetData和 LogicalGetData/ LogicalSetData。该文档非常详细地介绍了这两组方法之间的区别，但是示例使用了 GetData/ SetData。 log4net的 LogicalThreadContext也是如此。

快速测试表明 GetData/ SetData表现出相同的问题-数据不会在线程之间传播。我以为我可以试试 LogicalGetData/ LogicalSetData:

[Fact]
public void call_context_test()
{
    XmlConfigurator.Configure();
    var log = LogManager.GetLogger(GetType());

    var count = 5;
    var waitHandles = new ManualResetEvent[count];

    for (var i = 0; i < count; ++i)
    {
        waitHandles[i] = new ManualResetEvent(false);
        var localI = i;

        // on a bg thread, set some call context data
        ThreadPool.QueueUserWorkItem(delegate
        {
            CallContext.LogicalSetData("name", "value " + localI);
            log.DebugFormat("Set call context data to '{0}'", CallContext.LogicalGetData("name"));
            var localWaitHandle = new ManualResetEvent(false);

            // then on another bg thread, make sure the logical call context value is correct with respect to the "owning" bg thread
            ThreadPool.QueueUserWorkItem(delegate
            {
                var value = CallContext.LogicalGetData("name");
                log.DebugFormat("Retrieved call context data '{0}'", value);
                Assert.Equal("value " + localI, value);
                localWaitHandle.Set();
            });

            localWaitHandle.WaitOne();
            waitHandles[localI].Set();
        });
    }

    foreach (var waitHandle in waitHandles)
    {
        waitHandle.WaitOne();
    }
}

该测试通过-使用 LogicalGetData/ LogicalSetData时，上下文信息已成功在线程之间传播。

所以我的问题是: log4net弄错了吗？还是我想念的东西？

更新:我也尝试按照上面的发现更改了 LogicalThreadContextProperties类的自定义版本的log4net。我重新运行了最初的测试，并且成功了。对于这么多人使用的产品，这让我感到很明显是一个问题，所以我必须假设我缺少一些东西。

Answer 1

这是我前段时间问的一个问题，关于ThreadContext和LogicalThreadContext有什么区别:

What is the difference between log4net.ThreadContext and log4net.LogicalThreadContext?

其中有一个链接，指向log4net的作者之一Nicko Cadell发表的有关LogicalThreadContext的工作原理的链接。他谈到了存储在CallContext中的项目，这些项目支持将ILogicalThreadAffinative自动传播到子线程，但log4net不使用ILogicalThreadAffinative。他没有提到有关使用CallContext.LogicalSetData的任何内容，正如您所发现的那样，该方法使CallContext数据自动传播到子线程，而无需实现ILogicalThreadAffinative。

总之，我认为您没有丢失任何东西。我确实认为log4net弄错了。

我意识到您没有要求任何代码，但是这是几个月前当我研究log4net，CallContext，PatternLayoutConverter等时所做的一些工作。

首先，我几个月前将其组合在一起的“逻辑线程上下文”对象。我写它的目的是模仿CaSTLe日志记录工具提供的日志记录上下文抽象。

  public static class LogicalThreadDiagnosticContext
  {
    const string slot = "Logging.Context.LogicalThreadDiagnosticContext";

    internal static IDictionary<string, object> LogicalThreadDictionary
    {
      get
      {
        IDictionary<string, object> dict = (IDictionary<string, object>)CallContext.LogicalGetData(slot);
        if (dict == null)
        {
          dict = new Dictionary<string, object>();
          CallContext.LogicalSetData(slot, dict);
        }

        return dict;
      }
    }

    public new static string ToString()
    {
      if (LogicalThreadDictionary.Count == 0) return "";

      IEnumerable<string> es = (from kvp in LogicalThreadDictionary select string.Format("{0} = {1}", kvp.Key, kvp.Value));

      string s = string.Join(";", es);

      return s;
    }

    public static IDictionary<string, object> CloneProperties()
    {
      return new Dictionary<string, object>(LogicalThreadDictionary);
    }

    public static void Set(string item, object value)
    {
      LogicalThreadDictionary[item] = value;
    }

    public static object Get(string item)
    {
      object s;

      if (!LogicalThreadDictionary.TryGetValue(item, out s))
      {
        s = string.Empty;
      }

      return s;
    }

    public static bool Contains(string item)
    {
      return LogicalThreadDictionary.ContainsKey(item);
    }

    public static void Remove(string item)
    {
      LogicalThreadDictionary.Remove(item);
    }

    public static void Clear()
    {
      LogicalThreadDictionary.Clear();
    }

    public static int Count
    {
      get { return LogicalThreadDictionary.Count; }
    }
  }

这是一个log4net PatternLayoutConverter(在不同的时间编写，主要是作为一个实验来帮助了解log4net和CallContext)。它期望Option属性从逻辑调用上下文中指定一个特定的命名值。编写类似的PatternLayoutConverter并不难，它基于上述名称从逻辑上下文中获取字典，然后使用Option参数索引到字典中。

  class LogicalCallContextLayoutConverter : PatternLayoutConverter
  {
    private bool isDisabled = false;

    protected override void Convert(System.IO.TextWriter writer, LoggingEvent loggingEvent)
    {
      if (isDisabled || Option == null || Option.Length == 0) return;

      try
      {
        object data = CallContext.LogicalGetData(Option);
        if (data != null)
        {
          writer.Write(data.ToString());
        }
      }
      catch (SecurityException)
      {
        isDisabled = true;
      }
    }
  }

要像第一个代码示例中一样使用字典方案，PatternLayoutConverter可能看起来像这样(未经编译和未经测试):

  class LogicalCallContextLayoutConverter : PatternLayoutConverter
  {
    private bool isDisabled = false;

    protected override void Convert(System.IO.TextWriter writer, LoggingEvent loggingEvent)
    {
      if (isDisabled || Option == null || Option.Length == 0) return;

      try
      {
        object data = LogicalThreadDiagnosticContext[Option];
        if (data != null)
        {
          if (data != null)
          {
            writer.Write(data.ToString());
          }
        }
      }
      catch (SecurityException)
      {
        isDisabled = true;
      }
    }
  }

祝你好运!