Logback 背景
Logback是由log4j创始人设计的另一个开源日志组件,官方网站: http://logback.qos.ch。它当前分为下面下个模块:
- logback-core:其它两个模块的基础模块
- logback-classic:它是log4j的一个改良版本,同时它完整实现了slf4j API使你可以很方便地更换成其它日志系统如log4j或JDK14 Logging
- logback-access:访问模块与Servlet容器集成提供通过Http来访问日志的功能
▐ 普通debug日志
▐ SQL执行日志
Logback 配置案例
日志级别排序为: TRACE < DEBUG < INFO < WARN < ERROR
- %d:表示日期
- %n:换行
- %thread:表示线程名
- %level:日志级别
- %msg:日志消息
- %file:表示文件名
- %class: 表示文件名
- %logger:Java类名(含包名,这里设定了36位,若超过36位,包名会精简为类似a.b.c.JavaBean)
- %line:Java类的行号
注意:
%-4relative %d{yyyy-MM-dd HH:mm:ss.SSS} [%thread][%X{TRACE_ID}] %-5level %logger{100}.%M\(%line\) - %msg%n
在logback中,%relative表示自应用程序启动以来打印相对时间戳(以毫秒为单位). %-4只是元素的对齐方式.
▐ 案例
34524872021-08-0315:19:36.940 [thread-monitor-daemon][] WARNcom.xxxx.common.util.MonitorLogger.warn(27) -发现超时线程notify-replay-consumer...
由于案例中是守护线程thread-monitor-daemon,所以不记录链路ID。
对在系统设计的时候对于线程的命名规范也是有约束的
这里就不做详细展开后续有机会会分享。
回归正题比如下面的例子中记录了请求的链路ID
190069892021-08-0422:35:25.776 [http-nio-0.0.0.0-8010-exec-10][1fc8pebmgwukw863w2p342rp2936a3r157w0:0:] INFOcom.xxx.framework.eureka.core.listener.EurekaStateChangeListener.listen(58) -
服务实例[XX-PAAS]注册成功,当前服务器已注册服务实例数量[3]
对于上图中显示的系统启动时间、当前时间、当前线程、对应路径按照logback官方配置就可以逐步完善对于的日志信息,但是对于链路ID的生成写入就需要特殊处理。
链路ID设计
对于链路追踪设计我个人比较喜欢两种方案
▐ 第一种
在每一次请求中链路编号(traceId)、单元编号(spanId)都是通过HttpHeader的方式进行传递,日志的起始位置会主动生成traceId、spanId,而起始位置的Parent SpanId则是不存在的,值为null。
这样每次通过restTemplate、Openfeign的形式访问其他服务的接口时,就会携带起始位置生成的traceId、spanId到下一个服务单元。
▐ 第二种
在每一次请求中链路编号(traceId),没经过一次微服务对于深度(Deep)加1
publicstaticclassThreadTraceListenerimplementsThreadListener { publicvoidonThreadBegin(HttpServletRequestrequest) { StringtraceToken=ThreadLocalUtil.getTranVar(TRACE_ID); StringfromServer=ThreadLocalUtil.getTranVar(FROM_SERVER); intdeep; StringtraceId; if (StringUtils.isBlank(traceToken)) { traceId=IDGenerator.generateID(); deep=0; traceToken=StringHelper.join(traceId, ":0"); } else { intindex=traceToken.lastIndexOf(':'); traceId=traceToken.substring(0, index); deep=Integer.valueOf(traceToken.substring(index+1)); } ThreadLocalUtil.setLocalVar(TRACE_ID, traceId); ThreadLocalUtil.setLocalVar(TRACE_DEEP, deep); ThreadLocalUtil.setTranVar(TRACE_ID, StringHelper.join(traceId, ":", deep+1)); ThreadLocalUtil.setLocalVar(FROM_SERVER, fromServer); ThreadLocalUtil.setTranVar(FROM_SERVER, getCurrentServer()); MDC.put(TRACE_ID, StringHelper.join(traceToken, ":", fromServer)); } publicvoidonThreadEnd(HttpServletRequestrequest) { MDC.remove(TRACE_ID); } }
针对请求拦截
protectedvoiddoFilterInternal(HttpServletRequestrequest, HttpServletResponseresponse, FilterChainchain) throwsServletException, IOException { longstartTime=System.currentTimeMillis(); // 从Header中装载传递过来的变量Map<String, Object>tranVar=newHashMap<String, Object>(); Enumeration<String>headers=request.getHeaderNames(); while (headers.hasMoreElements()) { Stringkey=headers.nextElement(); if (!StringUtils.isEmpty(key) &&key.startsWith(ThreadLocalUtil.TRAN_PREFIX)) { tranVar.put(key.substring(ThreadLocalUtil.TRAN_PREFIX.length()), request.getHeader(key)); } } ThreadLocalHolder.begin(tranVar, request); try { if (isGateway) { response.addHeader("X-TRACE-ID", TraceUtil.getTraceId()); } // 检查RPC调用深度checkRpcDeep(request, response); // 业务处理chain.doFilter(request, response); // 记录RPC调用次数logRpcCount(request, response); } catch (Throwableex) { // 错误处理Response<?>result=ExceptionUtil.toResponse(ex); Determinedetermine=ExceptionUtil.determineType(ex); ExceptionUtil.doLog(result, determine.getStatus(), ex); response.setStatus(determine.getStatus().value()); response.setCharacterEncoding("UTF-8"); response.setContentType(MediaType.APPLICATION_JSON_UTF8_VALUE); response.getWriter().write(JsonUtil.toJsonString(result)); } finally { try { doMonitor(request, response, startTime); if (TraceUtil.isTraceLoggerOn()) { log.warn(StringHelper.join( "TRACE-HTTP-", request.getMethod(), " URI:", request.getRequestURI(), ", dt:", System.currentTimeMillis() -startTime, ", rpc:", TraceUtil.getRpcCount(), ", status:", response.getStatus())); } elseif (log.isTraceEnabled()) { log.trace(StringHelper.join(request.getMethod(), " URI:", request.getRequestURI(), ", dt:", System.currentTimeMillis() -startTime, ", rpc:", TraceUtil.getRpcCount(), ", status:", response.getStatus())); } } finally { ThreadLocalHolder.end(request); } } }
若有收获,就点个赞吧
更多技术分享可关注微信公众号:码农架构
专注于系统架构、高可用、高性能、高并发类技术分享