在生产环境下出现bug,都需要靠日志才能定位到问题的关键,而有效的日志往往能让你事半功倍。在生产并发访问情况下,日志纵横交错,那么如何快速找到你要看的日志呢?
    本章将介绍通过AOP使打印的每一条日志增加一个与业务相关的logId。

pom

1
2
3
4
5
<dependency>
<groupId>org.aspectj</groupId>
<artifactId>aspectjweaver</artifactId>
<version>1.7.4</version>
</dependency>

AOP环绕增强controller

    getUnique();没有给出具体实现,大家可以根据自己的业务需求,选择一个合适的值,比如用户id,流水号,都行。

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
package club.usql.core.aop;

import club.usql.core.enums.ResponseEnum;
import club.usql.core.facade.domain.vo.ResponseVO;
import org.apache.commons.lang3.StringUtils;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

import javax.servlet.http.HttpServletRequest;

/**
* @author far.liu
*/
@Aspect
@Component
@Order(0)
public class ApiLogAspect {

private static final Logger logger = LoggerFactory.getLogger(ApiLogAspect.class);

@Around("execution(public * club.usql..controller.*.*(..))")
public Object aroundApi(ProceedingJoinPoint pjp) throws Throwable {
String uri = StringUtils.EMPTY;
try {
Object[] args = pjp.getArgs();
HttpServletRequest request = getRequestObj();
uri = request.getRequestURI();

String unique = getUnique(args);// not implemented, user_id or seq_no
ThreadContext.put("unique", unique);

printRequest(uri, args);
Object result = pjp.proceed(args);
printResponse(uri, result);
return result;
} catch (Exception e) {
logger.error(e.getMessage(), e);
ResponseVO responseVO = new ResponseVO(ResponseEnum.UNAUTHORIZED);
printResponse(uri, responseVO);
return responseVO;
} finally {
// don't forget it
ThreadContext.clearAll();
}
}

private HttpServletRequest getRequestObj() {
return ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getRequest();
}

private void printRequest(String uri, Object[] args) {
logger.info(String.format("call uri:%s begin, reqParam:%s", uri, args.toString()));
}

private void printResponse(String uri, Object args) {
logger.info(String.format("call uri:%s end, respParam:%s", uri, args.toString()));
}
}

log4j2.xml

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
<configuration>
<Properties>
<Property name="LOG_HOME">e:/logs</Property>
</Properties>
<appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d %-5p [%t] [unique:%X{unique}] %C (%F:%L) %m%n" />
</Console>
</appenders>

<loggers>

<root level="DEBUG">
<appender-ref ref="Console" />
</root>
</loggers>
</configuration>

效果

1
2
2018-08-06 17:05:39,456 INFO  [thread-495] [unique:101660] club.usql.core.aop.ApiLogAspect(ApiLogAspect.java:56) call uri:/usql/test begin, reqParam:
2018-08-06 17:05:39,457 INFO [thread-495] [unique:101660] club.usql.core.aop.ApiLogAspect(ApiLogAspect.java:56) call uri:/usql/test end, respParam:

总结

    以上代码,能让你在本此请求中,所有打印的日志,会显示你设置的unique,你可以通过这个值获取到关于本次请求的日志,不用担心在并发的情况下要根据可能重复的线程号去定位。

彩蛋

less usql.log
  1. G -> 跳转到日志结尾
  2. g -> 跳转到日志开始
  3. /interest -> 从当前位置往下搜索interest
  4. ?interest -> 从当前位置往上搜索interest
tailf usql.log

    监听日志文件,有更新立即输出

grep interest -a5b5 usql.log >> test.log

    将usql.log中的interes上下5行,输出到test.log 中,grep不适用与已经压缩的日志文件,可以使用以下命令

1
gzip -dc usql.log.gz | grep interest