AsyncLocal在鏈路追蹤中的應用
前言
在項目生產中日誌的記錄是必不可少的,在.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
的一種思路,如有不正確之處歡迎指正,如果該思路對您有幫助,請點贊分享。