在日常的后端开发工作中,最常见的操作之一就是看日志排查问题,对于大项目一般使用类似ELK的技术栈统一搜集日志,小项目就直接把日志打印到日志文件。那不管对于大项目或者小项目,查看日志都需要通过某个关键字进行搜索,从而快速定位到异常日志的位置来进一步排查问题。
对于后端初学者来说,日志的关键字可能就是直接打印某个业务的说明加上业务标识,如果出现问题直接搜索对应的说明或者标识。例如下单场景,可能就直接打印:创建订单,订单编号:xxxx,当有问题的时候,则直接搜索订单编号或者创建订单。在这种方式下,经常会搜索出多条日志,增加问题的排查时长。
所以,今天我们就来说一说这个关键字的设计,这里我们使用RequestId进行精确定位问题日志的位置从而解决问题。
目标: 帮助开发快速定位日志位置
思路:当前端进行一次请求的时候,在进行业务逻辑处理之前我们需要生成一个唯一的RequestId,在业务逻辑处理过程中涉及到日志打印我们都需要带上这个RequestId,最后响应给前端的数据结构同样需要带上RequestId。 这样,每次请求都会有一个RequestId,当某个接口异常则通过前端反馈的RequestId,后端即可快速定位异常的日志位置。
总结下我们的需求:
public class RequestIdUtils {
private static final ThreadLocal<UUID> requestIdHolder = new ThreadLocal<>();
private RequestIdUtils() {
}
public static void generateRequestId() {
requestIdHolder.set(UUID.randomUUID());
}
public static void generateRequestId(UUID uuid) {
requestIdHolder.set(uuid);
}
public static UUID getRequestId() {
return (UUID)requestIdHolder.get();
}
public static void removeRequestId() {
requestIdHolder.remove();
}
}
因为我们一次请求会生成一次RequestId,并且RequestId唯一,所以这里我们使用使用UUID来生成RequestId,并且用ThreadLocal进行存储。
@Aspect
@Order
@Slf4j
public class ApiMessageAdvisor {
@Around("execution(public * org.anyin.gitee.shiro.controller..*Controller.*(..))")
public Object invokeAPI(ProceedingJoinPoint pjp) {
String apiName = this.getApiName(pjp);
// 生成RequestId
String requestId = this.getRequestId();
// 配置日志文件打印 REQUEST_ID
MDC.put("REQUEST_ID", requestId);
Object returnValue = null;
try{
// 打印请求参数
this.printRequestParam(apiName, pjp);
returnValue = pjp.proceed();
// 处理RequestId
this.handleRequestId(returnValue);
}catch (BusinessException ex){
// 业务异常
returnValue = this.handleBusinessException(apiName, ex);
}catch (Throwable ex){
// 系统异常
returnValue = this.handleSystemException(apiName, ex);
}finally {
// 打印响应参数
this.printResponse(apiName, returnValue);
RequestIdUtils.removeRequestId();
MDC.clear();
}
return returnValue;
}
/**
* 处理系统异常
* @param apiName 接口名称
* @param ex 系统异常
* @return 返回参数
*/
private Response handleSystemException(String apiName, Throwable ex){
log.error("@Meet unknown error when do " + apiName + ":" + ex.getMessage(), ex);
Response response = new Response(BusinessCodeEnum.UNKNOWN_ERROR.getCode(), BusinessCodeEnum.UNKNOWN_ERROR.getMsg());
response.setRequestId(RequestIdUtils.getRequestId().toString());
return response;
}
/**
* 处理业务异常
* @param apiName 接口名称
* @param ex 业务异常
* @return 返回参数
*/
private Response handleBusinessException(String apiName, BusinessException ex){
log.error("@Meet error when do " + apiName + "[" + ex.getCode() + "]:" + ex.getMsg(), ex);
Response response = new Response(ex.getCode(), ex.getMsg());
response.setRequestId(RequestIdUtils.getRequestId().toString());
return response;
}
/**
* 填充RequestId
* @param returnValue 返回参数
*/
private void handleRequestId(Object returnValue){
if(returnValue instanceof Response){
Response response = (Response)returnValue;
response.setRequestId(RequestIdUtils.getRequestId().toString());
}
}
/**
* 打印响应参数信息
* @param apiName 接口名称
* @param returnValue 返回值
*/
private void printResponse(String apiName, Object returnValue){
if (log.isInfoEnabled()) {
log.info("@@{} done, response: {}", apiName, JSONUtil.toJsonStr(returnValue));
}
}
/**
* 打印请求参数信息
* @param apiName 接口名称
* @param pjp 切点
*/
private void printRequestParam(String apiName, ProceedingJoinPoint pjp){
Object[] args = pjp.getArgs();
if(log.isInfoEnabled() && args != null&& args.length > 0){
for(Object o : args) {
if(!(o instanceof HttpServletRequest) && !(o instanceof HttpServletResponse) && !(o instanceof CommonsMultipartFile)) {
log.info("@@{} started, request: {}", apiName, JSONUtil.toJsonStr(o));
}
}
}
}
/**
* 获取RequestId
* 优先从header头获取,如果没有则自己生成
* @return RequestId
*/
private String getRequestId(){
// 因为如果有网关,则一般会从网关传递过来,所以优先从header头获取
ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
if(attributes != null && StringUtils.hasText(attributes.getRequest().getHeader("x-request-id"))) {
HttpServletRequest request = attributes.getRequest();
String requestId = request.getHeader("x-request-id");
UUID uuid = UUID.fromString(requestId);
RequestIdUtils.generateRequestId(uuid);
return requestId;
}
UUID existUUID = RequestIdUtils.getRequestId();
if(existUUID != null){
return existUUID.toString();
}
RequestIdUtils.generateRequestId();
return RequestIdUtils.getRequestId().toString();
}
/**
* 获取当前接口对应的类名和方法名
* @param pjp 切点
* @return apiName
*/
private String getApiName(ProceedingJoinPoint pjp){
String apiClassName = pjp.getTarget().getClass().getSimpleName();
String methodName = pjp.getSignature().getName();
return apiClassName.concat(":").concat(methodName);
}
}
简单说明:
<contextName>logback</contextName>
<springProperty scope="context" name="level" source="logging.level.root"/>
<springProperty scope="context" name="path" source="logging.file.path"/>
<Appender name="console" class="ch.qos.logback.core.ConsoleAppender">
<Target>System.out</Target>
<filter class="ch.qos.logback.classic.filter.ThresholdFilter" >
<level>DEBUG</level>
</filter>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%X{REQUEST_ID}] [%thread] [%-5level] [%logger{0}:%L] : %msg%n</pattern>
</encoder>
</appender>
<appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${path}</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${path}.%d{yyyy-MM-dd}.zip</fileNamePattern>
</rollingPolicy>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%X{REQUEST_ID}] [%thread] [%-5level] [%logger{0}:%L] : %msg%n</pattern>
</encoder>
</appender>
<root level="${level}">
<appender-ref ref="console"/>
<appender-ref ref="file"/>
</root>
这里是一个简单的日志格式配置文件,主要是关注[%X{REQUEST_ID}], 这里主要是把RequestId在日志文件中打印出来
public class MdcExecutor implements Executor {
private Executor executor;
public MdcExecutor(Executor executor) {
this.executor = executor;
}
@Override
public void execute(Runnable command) {
final String requestId = MDC.get("REQUEST_ID");
executor.execute(() -> {
MDC.put("REQUEST_ID", requestId);
try {
command.run();
} finally {
MDC.remove("REQUEST_ID");
}
});
}
}
这里是一个简单的代理模式,代理了Executor,在真正执行的run方法之前设置RequestId到日志系统中,这样子异步线程的日志同样可以打印我们想要的RequestId
通过以上骚操作,同学,你知道怎么使用RequestId看日志了吗?