Logback 快速定位用户在一次请求中的所有日志

问题描述

最近经常做线上问题的排查，而排查问题用得最多的方式是查看日志，但是在现有系统中，各种无关日志穿行其中，导致我没办法快速的找出用户在一次请求中所有的日志。

问题分析

我们没办法快速定位用户在一次请求中对应的所有日志，或者说是定位某个用户操作的所有日志，那是因为我们在输出的日志的时候没把请求的唯一标示或者说是用户身份标示输出到我们的日志中，导致我们没办法根据一个请求或者用户身份标示来做日志的过滤。所以我们在记录日志的是后把请求的唯一标示（requestId）或者身份标示（userId）记录到日志中这个问题就可以得到很好的解决了。

解决方案

在每次请求的时候，或者是方法执行，或者是任务触发，为每一个请求或方法的执行打上统一的标识，这样就可以根据唯一请求标示获取全部的日志信息

我们使用Logback的MDC机制，日志模板中加入requestId格式。在日志输出格式中指定输出requestId。如：

[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%X{sessionId}] [%thread] %-5level %logger{36} - %msg%n

这种方式工作量小，代码侵入小，易扩展，但是可控粒度低。

方案说明

这种方案很简单，也很容易实现，就是在输出日志的时候多输出一个参数，如：

[2018-11-23 13:51:38.403] [5216149e7fae45019a666775f2fe89a7] [http-bio-8080-exec-6] INFO  com.logback.dao.impl.LogBackDaoImpl - 保存用户成功---LogBackDao

执行步骤

我们在这里使用一个servlet模拟一个用户保存的过程，使用MVC的设计模式分层，view,service.dao
直接上代码

服务端

dao部分

public class LogBackDaoImpl implements LogBackDao {Logger logger = LoggerFactory.getLogger(LogBackDaoImpl.class);public void saveUser(User user) {logger.info("保存用户成功---LogBackDao");}
}

service 部分

public class LogbackServiceImpl implements LogbackService{private LogBackDao logBackDao;Logger logger = LoggerFactory.getLogger(LogbackServiceImpl.class);public void savaUser(User user) {logBackDao.saveUser(user);logger.info("调用LogBackDao保存用户成功");}public LogBackDao getLogBackDao() {return logBackDao;}public void setLogBackDao(LogBackDao logBackDao) {this.logBackDao = logBackDao;}}

controller 部分

/*** Servlet implementation class LogBackController*/
public class LogBackController extends HttpServlet {private static final long serialVersionUID = 1L;Logger logger = LoggerFactory.getLogger(LogBackController.class);private final static String SESSION_KEY = "sessionId";/*** Default constructor. */public LogBackController() {// TODO Auto-generated constructor stubW}/*** @see HttpServlet#doGet(HttpServletRequest request, HttpServletResponse response)*/protected void doGet(HttpServletRequest request, HttpServletResponse response) throws ServletException, IOException {// 设置SessionIdString token = UUID.randomUUID().toString().replace("-", "");MDC.put(SESSION_KEY, token);logger.info("请求到来");LogBackDao logBackDao = new LogBackDaoImpl();LogbackServiceImpl logbackService = new LogbackServiceImpl();logbackService.setLogBackDao(logBackDao);String username = request.getParameter("username");String password = request.getParameter("password");User user = new User();user.setPassword(password);user.setUsername(username);logbackService.savaUser(user);logger.info("请求请求结束");MDC.remove(SESSION_KEY);}/*** @see HttpServlet#doPost(HttpServletRequest request, HttpServletResponse response)*/protected void doPost(HttpServletRequest request, HttpServletResponse response) throws ServletException, IOException {// TODO Auto-generated method stubdoGet(request, response);}}

logback.xml

<configuration><appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">  <encoder>  <pattern>[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%X{sessionId}] [%thread] %-5level %logger{36} - %msg%n</pattern>  </encoder>  </appender> <root level="DEBUG"><appender-ref ref="STDOUT" /></root>
</configuration>

服务端部分到此完成

客户端

使用线程调用服务100次查看服务端结果

RequestThread 代码

package com.logback;import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.io.InputStream;
import java.net.HttpURLConnection;
import java.net.URL;public class RequestThread extends Thread{@Overridepublic void run() {request();}public static void request() {String path = "http://localhost:8080/logback/LogBackController?username=aaa&password=bbb";try {URL url = new URL(path.trim());// 打开连接HttpURLConnection urlConnection = (HttpURLConnection) url.openConnection();if (200 == urlConnection.getResponseCode()) {// 得到输入流InputStream is = urlConnection.getInputStream();ByteArrayOutputStream baos = new ByteArrayOutputStream();byte[] buffer = new byte[1024];int len = 0;while (-1 != (len = is.read(buffer))) {baos.write(buffer, 0, len);baos.flush();}System.out.println(baos.toString("utf-8"));}} catch (IOException e) {e.printStackTrace();}}
}

LogbackTest

public class LogbackTest {public static void main(String[] args) {ExecutorService threadPool = Executors.newFixedThreadPool(5);for (int i = 0; i < 100; i++) {RequestThread thread = new RequestThread();threadPool.execute(thread);}}
}

只要执行LogbackTest 的main方法就可以得到日志，日志如下：

[2018-11-23 13:51:38.332] [786a5879d7414c09b3208b5efa86f858] [http-bio-8080-exec-9] INFO  c.l.controller.LogBackController - 请求到来
[2018-11-23 13:51:38.332] [ea0757a9c56b4de2a25b5fd92d464741] [http-bio-8080-exec-6] INFO  c.l.controller.LogBackController - 请求到来
[2018-11-23 13:51:38.332] [117903b518c248739cf0e974a30b0ea2] [http-bio-8080-exec-5] INFO  c.l.controller.LogBackController - 请求到来
[2018-11-23 13:51:38.332] [18d3fd3681264e38803cd1d03bec1dd9] [http-bio-8080-exec-7] INFO  c.l.controller.LogBackController - 请求到来
[2018-11-23 13:51:38.332] [d54718d4e14a4b9aba10ce2ac589e2a0] [http-bio-8080-exec-8] INFO  c.l.controller.LogBackController - 请求到来
[2018-11-23 13:51:38.340] [d54718d4e14a4b9aba10ce2ac589e2a0] [http-bio-8080-exec-8] INFO  com.logback.dao.impl.LogBackDaoImpl - 保存用户成功---LogBackDao
[2018-11-23 13:51:38.340] [d54718d4e14a4b9aba10ce2ac589e2a0] [http-bio-8080-exec-8] INFO  c.l.service.impl.LogbackServiceImpl - 调用LogBackDao保存用户成功
[2018-11-23 13:51:38.340] [786a5879d7414c09b3208b5efa86f858] [http-bio-8080-exec-9] INFO  com.logback.dao.impl.LogBackDaoImpl - 保存用户成功---LogBackDao
[2018-11-23 13:51:38.340] [d54718d4e14a4b9aba10ce2ac589e2a0] [http-bio-8080-exec-8] INFO  c.l.controller.LogBackController - 请求请求结束
[2018-11-23 13:51:38.340] [ea0757a9c56b4de2a25b5fd92d464741] [http-bio-8080-exec-6] INFO  com.logback.dao.impl.LogBackDaoImpl - 保存用户成功---LogBackDao
[2018-11-23 13:51:38.340] [ea0757a9c56b4de2a25b5fd92d464741] [http-bio-8080-exec-6] INFO  c.l.service.impl.LogbackServiceImpl - 调用LogBackDao保存用户成功
[2018-11-23 13:51:38.340] [ea0757a9c56b4de2a25b5fd92d464741] [http-bio-8080-exec-6] INFO  c.l.controller.LogBackController - 请求请求结束
[2018-11-23 13:51:38.340] [18d3fd3681264e38803cd1d03bec1dd9] [http-bio-8080-exec-7] INFO  com.logback.dao.impl.LogBackDaoImpl - 保存用户成功---LogBackDao
[2018-11-23 13:51:38.341] [18d3fd3681264e38803cd1d03bec1dd9] [http-bio-8080-exec-7] INFO  c.l.service.impl.LogbackServiceImpl - 调用LogBackDao保存用户成功
[2018-11-23 13:51:38.341] [18d3fd3681264e38803cd1d03bec1dd9] [http-bio-8080-exec-7] INFO  c.l.controller.LogBackController - 请求请求结束
[2018-11-23 13:51:38.340] [117903b518c248739cf0e974a30b0ea2] [http-bio-8080-exec-5] INFO  com.logback.dao.impl.LogBackDaoImpl - 保存用户成功---LogBackDao
[2018-11-23 13:51:38.340] [786a5879d7414c09b3208b5efa86f858] [http-bio-8080-exec-9] INFO  c.l.service.impl.LogbackServiceImpl - 调用LogBackDao保存用户成功
[2018-11-23 13:51:38.342] [117903b518c248739cf0e974a30b0ea2] [http-bio-8080-exec-5] INFO  c.l.service.impl.LogbackServiceImpl - 调用LogBackDao保存用户成功

logback MDC线上问题快速定位神器相关推荐

快速了解 Java 线上问题快速诊断神器 Arthas
快速了解 Java 线上问题快速诊断神器 Arthas 1.什么是 Arthas Arthas 是 Alibaba开源的一款 Java 诊断工具,能够查看 Java 应用的线程状态.JVM 信息等,支 ...
一文带你快速了解 Java 线上问题快速诊断神器 Arthas
文章目录一.什么是 Arthas 二.特性一览三.Arthas 能为你做什么? 四.快速安装 1.前提条件 2.一键安装五.快速使用 1.启动脚本并连接进程 2.启动 jar 包并连接进程六. ...
线上故障快速定位及恢复
Java线程堆栈 Linux jstack命令 jstack 7756(Java进程号) > java.stack Linux kill命令 kill -3 7756(Java进程号) 向JVM ...
Probe：Android线上OOM问题定位组件
配送骑手端App是骑手用于完成配送履约的应用,帮助骑手完成接单.到店.取货及送达,提供各种不同的运力服务,也是整个外卖闭环中的重要节点.由于配送业务的特性,骑手App对于应用稳定性的要求非常高,体现A ...
pycharm 最上面的快速定位标签_受用一生的高效 PyCharm 使用技巧（四）
原标题:受用一生的高效 PyCharm 使用技巧(四) 大家好,距离最近一篇 PyCharm 使用技巧的文章已经过去一月有余,最近虽然也比较忙,但是一直没忘记录下一些我觉得值得分享的小tip.这个系列 ...
线上问题分析诊断神器 Arthas（阿尔萨斯）
1.Arathas 介绍官方文档:https://arthas.aliyun.com/doc/ GitHub 地址:https://github.com/alibaba/arthas Arthas ...
Java线上接口耗时分析神器 Arthas
文章目录背景问题 Arthas github地址官网文档地址: 说明安装运行Arthas trace命令的使用统计时间不准确问题总结背景有时候我们在对线上接口作性能优化的时候需要找出 ...
语音会议源代码_线上语音群聊神器！开会开黑都好用，免注册、免安装，还免费...
开发者,是移动互联网生态中不可忽视的中坚力量,他们坚韧不拔且极具勇气,他们坚持正确的价值观,并坚信创新能够创造价值. AppSo 也一样,我们希望那些具备可贵品质的开发者们,和他们带着闪光点的产品,能 ...
JB的测试之旅-关于线上问题的看法
说明本文以文字为主,会讲解到理论及具体工作思路,因当时没有保存代码,因此代码部分不贴,也懒得写了: 前言这篇文章修改很多次,各种推倒重写,原因是,一开始只想写自己做过的东西,但是写着写着,觉得太局 ...
javacore分析工具_线上死锁定位分析
" 记录一次线上死锁的定位分析." 昨晚睡觉前提了点代码到 jfoa(https://github.com/JavaFamilyClub/jfoa) 怎么也没想到导致 ...

logback MDC线上问题快速定位神器