分布式异常日志链路追踪设计和demo
前言
随着微服务化的推进，服务间网状式的交互不仅提高了研发成本，也使得日志的追踪更加繁琐。一个远程接口的调用失败，可能需要查询多个服务日志后才能得找到实际发生异常的服务的堆栈信息。虽然业界已经有了一些成熟的解决方案，比如skywalking、Spring Cloud Sleuth等等，但基于java agent的实现我觉得还是偏重了，能否基于代码层面来实现分布式异常日志链路追踪，牺牲一定的代码侵入性来保证功能的快速实现。刚好入职新公司的试用期考核涉及分布式日志这块的内容，先试着自己造个*，再去学习好的*是怎么造的。
设计思路
日志存在哪？
1.文件
不同微服务可能在不同的服务器，最后的日志文件搜集会比较麻烦，所以这里不考虑文件存储。
2.数据库
基于多数据源的配置，多个微服务将异常信息写入同一个数据库确实可行，但是数据库的IO资源往往是高并发下容易发生瓶颈的地方，即使去异步写，也会存在IO性能上的损耗，所以不是最优解。
3.Redis
我觉得Redis最合理的存储介质。原因如下，一读写都是基于内存速度快，二过期时间可配置化不会发生数据的堆积，三数据类型HashMap完美的适用于分布式日志的存储，key为请求的唯一标识，键值对为服务名和异常信息。
请求的唯一标识怎么来？
考虑到现有项目的接入性，如果要求所有客户端的请求都需要自带请求唯一标识，那确实不太合理，所以唯一标识的生成交给了服务端。在哪里进行拦截统一生成唯一标识呢？一开始想在网关做，但风险太大，既然是追踪微服务间的调用，切面会更合理些，接入性更强。
怎么快速接入现有的项目？
基于bean的手动注册，将切面注入到项目中即可。需配置好服务名、日志过期时间、异常堆栈信息层级等。
DEMO
先看下项目结构
common里面为切面的具体实现，注册中心选用eureka，log-service提供分布式异常日志的查看功能，ServiceA B C为相互调用的微服务。
com.common.aop.FeignAspect
/**
* @Author linlx
* @Date 2021/8/13 8:42
* @Description feign接口切面，实现唯一标识的生成
**/
@Aspect
public class FeignAspect {
private String serverName;
public FeignAspect(String serverName) {
this.serverName = serverName;
}
// 切点为项目feignClient包的位置
@Pointcut("execution(* com.*.client.*.*(..))")
private void pointcut() {
}
@Before(value = "pointcut() && args(apiRequest)")
public void beforeAdvice(ApiRequest<?> apiRequest) {
// 给请求生成唯一标识
if (StringUtils.isEmpty(apiRequest.getRequestId())) {
apiRequest.setRequestId(
"origin-serverName:" + serverName + ":" + UUID.randomUUID().toString().substring(0, 10));
}
}
}
com.common.aop.LogAspect
/**
* @Author linlx
* @Date 2021/8/12 8:42
* @Description
**/
@Aspect
@Slf4j
public class LogAspect {
private ThreadLocal<ApiRequest> threadLocal = new ThreadLocal<>();
private ExecutorService executorService;
// 服务名
private String serviceName;
// 日志过期时间
private Long expireMinutes;
// 异常堆栈信息的层级
private Integer exceptionLogDepth;
public LogAspect(String serviceName, Long expireMinutes, Integer exceptionLogDepth) {
this.serviceName = serviceName;
this.expireMinutes = expireMinutes;
this.exceptionLogDepth = exceptionLogDepth;
this.executorService = Executors.newSingleThreadExecutor(
new ThreadFactoryBuilder().setNameFormat("LogAspect-" + this.serviceName + "-%d").build());
}
@Resource
private StringRedisTemplate stringRedisTemplate;
// 切点为feign接口的入口
@Pointcut("execution(* com.*.controller.*.*(..))")
private void pointcut() {
}
@Before(value = "pointcut() && args(apiRequest)")
public void beforeAdvice(ApiRequest<?> apiRequest) {
// 请求参数放入线程变量
threadLocal.set(apiRequest);
}
@Around("pointcut()")
public void around(ProceedingJoinPoint joinPoint) throws Throwable {
String methodName = joinPoint.getSignature().getName();
Object[] params = joinPoint.getArgs();
try {
joinPoint.proceed();
} catch (Exception e) {
String feignId = threadLocal.get().getRequestId();
// 异步写日志
executorService.execute(() -> {
LogRedisVO logRedisVO = new LogRedisVO();
logRedisVO.setParams(params);
// 异常名称
logRedisVO.setExceptionName(e.toString());
// 发生异常的原始方法
logRedisVO.setOriginMethodName(methodName);
logRedisVO.setCreateTime(new Date());
StackTraceElement[] stackTrace = e.getStackTrace();
Integer index = Math.min(exceptionLogDepth, stackTrace.length);
List<LogExceptionVO> logExceptionVOList = new ArrayList<>(index);
LogExceptionVO logExceptionVO;
for (int i = 0; i < index; i++) {
logExceptionVO = new LogExceptionVO();
// 发生异常的类
logExceptionVO.setClassName(stackTrace[i].getClassName());
// 发生异常的行数
logExceptionVO.setLineNumber(stackTrace[i].getLineNumber());
// 发生异常的方法
logExceptionVO.setExceptionMethodName(stackTrace[i].getMethodName());
logExceptionVOList.add(logExceptionVO);
}
logRedisVO.setLogExceptionVOList(logExceptionVOList);
// key为请求唯一标识 键值对为服务名-异常日志信息
stringRedisTemplate.opsForHash().put(feignId, serviceName, JSON.toJSONString(logRedisVO));
stringRedisTemplate.expire(feignId, expireMinutes, TimeUnit.MINUTES);
});
throw e;
}
}
}
在serviceA B C 中手动将两个切面进行注入
@Value("${spring.application.name}")
private String serverName;
@Value("${logAspect.expireMinutes}")
private Long expireMinutes;
@Value("${logAspect.exceptionLogDepth}")
private Integer exceptionLogDepth;
@Bean
public LogAspect logAspect() {
return new LogAspect(serverName, expireMinutes, exceptionLogDepth);
}
@Bean
public FeignAspect feignAspect() {
return new FeignAspect(serverName);
}
进下来进行测试，调用链路为A->B，B发生异常
@RestController
public class ServiceAController {
@Autowired
private ServiceBFeign serviceBFeign;
@PostMapping("/testLog")
public void testLog(@RequestBody ApiRequest request) {
serviceBFeign.testLog(request);
}
}
----------------------------------------------------------
@RestController
public class ServiceBController implements ServiceBFeign {
@Autowired
private ServiceCFeign serviceCFeign;
@Override
public String testLog(ApiRequest apiRequest) {
if (1 == 1) {
throw new RuntimeException();
}
return "success";
}
}
postman请求后发生异常后使用log-service提供的接口进行查看，返回的异常日志如下
[
[{
"serviceName": "ServiceA",
"logRedisVO": {
"exceptionName": "feign.FeignException: status 500 reading ServiceBFeign#testLog(ApiRequest)",
"originMethodName": "testLog",
"logExceptionVOList": [{
"className": "feign.FeignException",
"lineNumber": 78,
"exceptionMethodName": "errorStatus"
}],
"createTime": "2021-08-14 16:24:54",
"params": [{
"requestId": "origin-serverName:ServiceA:481cabc0-a",
"body": "hello world"
}]
}
},
{
"serviceName": "ServiceB",
"logRedisVO": {
"exceptionName": "java.lang.RuntimeException",
"originMethodName": "testLog",
"logExceptionVOList": [{
"className": "com.serviceb.controller.ServiceBController",
"lineNumber": 23,
"exceptionMethodName": "testLog"
},
{
"className": "com.serviceb.controller.ServiceBController$$FastClassBySpringCGLIB$$bcd3b687",
"lineNumber": -1,
"exceptionMethodName": "invoke"
}
],
"createTime": "2021-08-14 16:24:54",
"params": [{
"requestId": "origin-serverName:ServiceA:481cabc0-a",
"body": "hello world"
}]
}
}
]
]
从requestId中还可以看出该次请求的入口服务为ServiceA。最后测试一下三个服务间发生调用发生异常的日志输出。
[
[{
"serviceName": "ServiceC",
"logRedisVO": {
"exceptionName": "java.lang.RuntimeException",
"originMethodName": "testLogThird",
"logExceptionVOList": [{
"className": "com.servicec.controller.ServiceCController",
"lineNumber": 19,
"exceptionMethodName": "testLogThird"
},
{
"className": "com.servicec.controller.ServiceCController$$FastClassBySpringCGLIB$$66a13189",
"lineNumber": -1,
"exceptionMethodName": "invoke"
},
{
"className": "org.springframework.cglib.proxy.MethodProxy",
"lineNumber": 218,
"exceptionMethodName": "invoke"
}
],
"createTime": "2021-08-14 16:28:15",
"params": [{
"requestId": "origin-serverName:ServiceA:744cfb5c-7",
"body": "hello world"
}]
}
},
{
"serviceName": "ServiceA",
"logRedisVO": {
"exceptionName": "feign.FeignException: status 500 reading ServiceBFeign#testLogThird(ApiRequest)",
"originMethodName": "testLogThird",
"logExceptionVOList": [{
"className": "feign.FeignException",
"lineNumber": 78,
"exceptionMethodName": "errorStatus"
}],
"createTime": "2021-08-14 16:28:15",
"params": [{
"requestId": "origin-serverName:ServiceA:744cfb5c-7",
"body": "hello world"
}]
}
},
{
"serviceName": "ServiceB",
"logRedisVO": {
"exceptionName": "feign.FeignException: status 500 reading ServiceCFeign#testLogThird(ApiRequest)",
"originMethodName": "testLogThird",
"logExceptionVOList": [{
"className": "feign.FeignException",
"lineNumber": 78,
"exceptionMethodName": "errorStatus"
},
{
"className": "feign.codec.ErrorDecoder$Default",
"lineNumber": 93,
"exceptionMethodName": "decode"
}
],
"createTime": "2021-08-14 16:28:15",
"params": [{
"requestId": "origin-serverName:ServiceA:744cfb5c-7",
"body": "hello world"
}]
}
}
]
]
每个服务的异常日志都可以根据配置输出不同层级的堆栈信息。
总结
先说缺点，一基于切面的实现，execution表达式需要根据项目的结构进行调整，这个目前还没有找到配置化的办法。二存在代码的侵入性，所有的feign请求需要继承一个含有请求唯一标识的父类。三需要腾出一整层的redis进行日志的存储，方便全量日志的查询。最后说优点，实现简单，基础两个切面和Redis完成分布式日志的链路收集和展示，更适合从0到1的项目。
由于公司禁了github，源码留邮箱分享吧。