使用 MDLC 和 NDLC 跨线程的奇怪 NLog 行为

Weird NLog behavior across threads with MDLC and NDLC

我正在尝试跨线程设置 CorrelationID,以在对我的服务器的调用与对外部 Web 服务的相应调用之间建立 link。相关 ID 是一个 GUID,我将其保存在 NLog 的逻辑上下文结构中(据推测,逻辑上下文可以跨线程正常工作)。

我的想法是让对我的服务器的任何请求与我因该请求向各种 Web 服务发出的相应请求之间共享一个 GUID。我尝试同时使用 MDLC 和 NDLC。

问题是只有第一个请求正确存储了值,并且为所有后续请求保存了空白值,即使为我的服务器的每个新请求正确生成了 GUID。

我尝试将日志记录到数据库或文件中。如果我在代码中添加一个断点,或者如果我在日志记录方法周围的任何地方添加一个 System.Threading.Sleep ,问题似乎会自行解决。同样奇怪的是,我可以在逻辑上下文中设置值的方法之前或之后添加 Sleep,并且无论哪种方式它仍然有效。删除 Sleep/breakpoint 会导致它再次损坏。

我正在使用 NLog v4.5.2。

记录模块:

using System;
using System.Web;
using NLog;

namespace Shift.Stardust.Engine.Modules
{
    public class LoggingHttpModule : IHttpModule
    {
        public void Init(HttpApplication context)
        {
            context.BeginRequest += HandleBeginRequest;
        }

        public void Dispose()
        {
        }

        private void HandleBeginRequest(object sender, EventArgs e)
        {
            System.Threading.Thread.Sleep(500);
            var guid = Guid.NewGuid().ToString();
            NestedDiagnosticsLogicalContext.Push(guid);
        }
    }
}

在 HandleBeginRequest 中的任意位置放置断点会产生正确的输出。与添加 System.Threading.Thread.Sleep(500) 类似。当然,我不想在我的代码中添加这样一行来解决这个问题。

NLog 配置:

<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" internalLogFile="c:\temp\nlog-internal.txt" internalLogLevel="Trace">
  <variable name="logDirectory" value="${basedir}/logs"/>
  <targets>
    <target name="asyncdatabase"
            xsi:type="AsyncWrapper"
            queueLimit="5000"
            overflowAction="Block">
        <target xsi:type="Database"
                connectionStringName="ConnectionStringHere"
                keepConnection="true">
            <commandText>[db].[P_Log_Insert] @CreateDate, @ApplicationName, @MachineName, @LoggerName, @LogLevel, @Message, @Exception, NULL, @EngineSessionId, @CorrelationId</commandText>
            <parameter name="@CreateDate" layout="${date}"/>
            <parameter name="@ApplicationName" layout="${appsetting:name=Shift.Stardust.ApplicationName}"/>
            <parameter name="@MachineName" layout="${machinename}"/>
            <parameter name="@LoggerName" layout="${logger}"/>
            <parameter name="@LogLevel" layout="${level}"/>
            <parameter name="@Message" layout="${message}"/>
            <parameter name="@Exception" layout="${exception:format=tostring}"/>
            <parameter name="@EngineSessionId" layout="${aspnet-sessionid}"/>
            <parameter name="@CorrelationId" layout="${ndlc}"/>
        </target>
    </target>
  </targets>
  <rules>
    <logger name="Http.*" minlevel="Info" writeTo="asyncdatabase" final="true" />
  </rules>
</nlog>

我希望每个传入请求都有不同的 CorrelationID,但这仅适用于第一个请求。所有后续的值都为空字符串。

我认为在这种情况下写入 HTTP 上下文会更好。

例如

HttpContext.Current.Items["myvariable"] = 123;

和用法:

${aspnet-item:variable=myvariable} - produces "123"

docs

您需要 NLog.Web (ASP.NET non-core) 包。

注意:ASP.NET核心用户应该使用NLog.Web.AspNetCore而不是NLog.Web