asp.net core nlog trace id

最近公司幾次技術分享都有提到traceId，當你程式在執行A > B > C

如果沒有traceId你會非常難知道上下文的關係，你會不知道B被誰呼叫，C又被誰呼叫

整段的請求流程會不清楚，出錯了也很難追蹤哪個環節出錯了

在分散式的系統裡更為重要，例如在A站台呼叫了B站台的API，B站台又呼叫了C站台的API

如果有了traceId，你會知道整個請求流程，在除錯上也會很快的定位方向!!

那asp.net core該如何實現，其實可以使用NLog來記錄traceId，再搭配Middleware來串接分散式的請求

首先我們會先安裝NLog，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.Web.AspNetCore"/>
	</extensions>

	<targets>
		<target xsi:type="File" name="File" fileName="${basedir}/logs/${shortdate}.log"
	            layout="TimeStamp=${longdate} Level=${uppercase:${level}} TraceId=${aspnet-item:variable=TraceId} Message=${message}" />
	</targets>

	<rules>
		<logger name="*" minlevel="Debug" writeTo="File" />
	</rules>
</nlog>

接下來再建一個LoggingMiddleware

using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.Http.Extensions;
using Microsoft.Extensions.Logging;
using System;
using System.Collections.Generic;
using System.Linq;
using System.Threading.Tasks;

namespace WebApplication6
{
    public class LoggingMiddleware
    {
        private readonly ILogger<LoggingMiddleware> logger;
        private readonly RequestDelegate next;

        public LoggingMiddleware(ILogger<LoggingMiddleware> logger, RequestDelegate next)
        {
            this.logger = logger;
            this.next = next;
        }

        public async Task Invoke(HttpContext context)
        {
            var parentTraceId = context.Request.Headers["X-Trace-Id"];
            if (!string.IsNullOrEmpty(parentTraceId))
                context.Items["TraceId"] = parentTraceId;
            else
                context.Items["TraceId"] = Guid.NewGuid().ToString();
            await next(context);
        }
    }
}

這個Middleware的用意是如果別的站台呼叫我們API的時候而且Header有帶X-Trace-Id

我們就會把traceId帶入context.Items["TraceId"]，給NLog使用

如果沒有就自己產一個新的Guid，帶入NLog使用，在Startup.cs加入Middleware

public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
        {            
            if (env.IsDevelopment())
            {
                app.UseDeveloperExceptionPage();
            }

            app.UseHttpsRedirection();
            app.UseMiddleware<LoggingMiddleware>();
            app.UseRouting();

            app.UseAuthorization();

            app.UseEndpoints(endpoints =>
            {
                endpoints.MapControllers();
            });
        }

這個時候我們用一個LogController來測試一下

using CorrelationId.Abstractions;
using Microsoft.AspNetCore.Mvc;
using Microsoft.Extensions.Logging;
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Net.Http;
using System.Threading.Tasks;

namespace WebApplication6.Controllers
{
    [ApiController]
    [Route("[controller]")]
    public class LogController : ControllerBase
    {
        private readonly ILogger<LogController> _logger;

        public LogController(ILogger<LogController> logger)
        {
            _logger = logger;
        }

        [HttpGet]
        [Route("Test1")]
        public IEnumerable<WeatherForecast> Test1()
        {
            _logger.LogInformation("Test1");
            AAA();
            BBB();
            return new List<WeatherForecast>();
        }


        private void AAA()
        {
            _logger.LogInformation("AAA");
        }

        private void BBB()
        {
            _logger.LogInformation("BBB");
        }
    }
}

所以呼叫Test1會寫入這樣的Log

TimeStamp=2022-02-19 15:08:05.5464 Level=INFO TraceId=89214b64-d547-4f49-84f1-8da1e0ff887a Message=Test1
TimeStamp=2022-02-19 15:08:05.5517 Level=INFO TraceId=89214b64-d547-4f49-84f1-8da1e0ff887a Message=AAA
TimeStamp=2022-02-19 15:08:05.5517 Level=INFO TraceId=89214b64-d547-4f49-84f1-8da1e0ff887a Message=BBB
  

如果外部有帶X-trace-Id 1234進來的話，Log會是這樣呈現

TimeStamp=2022-02-19 15:08:28.7794 Level=INFO TraceId=1234 Message=Test1
TimeStamp=2022-02-19 15:08:28.7832 Level=INFO TraceId=1234 Message=AAA
TimeStamp=2022-02-19 15:08:28.7832 Level=INFO TraceId=1234 Message=BBB
  

所以當在Log收集的時候，就會很清楚整條請求的流程