在分布式服务中追踪一次请求的日志是一件非常重要的事，本文提供一种利用logBack + log4j的方案来解决这个问题
最终要实现的目的是通过一个traceId，然后再ELK中找到这个traceId对应请求所有打印的日志
来，一步一步看
1.设计思路
多个系统服务同时需要依赖一套生成和读取traceId的方案，所以，我们首先需要搞一套依赖，用来管理traceId
不同服务引用后，当一个请求进入服务中，服务首先检测他有没有携带traceId，没有的话将traceId补上，并放入MDC中，该请求进入下一个服务时，将traceId携带
各个服务间打印日志使用统一的工具类进行打印，打印中从MDC中取出traceId并打印，然后由ELK搜集整理
2.生成和读取traceId的方案
生成traceId可以使用UUID来做全局唯一标识
生成的traceId放入MDC中，用来给所有打印日志的地方使用1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16/**
* 获取traceId
*/
public static String getTraceId() {
//获取
String traceId = MDC.get(TRACE_ID);
//如果traceId为空，则返回默认值
return StringUtils.isBlank(traceId) ? DEFAULT_TRACE_ID : traceId;
}
/**
* 生成traceId
*/
public static String gentraceId() {
return UUID.randomUUID().toString().replaceAll("-","");
}
3.何时将traceId记录到请求中
在服务中定义WebFilter，读取到request后检查是否携带traceId，未携带代表该服务是这个请求的入口服务，需要将traceId设置到请求中
已携带代表是从上游服务下来的请求，直接使用该traceId来进行打印
这里我们需要用到一个工具叫MDC，他提供了静态方法可以用来做线程间隔离的数据存储，底层是封装了一套threadLocal，这个会在接下来分析1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31@WebFilter(urlPatterns = "/*", filterName = "traceIdFilter")
@Order(1)
public class Filter0_traceIdFilter extends GenericFilterBean {
@Override
public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
logger.info("traceIdFilter before");
//traceId初始化
initTraceId((HttpServletRequest) servletRequest);
//执行后续过滤器
filterChain.doFilter(servletRequest,servletResponse);
logger.info("traceIdFilter after");
}
/**
* traceId初始化
*/
private void initTraceId(HttpServletRequest request) {
//尝试获取http请求中的traceId
String traceId = request.getParameter("traceId");
//如果当前traceId为空或者为默认traceId，则生成新的traceId
if (StringUtils.isBlank(traceId) || traceIdUtil.defaultTraceId(traceId)){
traceId = traceIdUtil.gentraceId();
}
//设置traceId
traceIdUtil.setTraceId(traceId);
}
}
bounce.MDC分析MDC提供了threadLocal的封装，但封装并不存在于MDC这个类中，而是存在于MDCAdapterMDCAdapter是一个接口，像logback就提供了一个实现，叫做LogbackMDCAdapter
在MDC初始化中，会先去寻找是否有实现，没有MDCAdapter的实现的话会用默认的NOPMDCAdapter来做实现，其实就是什么也没做
MDCAdapter提供了get(),put(),remove(),clear(),getCopyOfContextMap(),setContextMap()方法
在LogbackMDCAdapter中，分别对这些方法进行了实现，其实很简单，就是一些增删改查
在LogbackMDCAdapter里定义了两个常量WRITE_OPERATION, MAP_COPY_OPERATION，并且有一个threadLocal来记录上一次的操作类型，
在增删中会将操作类型设置为WRITE_OPERATION，在获取keys的方法中将操作类型记为MAP_COPY_OPERATION，作者的意图是用这个操作来判断一次的操作类型，如果是拿全量map（getPropertyMap()方法）
则要保持被拿走的map是不变的，新的写操作需要写到新map里
按照代码的逻辑，写操作(put(),remove())都会去判断是不是该把值写到新的map里，判断的依据上一次操作是不是MAP_COPY_OPERATION，也就是是不是有人拿走了map，如果有人拿走了map就要写到新map里，没有的话就继续写到旧map中
4.怎么打印
日志打印工具类需要将traceId打印到日志中，利用filter中的向MDC中存储的traceId，来进行打印MDC的线程隔离性保证了同一个线程在代码的不同位置拿到的数据都一致1
2
3//打印你要的内容
String traceId = MDC.get(TRACE_ID);
log.info(traceId + xxx);
5.在ELK中查询
可以通过日志中打印的关键字或者其他一些信息定位到某一段日志代码，找到traceId并在ELK中搜索，就可以检索到所有这个请求下的日志
6.如果有需要的话。。。
使用这种方式既简单又高效的完成了日志打印，但是不是还少了些什么？比如接口的时间统计？调用方？
这些都是可以提高问题查询效率的一个方式，也是可以增加在ELK中的检索类别，可以更快的帮助你定位到需要的日志
下面可以提供一种方式，利用切面切所有的controller，从切点用取出需要的数据，然后进行打印，但是别忘了要在保证性能和安全性的角度下1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140@Aspect
@Component
@Slf4j
public class SysLogAspect {
@Pointcut("bean(*Controller)")
public void logPointCutRestController() {
}
/**
* RestController切面
* @param joinPoint
* @return
* @throws Throwable
*/
@Around("logPointCutRestController()")
public Object restControllerAspect(ProceedingJoinPoint joinPoint) throws Throwable {
return aroundInternal(joinPoint);
}
public Object aroundInternal(ProceedingJoinPoint joinPoint) throws Throwable {
HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getRequest();
long beginTime = System.currentTimeMillis();
//返回值
Object returnValue = null;
String param = "";
String apiName = "";
String className = "";
String methodName = "";
String functionName = "";
long time = 0;
String status = "";
String code = "";
String message = "";
try {
MethodSignature signature = (MethodSignature) joinPoint.getSignature();
Method method = signature.getMethod();
//只打印注解为RequestMapping类并且没有IgnoreSysLog注解的方法
boolean needLog = false;
Annotation[] annotations = method.getAnnotations();
if (Objects.nonNull(annotations)) {
boolean hasMappingAnnotation = Arrays.stream(annotations)
.anyMatch(annotation -> (
annotation instanceof RequestMapping
|| annotation instanceof GetMapping
|| annotation instanceof PostMapping));
boolean hasIgnoreSysLogAnnotation = Arrays.stream(annotations)
.anyMatch(annotation -> (annotation instanceof IgnoreSysLog));
//是mapping并且没有IgnoreSysLog注解，需要打印
needLog = hasMappingAnnotation && (!hasIgnoreSysLogAnnotation);
}
if (!needLog) {
return joinPoint.proceed();
}
//请求的 类名、方法名
className = joinPoint.getTarget().getClass().getName();
String simpleName = joinPoint.getTarget().getClass().getSimpleName();
methodName = signature.getName();
SysLog sysLog = method.getAnnotation(SysLog.class);
if (sysLog != null) {
//注解上的描述
apiName = sysLog.value();
}
functionName = simpleName + ":" + methodName;
//请求的参数
Object[] args = joinPoint.getArgs();
String[] paramNames = signature.getParameterNames();
Map paramMap = new HashMap<>();
for (int i = 0; i < args.length; i++) {
if (!(args[i] instanceof HttpServletRequest)) {
//支持文件上传
if (args[i] instanceof MultipartFile[]) {
MultipartFile[] files = (MultipartFile[]) args[i];
List<String> fileInfos = new ArrayList<>();
for (MultipartFile file : files) {
String nameFiled = file.getName();
String fileName = file.getOriginalFilename();
long kByte = file.getSize() / 1000;
fileInfos.add("[" + nameFiled + ":" + fileName + ", size=" + kByte + "kb]");
}
paramMap.put(paramNames[i], String.join(",", fileInfos));
} else {
paramMap.put(paramNames[i], args[i]);
}
}
}
param = JacksonUtil.toJsonString(paramMap);
} catch (Exception e) {
//吞掉业务异常以外的异常，不影响业务正常进行
log.warn("SysLogAspect.around Exception:",e);
}
try {
//连接点：被切的方法的代码还会继续执行，所以当业务代码出现异常的时候会抛到这里来，此异常不能自己消化，需要继续往外抛。
returnValue = joinPoint.proceed();
} catch (Exception e) {
status = String.valueOf(ComResponse.ERROR_STATUS);
if (e instanceof BizException) {
code = String.valueOf(((BizException) e).getCode());
message = ((BizException) e).getMsg();
} else if (e instanceof RemoteAccessException) {
code = String.valueOf(((RemoteAccessException) e).getCode());
message = ((RemoteAccessException) e).getMsg();
} else {
code = String.valueOf(ResponseCodeEnums.SYSTEM_ERROR_CODE.getCode());
message = JacksonUtil.toJsonString(e);
}
time = System.currentTimeMillis() - beginTime;
log.error(xxx);
//业务异常需要继续往外抛出，抛给统一异常处理器处理异常。否则当业务发生异常了，异常信息都会被吞掉。
throw e;
}
try {
//接口耗时
time = System.currentTimeMillis() - beginTime;
//从接口返回值判断接口调用状态
if (Objects.nonNull(returnValue)) {
//伪代码
}
log.info(xxx);
} catch (Exception e) {
status = String.valueOf(ComResponse.ERROR_STATUS);
code = String.valueOf(ResponseCodeEnums.SYSTEM_ERROR_CODE.getCode());
message = JacksonUtil.toJsonString(e);
//当try里面的代码快出现异常，需要自己把异常消化掉不然会影响业务的正常进行。
log.error(xxx);
}
return returnValue;
}
}