前言
在專案生產中日誌的記錄是必不可少的,在.net專案中,要說日誌元件,log4net
絕對可有一席之地,隨著公司業務的發展,微服務則必定無可避免。在跨服務中通過日誌進行分析效能或者排查故障點,如何快速定位日誌尤為關鍵。鏈路追蹤技術的出現正是解決這些痛點的。
分散式鏈路追蹤需要收集單次請求所經過的所有服務,而且為了知道請求細節,還需要將具體的業務日誌進行串聯,而這一切的基礎就是要通過一個traceid
從頭傳到尾,相當於將該次請求過程產生的所有日誌都關聯其traceid
,事後排查問題只需要知道traceid
,就可以在日誌中拉出與之關聯的所有日誌。
當然不是所有的公司都需要鏈路追蹤,對於一些小公司,就幾個單體系統,壓根不需要這些。比如我們使用log4net
時,會在日誌模板中加入ThreadId
,例如這樣的模板
"%date [%thread] %-5level - %message%newline"
雖然併發高時我們多個使用者的請求日誌都摻雜在一起,但是我們依然可以根據執行緒號
將該次請求的日誌進行串聯。這在大多時候都很好的解決了我們的問題。
老傳統做法
即使在體量不大的系統中上面的執行緒號很好用了,但是哪有一點不用多執行緒的業務場景呢,當一次請求進來後可能會開多個非同步執行緒去執行,那上面的執行緒號就顯得力不從心了,就是說沒法一下將相干日誌提取出來了。
但是這難不倒我們,我們可以在業務開始時自定義一個隨便字串作為該次請求的唯一標識,然後將該變數通過引數傳給下游方法,下游方法也將其一層一層接力傳下去,在列印日誌時都將該欄位進行輸出,這個辦法很多人都用過吧。
AspNetCore的TraceIdentifier
難道沒有一種優雅的方式能將我們某次請求的過程(包括多執行緒)進行串聯起來的唯一標識嗎?
在ASPNetCore
中其實一直有個不起眼的屬性HttpContext.TraceIdentifier
,可以說他就是框架給我們提供的traceid
,我們可以在所需要的地方都注入HttpContext
來獲取該引數,當然不許那麼麻煩,只需要給日誌元件獲取到該值,在任何leave的日誌輸出時日誌元件將其輸出即可,這個完全沒問題,大家可以去深入研究,有些日誌元件可以直接配置就可以輸出該TraceIdentifier
值到每一條日誌中,也可以將其使用到跨應用呼叫時傳遞到下游服務,如http請求可以通過header攜帶該值,下游從header中獲取並作為它自己的TraceIdentifier
繼續傳遞。
AsyncLocal在鏈路追蹤的應用
ThreadLoacl
倒是熟悉,是每個執行緒之間隔離的,每個執行緒操作的都是自己執行緒的物件,能做到各個執行緒或不影響。AsyncLocal
並不是一個新特性,只是用的場景不多,很少被使用
定義
Represents ambient data that is local to a given asynchronous control flow, such as an asynchronous method.
表示對於給定非同步控制流(如非同步方法)是本地資料的環境資料。
示例
using System;
using System.Threading;
using System.Threading.Tasks;
class Example
{
static AsyncLocal<string> _asyncLocalString = new AsyncLocal<string>();
static ThreadLocal<string> _threadLocalString = new ThreadLocal<string>();
static async Task AsyncMethodA()
{
// Start multiple async method calls, with different AsyncLocal values.
// We also set ThreadLocal values, to demonstrate how the two mechanisms differ.
_asyncLocalString.Value = "Value 1";
_threadLocalString.Value = "Value 1";
var t1 = AsyncMethodB("Value 1");
_asyncLocalString.Value = "Value 2";
_threadLocalString.Value = "Value 2";
var t2 = AsyncMethodB("Value 2");
// Await both calls
await t1;
await t2;
}
static async Task AsyncMethodB(string expectedValue)
{
Console.WriteLine("Entering AsyncMethodB.");
Console.WriteLine(" Expected '{0}', AsyncLocal value is '{1}', ThreadLocal value is '{2}'",
expectedValue, _asyncLocalString.Value, _threadLocalString.Value);
await Task.Delay(100);
Console.WriteLine("Exiting AsyncMethodB.");
Console.WriteLine(" Expected '{0}', got '{1}', ThreadLocal value is '{2}'",
expectedValue, _asyncLocalString.Value, _threadLocalString.Value);
}
static async Task Main(string[] args)
{
await AsyncMethodA();
}
}
// The example displays the following output:
// Entering AsyncMethodB.
// Expected 'Value 1', AsyncLocal value is 'Value 1', ThreadLocal value is 'Value 1'
// Entering AsyncMethodB.
// Expected 'Value 2', AsyncLocal value is 'Value 2', ThreadLocal value is 'Value 2'
// Exiting AsyncMethodB.
// Expected 'Value 2', got 'Value 2', ThreadLocal value is ''
// Exiting AsyncMethodB.
// Expected 'Value 1', got 'Value 1', ThreadLocal value is ''
簡單理解,就是對該變數賦值後,之影響自己個自己的子執行緒,即當前執行緒發起的其他執行緒,包括執行緒池中的執行緒,都能獲取到該值,而子執行緒修改該值,對父執行緒來說是無影響的。而這種特性貌似就是我們尋找那種能夠優雅標記出同一次請求的特性。定義一個全域性變數,在每次請求的起點對該變數賦值一個隨機字串,然後本次請求涉及到的所有執行緒訪問該值,都是我們在入口賦的值。
專案應用
我們可以在任意地方定義一個全域性變數,最好是放到LogHelper之中
AspNet4
public static class LogHelper{
public static AsyncLocal<string> Traceid = new AsyncLocal<string>();
...
}
在授權過濾器中對該值進行賦值,一般授權過濾最先執行,可作為請求的入口點
LogHelper.TraceId.Value = Guid.NewGuid().ToString();
在log4net
的LogHelper中使用,日誌模板為
"%date [%property{trace}] [%thread] %-5level - %message%newline"
public static void Info(object message)
{
ThreadContext.Properties["trace"] = TraceId.Value;
Loger.Info(message);
}
...
AspNetCore
註冊中介軟體進行設定值,將自己的中介軟體註冊靠前點
app.Use(delegate (HttpContext ctx, RequestDelegate next)
{
LogHelper.TraceId.Value = ctx.TraceIdentifier;
return next(ctx);
});
經驗證與預期符合,該實現方式不依賴AspnetCore框架HttpContext.TraceIdentifier
,提供一種實現鏈路追蹤中傳遞TraceId
的一種思路,如有不正確之處歡迎指正,如果該思路對您有幫助,請點贊分享。