以vertx为基础的微服务构架下实现requestId的解决思路

摘要: 一个web请求对应一个线程情况下，利用log4j的MDC功能，将requestId绑定在线程变量下，每次log4j记录日志时，从线程变量上获取requestId，并记录到日志文件中。
一个web请求涉及多个线程时，在vertx下，处理过程可以理解为一个线程处理web数据，并将处理后的结果传递给下一个线程，然后重复这个过程直到获取最终的数据。只要在将数据传递给下一个线程的过程中将requestId透明地传给下一个处理线程，就可以实现类型单线程下的requestId记录。
本文主要是介绍lambda表示式如何实现requestId的传递。至于跨网络的数据传递，只能重新重新规定传递的数据结构。

##问题背景

最近认识到requestId在微服务架构排错上的重要性，因为上线后，发现没有requestId的日志很难跟踪到用户的一次行为，同时跨服务间的调用bug很难跟踪和排查。

于是准备开始为日志附加requestId，但是发现这个功能不是很简单。

##问题本质

假设系统的基础日志框架是log4j。对于采用slj4j+log4j的日志框架，因为slj4j是一个外观模式，是对log4j的一次封装，这种日志框架也适合以下讨论。

下面的讨论中也不会涉及如何生成一个requestId，会把精力集中在requestId如何在日志中记录，同时如何在多个线程中传递。

在传统的J2EE框架下，这个问题很简单，使用log4j的MDC功能就行。简单来说就是每次一个web请求到来后，生成一个requestId并且绑定到线程上，因为J2EE下对这次请求的处理都是在同一个线程中，所以保证在请求过程中可以随时获取到requestId，可以很容易实现requestId的记录。

举个例子来说：

在web请求入口中：

String requestId=generateRequestId(); //生成requestId
MDC.put("r",requestId);                           //log4j的功能，将requestId绑定到当前线程中。

在log4j的配置文件中，调整日志的输出模式

log4j.appender.stdout.layout.ConversionPattern=%X{r} %m %n   //%X{r}表示输出MDC中绑定名r的线程变量值

最后在一个请求中输出日志

logger.info("test output")

发现一个requestId出现了日志中（假设这次请求的requestId值为XXXXX），日志输出如下

XXXXX test output

这种设计下对开发人员的开发影响基本为0，性能消耗极小。

但是使用vert.x后，一次web请求中，已经涉及很多个线程进行处理，线程变量已经无法覆盖整个过程了。此时好像也会遇到线程并发的问题。

虽然一个web请求涉及了多个线程，但是一个好消息是在整个请求过程requestId是不会发生改变，这保证了线程安全问题。同时也符合lambda表达式的一个特性，这个特性在是解决方案中会用到。

vertx的一个web请求过程中，多个线程执行过程中是通过数据作为连接的，只要能够在线程切换过程中，将requestId传递过去并将其放到MDC中，也就能实现log4j记录时，日志出现requestId。

其实问题的本质就是如何在实现线程切换执行过程中保证requestId的传递？这里说的线程切换不是操作系统下的线程切换，一个线程拿到上一个线程对web请求数据的处理的结果定义为一次线程切换，通常情况下都是通过lambda表达式实现。

##解决思路

实现过程中涉及一个上面说所的lambda表达式的特性，这里先简单介绍（假设读者已经基本了解lambda表达式是什么了），以vertx的eventbus.send为

String outsideValue="this is a outside lambda value";
eventbus.send("test.requestId",  res->{
logger.info(outsideValue);           //    这里会输出 this is a outside lambda value
});

这里lambda表达式内可以获取lambda表达式定义时的外部变量，该变量在lambda内会变成final类型，这个函数闭包的一个特性，这个特性某种意义上使得lambda表达式获得了额外的参数。

定义一个封装方法实现requestId的传递。

public Handler<AsyncResult<T>>  <T> wrap(Handler<AsyncResult<T>>  source){
String requestId=MDC.get("r");             // 获取当前线程的requestId，此时作为额外的参数
return res->{
MDC.put("r",requestId);        //设置执行线程的requestId线程变量，source执行中可以获取该值
source.handler(res);
}
}

经过包装的代码就能输出requestId了

String outsideValue="this is a outside lambda value";
eventbus.send("test.requestId",  wrap(res->{
logger.info(outsideValue);           //    这里会输出XXXXX  this is a outside lambda value
}));

对于初入门的开发人员可能无法识别那些lambda表达式会导致线程切换，手动通过对lambda增加wrap函数也比较烦，可以考虑重新实现会导致线程切换的接口，接口中使用wrap方法。

对于通过网络传递数据的接口，只能在传递数据中增加requestId属性，传递到另外的处理线程中。实现的方式也可以考虑重新实现接口，在发送端增加requestId属性，在接收端解析requestId属性，并将其放到MDC中。

通过这种方式可以实现类似J2EE下单线程MDC的requestId的功效。