在项目生产中日志的记录是必不可少的,在.net项目中,要说日志组件,log4net
绝对可有一席之地,随着公司业务的发展,微服务则必定无可避免。在跨服务中通过日志进行分析性能或者排查故障点,如何快速定位日志尤为关键。链路追踪技术的出现正是解决这些痛点的。
分布式链路追踪需要收集单次请求所经过的所有服务,而且为了知道请求细节,还需要将具体的业务日志进行串联,而这一切的基础就是要通过一个traceid
从头传到尾,相当于将该次请求过程产生的所有日志都关联其traceid
,事后排查问题只需要知道traceid
,就可以在日志中拉出与之关联的所有日志。
当然不是所有的公司都需要链路追踪,对于一些小公司,就几个单体系统,压根不需要这些。比如我们使用log4net
时,会在日志模板中加入ThreadId
,例如这样的模板
"%date [%thread] %-5level - %message%newline"
虽然并发高时我们多个用户的请求日志都掺杂在一起,但是我们依然可以根据线程号
将该次请求的日志进行串联。这在大多时候都很好的解决了我们的问题。
即使在体量不大的系统中上面的线程号很好用了,但是哪有一点不用多线程的业务场景呢,当一次请求进来后可能会开多个异步线程去执行,那上面的线程号就显得力不从心了,就是说没法一下将相干日志提取出来了。
但是这难不倒我们,我们可以在业务开始时自定义一个随便字符串作为该次请求的唯一标识,然后将该变量通过参数传给下游方法,下游方法也将其一层一层接力传下去,在打印日志时都将该字段进行输出,这个办法很多人都用过吧。
难道没有一种优雅的方式能将我们某次请求的过程(包括多线程)进行串联起来的唯一标识吗?
在ASPNetCore
中其实一直有个不起眼的属性HttpContext.TraceIdentifier
,可以说他就是框架给我们提供的traceid
,我们可以在所需要的地方都注入HttpContext
来获取该参数,当然不许那么麻烦,只需要给日志组件获取到该值,在任何leave的日志输出时日志组件将其输出即可,这个完全没问题,大家可以去深入研究,有些日志组件可以直接配置就可以输出该TraceIdentifier
值到每一条日志中,也可以将其使用到跨应用调用时传递到下游服务,如http请求可以通过header携带该值,下游从header中获取并作为它自己的TraceIdentifier
继续传递。
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之中
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); } ...
注册中间件进行设置值,将自己的中间件注册靠前点
app.Use(delegate (HttpContext ctx, RequestDelegate next) { LogHelper.TraceId.Value = ctx.TraceIdentifier; return next(ctx); });
经验证与预期符合,该实现方式不依赖AspnetCore框架HttpContext.TraceIdentifier
,提供一种实现链路追踪中传递TraceId
的一种思路,如有不正确之处欢迎指正,如果该思路对您有帮助,请点赞分享。