Странное поведение NLog в потоках с MDLC и NDLC - PullRequest
Новая
       26

Странное поведение NLog в потоках с MDLC и NDLC

2 голосов
/ 01 июля 2019

Я пытаюсь настроить CorrelationID между потоками, чтобы установить связь между вызовами к моему серверу и соответствующими вызовами, которые я делаю к внешним веб-службам. Идентификатор корреляции - это GUID, который я сохраняю в структурах логического контекста NLog (предположительно, логические контексты работают в разных потоках).

Идея состоит в том, чтобы иметь GUID, общий для любого запроса к моему серверу, и соответствующих запросов, которые я выдаю различным веб-службам из-за этого запроса. Я пытался использовать как MDLC, так и NDLC.

Проблема в том, что значение сохраняется правильно только для первого запроса, и оно сохраняет пустые значения для всех последующих, даже если GUID правильно генерируется для каждого нового запроса к моему серверу.

Я пытался войти в базу данных или в файл. Кажется, проблема решается сама собой, если я добавляю точку останова в коде или если я добавляю System.Threading.Sleep где-нибудь вокруг метода ведения журнала. Также странно, что я могу добавить Sleep до или после метода, который устанавливает значение в логическом контексте, и он все равно работает в любом случае. Удаление точки сна / останова может привести к ее повторному прерыванию.

Я использую 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 для каждого входящего запроса, но это верно только для первого. Все последующие имеют пустую строку в качестве значения.

1 Ответ

2 голосов
/ 03 июля 2019

Я думаю, что лучше написать в контексте HTTP для этого случая.

, например 

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

и использование: 

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

См. документы

Для этого вам нужен пакет NLog.Web (не основной ASP.NET).

Примечание. Для использования ASP.NET Core следует использовать NLog.Web.AspNetCore вместо NLog.Web

...