一、整体架构概览
1.1 请求处理流程
HTTP请求
↓
[Tomcat线程池] 分配一个线程处理请求
↓
[TraceIdFilter] 拦截请求，设置MDC
↓
[Controller/Service/Helper] 业务代码执行
↓
[Logger打印日志] 自动从MDC获取traceId
↓
[TraceIdFilter] 清理MDC
↓
响应返回，线程归还线程池
1.2 核心组件关系
┌─────────────────────────────────────────────────────────┐
│ HTTP请求处理 │
├─────────────────────────────────────────────────────────┤
│ TraceIdFilter (Filter层) │
│ ├─ 从请求头提取traceId │
│ ├─ 设置到MDC (线程本地存储) │
│ └─ 请求结束后清理MDC │
├─────────────────────────────────────────────────────────┤
│ MDC (Mapped Diagnostic Context) │
│ └─ ThreadLocal<Map<String, String>> │
│ └─ 存储: {"tid": "abc123", "EagleEye-TraceID": "abc123"} │
├─────────────────────────────────────────────────────────┤
│ Logback (日志框架) │
│ └─ Pattern: %X{tid} 从MDC读取值 │
├─────────────────────────────────────────────────────────┤
│ 业务代码 (Controller/Service/Helper) │
│ └─ logger.info("xxx") 自动包含traceId │
└─────────────────────────────────────────────────────────┘
二、从顶层到底层逐步剖析
2.1 第一层：HTTP请求与Servlet容器
2.1.1 HTTP请求的生命周期
// 当用户发起HTTP请求时
GET /api/summary/list HTTP/1.1
Host: example.com
X-Trace-Id: abc123def456 ← 前端传递的traceId（可选）
关键点：
- HTTP请求是无状态的，每次请求都是独立的
- Servlet容器（如Tomcat）接收到请求后，会从线程池中分配一个线程来处理
- 这个线程会处理整个请求的生命周期
2.1.2 线程池模型
Tomcat线程池 (例如：200个线程)
├─ thread-1: 处理请求A
├─ thread-2: 处理请求B
├─ thread-3: 处理请求C
└─ ...
每个请求分配一个线程，请求处理完成后，线程归还线程池
为什么需要MDC？
- 线程会被复用（请求A处理完后，thread-1可能被用来处理请求D）
- 如果不在请求结束时清理MDC，下一个请求可能会看到上一个请求的traceId（数据污染）
2.2 第二层：Filter过滤器链
2.2.1 Filter的执行顺序
// BaseSummaryWebMvcConfigure.java
@Bean
public FilterRegistrationBean<TraceIdFilter> traceIdFilter() {
FilterRegistrationBean<TraceIdFilter> registration = new FilterRegistrationBean<>();
registration.setFilter(new TraceIdFilter());
registration.addUrlPatterns("/*"); // 匹配所有URL
registration.setOrder(Ordered.HIGHEST_PRECEDENCE); // 最高优先级
return registration;
}
执行顺序：
请求到达
↓
TraceIdFilter (Order=HIGHEST_PRECEDENCE) ← 最先执行
↓
其他Filter（如SummaryRRLogFilter）
↓
DispatcherServlet
↓
Controller
为什么TraceIdFilter要最先执行？
- 因为后续的Filter和Controller都需要使用traceId
- 如果SummaryRRLogFilter先执行，它记录的日志中traceId还是空的
2.2.2 Filter的拦截机制
// TraceIdFilter.java
public class TraceIdFilter extends OncePerRequestFilter {
@Override
protected void doFilterInternal(HttpServletRequest request,
HttpServletResponse response,
FilterChain filterChain) {
try {
// 1. 提取或生成traceId
String traceId = extractTraceIdFromRequest(request);
if (traceId == null) {
traceId = generateTraceId();
}
// 2. 设置到MDC（关键步骤）
MDC.put("tid", traceId);
MDC.put("EagleEye-TraceID", traceId);
// 3. 继续执行Filter链
filterChain.doFilter(request, response);
} finally {
// 4. 清理MDC（防止线程复用导致数据污染）
MDC.clear();
}
}
}
关键点：
filterChain.doFilter()会继续执行后续的Filter和Controller- 在同一个线程中，MDC的值在整个请求处理过程中都可用
finally块确保无论成功还是异常，都会清理MDC
2.3 第三层：MDC（Mapped Diagnostic Context）
2.3.1 MDC的本质
MDC是SLF4J提供的线程本地存储机制，底层实现是ThreadLocal：
// MDC的简化实现（实际在slf4j-api中）
public class MDC {
// 底层使用ThreadLocal存储
private static ThreadLocal<Map<String, String>> contextMap = new ThreadLocal<>();
public static void put(String key, String value) {
Map<String, String> map = contextMap.get();
if (map == null) {
map = new HashMap<>();
contextMap.set(map);
}
map.put(key, value);
}
public static String get(String key) {
Map<String, String> map = contextMap.get();
return map != null ? map.get(key) : null;
}
public static void clear() {
contextMap.remove();
}
}
2.3.2 ThreadLocal的工作原理
ThreadLocal是Java提供的线程本地变量：
// 每个线程都有自己独立的ThreadLocal副本
Thread-1: ThreadLocal → Map{"tid": "traceId-1"}
Thread-2: ThreadLocal → Map{"tid": "traceId-2"}
Thread-3: ThreadLocal → Map{"tid": "traceId-3"}
内存模型：
┌─────────────────────────────────────────┐
│ Thread-1 (处理请求A) │
│ ThreadLocal<Map> │
│ └─ {"tid": "abc123"} │
└─────────────────────────────────────────┘
┌─────────────────────────────────────────┐
│ Thread-2 (处理请求B) │
│ ThreadLocal<Map> │
│ └─ {"tid": "def456"} │
└─────────────────────────────────────────┘
关键特性：
- 线程隔离：每个线程的ThreadLocal是独立的，互不干扰
- 自动清理：线程结束时，ThreadLocal会被GC回收
- 性能高效：访问ThreadLocal几乎无性能开销
2.3.3 MDC在请求处理中的生命周期
请求开始 (Thread-1)
↓
TraceIdFilter.doFilterInternal()
├─ MDC.put("tid", "abc123") ← 设置到Thread-1的ThreadLocal
└─ filterChain.doFilter() ← 继续执行
↓
Controller.handleRequest()
├─ logger.info("xxx") ← 从Thread-1的ThreadLocal读取traceId
└─ Service.doSomething()
└─ logger.info("yyy") ← 从Thread-1的ThreadLocal读取traceId
↓
TraceIdFilter.finally块
└─ MDC.clear() ← 清理Thread-1的ThreadLocal
↓
请求结束，Thread-1归还线程池
2.4 第四层：Logback日志框架
2.4.1 Logback Pattern配置
<!-- logback.xml -->
<pattern>
[%level] %d{yyyy-MM-dd HH:mm:ss.SSS}
[traceId=%X{tid}, tid=%X{EagleEye-TraceID:-}]
[%t] [%file:%line] - %m%n
</pattern>
Pattern解析：
%X{tid}：从MDC中读取key为"tid"的值%X{EagleEye-TraceID:-}：从MDC中读取key为"EagleEye-TraceID"的值，如果为空则显示"-"
2.4.2 Logback如何从MDC读取值
Logback内部实现（简化版）：
// Logback的PatternLayout处理%X{key}时
public class MDCConverter {
public String convert(ILoggingEvent event) {
String key = "tid"; // 从pattern中解析出的key
// 从当前线程的MDC中获取值
String value = MDC.get(key);
return value != null ? value : "";
}
}
执行流程：
logger.info("开始处理请求")
↓
Logback格式化日志
├─ 解析pattern: %X{tid}
├─ 调用MDC.get("tid")
├─ MDC内部从ThreadLocal获取值
└─ 输出: [traceId=abc123, tid=abc123]
2.4.3 日志输出的完整过程
// 业务代码
logger.info("开始处理打点任务上报, userId={}, meetingId={}", userId, meetingId);
// Logback处理过程：
1. 接收日志事件（包含消息、级别、线程等信息）
2. 解析pattern: [%level] ... [traceId=%X{tid} ...]
3. 对于%X{tid}：
a. 调用MDC.get("tid")
b. MDC从当前线程的ThreadLocal获取Map
c. 从Map中取出"tid"对应的值
4. 格式化输出：
[INFO] 2024-01-01 12:00:00.000 [traceId=abc123, tid=abc123] [http-nio-8001-exec-1] [PcFileUploadHelper.java:74] - 开始处理打点任务上报, userId=123, meetingId=meeting-001
2.5 第五层：业务代码中的使用
2.5.1 业务代码无需关心MDC
// PcFileUploadHelper.java
public void handleDotTask(UploadDotTaskDTO uploadDotTaskDTO, Long userId) {
// 直接使用logger，traceId会自动包含在日志中
log.info("开始处理打点任务上报, userId={}, meetingId={}",
userId, uploadDotTaskDTO.getMeetingId());
// 调用其他方法
summaryTaskHelper.createTask(...);
// 在summaryTaskHelper中的日志也会自动包含traceId
}
为什么业务代码不需要手动传递traceId？
- MDC是线程本地的，同一个线程内的所有代码都能访问
- Logback自动从MDC读取，无需业务代码干预
2.5.2 跨线程传递MDC（异步场景）
// 主线程
String traceId = MDC.get("tid"); // 获取当前traceId
Map<String, String> mdcContext = MDC.getCopyOfContextMap(); // 复制整个MDC
// 异步线程
CompletableFuture.runAsync(() -> {
MDC.setContextMap(mdcContext); // 恢复MDC上下文
try {
logger.info("异步任务执行"); // 日志会包含traceId
} finally {
MDC.clear();
}
});
为什么需要手动传递？
- ThreadLocal是线程隔离的，子线程无法自动继承父线程的ThreadLocal
- 必须手动复制MDC上下文到子线程
三、完整请求处理示例
3.1 请求处理时间线
时间轴：0ms → 10ms → 50ms → 100ms → 150ms → 200ms
│ │ │ │ │ │
│ │ │ │ │ └─ 响应返回，线程归还
│ │ │ │ └─ MDC.clear()
│ │ │ └─ Controller返回
│ │ └─ Helper.logger.info() → 从MDC读取traceId
│ └─ Service.doSomething()
└─ TraceIdFilter设置MDC
3.2 内存状态变化
┌─────────────────────────────────────────────────────────┐
│ 时间点: 请求到达前 │
├─────────────────────────────────────────────────────────┤
│ Thread-1的ThreadLocal: null (空) │
└─────────────────────────────────────────────────────────┘
┌─────────────────────────────────────────────────────────┐
│ 时间点: TraceIdFilter执行后 │
├─────────────────────────────────────────────────────────┤
│ Thread-1的ThreadLocal: │
│ Map{"tid": "abc123", "EagleEye-TraceID": "abc123"} │
└─────────────────────────────────────────────────────────┘
┌─────────────────────────────────────────────────────────┐
│ 时间点: Controller执行中 │
├─────────────────────────────────────────────────────────┤
│ Thread-1的ThreadLocal: │
│ Map{"tid": "abc123", "EagleEye-TraceID": "abc123"} │
│ │
│ logger.info() → MDC.get("tid") → 返回"abc123" │
└─────────────────────────────────────────────────────────┘
┌─────────────────────────────────────────────────────────┐
│ 时间点: 请求处理完成后 │
├─────────────────────────────────────────────────────────┤
│ Thread-1的ThreadLocal: null (已清理) │
│ │
│ Thread-1归还线程池，等待下一个请求 │
└─────────────────────────────────────────────────────────┘
四、关键技术点深入理解
4.1 为什么使用ThreadLocal而不是全局变量？
错误做法（全局变量）：
// ❌ 错误：全局变量会被所有线程共享
public class GlobalContext {
private static String traceId; // 所有线程共享，会互相覆盖
}
问题：
- 线程A设置traceId="abc"，线程B设置traceId="def"
- 线程A读取时可能读到"def"（数据污染）
正确做法（ThreadLocal）：
// ✅ 正确：每个线程独立存储
ThreadLocal<String> traceId = new ThreadLocal<>();
// Thread-1: traceId.get() → "abc"
// Thread-2: traceId.get() → "def"
// 互不干扰
4.2 为什么必须在finally中清理MDC？
问题场景：
请求A: Thread-1处理，设置MDC{"tid": "abc"}
↓
请求A处理完成，但忘记清理MDC
↓
Thread-1归还线程池
↓
请求B: Thread-1再次被使用
↓
请求B的日志中traceId显示为"abc"（错误！应该是请求B的traceId）
解决方案：
try {
MDC.put("tid", traceId);
// 业务处理
} finally {
MDC.clear(); // 无论成功还是异常，都清理
}
4.3 Filter的执行顺序为什么重要？
错误顺序：
SummaryRRLogFilter (先执行)
└─ logger.info("请求开始") ← traceId为空
↓
TraceIdFilter (后执行)
└─ MDC.put("tid", "abc") ← 设置traceId
↓
Controller
└─ logger.info("处理中") ← traceId有值
正确顺序：
TraceIdFilter (先执行)
└─ MDC.put("tid", "abc") ← 先设置traceId
↓
SummaryRRLogFilter (后执行)
└─ logger.info("请求开始") ← traceId有值
↓
Controller
└─ logger.info("处理中") ← traceId有值
4.4 Logback Pattern中的%X{key}是如何工作的？
Pattern解析过程：
// Logback内部实现（简化）
public class PatternLayout {
public String doLayout(ILoggingEvent event) {
String pattern = "[%level] [traceId=%X{tid}] - %m";
// 1. 解析pattern，找到%X{tid}
// 2. 创建MDCConverter
MDCConverter converter = new MDCConverter();
converter.setKey("tid");
// 3. 格式化时调用
String traceId = converter.convert(event);
// converter内部调用: MDC.get("tid")
// 4. 替换pattern中的%X{tid}
return pattern.replace("%X{tid}", traceId);
}
}
五、常见问题解答
5.1 为什么日志中traceId有时是空的？
可能原因：
- Filter未执行：请求绕过了Filter（如静态资源）
- MDC未设置：在Filter之前就打印了日志
- MDC被清理：在finally块执行后打印了日志
- 跨线程未传递：异步任务中未传递MDC上下文
5.2 如何调试MDC问题？
// 在代码中打印MDC内容
logger.info("当前MDC内容: {}", MDC.getCopyOfContextMap());
logger.info("当前traceId: {}", MDC.get("tid"));
logger.info("当前线程: {}", Thread.currentThread().getName());
5.3 异步任务中如何传递traceId？
// 1. 在主线程中保存MDC上下文
Map<String, String> mdcContext = MDC.getCopyOfContextMap();
// 2. 在异步线程中恢复
CompletableFuture.runAsync(() -> {
MDC.setContextMap(mdcContext); // 恢复
try {
// 业务逻辑
} finally {
MDC.clear(); // 清理
}
});
5.4 为什么使用MDC而不是方法参数传递traceId？
方法参数传递（不推荐）：
// ❌ 需要每个方法都传递traceId参数
public void method1(String traceId) {
logger.info("method1, traceId={}", traceId);
method2(traceId);
}
public void method2(String traceId) {
logger.info("method2, traceId={}", traceId);
method3(traceId);
}
// 问题：代码侵入性强，容易遗漏
MDC方式（推荐）：
// ✅ 自动传递，无需修改方法签名
public void method1() {
logger.info("method1"); // 自动包含traceId
method2();
}
public void method2() {
logger.info("method2"); // 自动包含traceId
method3();
}
// 优点：代码简洁，自动传递
六、性能考虑
6.1 MDC的性能开销
性能测试结果（参考）：
- MDC.put/get操作：< 1纳秒（几乎无开销）
- ThreadLocal访问：< 1纳秒
- 总体影响：可忽略不计
为什么性能这么好？
- ThreadLocal是线程本地变量，直接访问线程栈，无需加锁
- MDC只是对ThreadLocal的简单封装
6.2 内存占用
每个请求的MDC占用：
- 假设存储2个key-value对（tid, EagleEye-TraceID）
- 每个key约10字节，value约32字节
- 总计：约100字节/请求
- 对于1000并发：约100KB（可忽略）
七、最佳实践总结
7.1 设置MDC的时机
- ✅ Filter中设置：确保所有后续代码都能使用
- ✅ 请求开始时设置：在业务逻辑之前
- ❌ 不要在业务代码中设置：容易遗漏，维护困难
7.2 清理MDC的时机
- ✅ finally块中清理：确保无论成功还是异常都清理
- ✅ 请求结束时清理：避免线程复用导致数据污染
- ❌ 不要忘记清理：会导致traceId串用
7.3 异步任务处理
- ✅ 复制MDC上下文：使用
getCopyOfContextMap() - ✅ 在异步线程中恢复：使用
setContextMap() - ✅ 异步任务结束时清理：避免内存泄漏
7.4 日志Pattern设计
- ✅ 使用%X{key}：从MDC读取值
- ✅ 提供默认值：
%X{key:-}避免显示空字符串 - ✅ 统一key命名：使用一致的key名称（如"tid"）
八、总结
8.1 核心原理
- ThreadLocal：提供线程本地存储，每个线程独立
- MDC：基于ThreadLocal的上下文存储，用于日志追踪
- Filter：在请求开始时设置MDC，结束时清理
- Logback：从MDC自动读取值，格式化日志输出
8.2 数据流向
HTTP请求头 (X-Trace-Id)
↓
TraceIdFilter提取
↓
MDC.put() → ThreadLocal存储
↓
业务代码执行
↓
logger.info() → Logback从MDC读取
↓
日志输出包含traceId
↓
请求结束 → MDC.clear()
8.3 关键设计思想
- 透明传递：业务代码无需关心traceId的传递
- 线程隔离：使用ThreadLocal确保线程安全
- 自动清理：使用finally确保资源释放
- 统一管理：在Filter层统一处理，避免代码重复
通过这套机制，我们实现了零侵入的日志链路追踪，业务代码只需要正常使用logger，traceId会自动包含在日志中，大大简化了开发工作。
