微服务链路追踪实战——SkyWalking 从接入到问题排查的完整流程
微服务链路追踪实战——SkyWalking 从接入到问题排查的完整流程
适读人群:微服务系统的后端开发者和运维工程师 | 阅读时长:约17分钟 | 核心价值:掌握 SkyWalking 完整接入流程,建立通过链路追踪快速定位问题的方法论
那个排查了三天的 bug
两年前,我们微服务系统出现了一个奇怪的问题:某些用户的下单请求会偶发性地超时,发生概率大概 3%,找不到规律,有时候能正常下单,有时候就卡住了。
三个开发同时查了整整三天,每人翻了一遍各自服务的日志,都没找到问题。大家互相甩锅——"我的服务日志没报错"、"我的接口响应很快"。
最后是一个同事建议:接入链路追踪吧,看看请求到底卡在哪里。
装上 SkyWalking 之后,不到 2 小时问题就定位了——第三方物流接口有时候响应极慢(30 秒+),而调用物流接口的地方没有超时设置,请求就一直等着,最终导致上游超时。
这个问题,如果早接 SkyWalking,可能第一天就发现了。
SkyWalking 核心架构
SkyWalking 是国内开源的 APM(应用性能监控)系统,由吴晟发起,现在是 Apache 顶级项目。
三大组件:
- SkyWalking Agent:Java 探针,通过字节码增强(无侵入)自动采集链路数据
- SkyWalking OAP(Observability Analysis Platform):数据接收和分析服务
- SkyWalking UI:可视化界面,展示链路、拓扑、服务指标
无侵入的原理: SkyWalking Agent 通过 Java Agent 机制(-javaagent)在 JVM 启动时注入,使用 ByteBuddy 对 Spring MVC、JDBC、Feign 等框架的关键方法进行增强,自动记录调用链路,不需要修改任何业务代码。
快速接入:3 步完成
第一步:部署 OAP + UI
# docker-compose.yml
version: '3'
services:
oap:
image: apache/skywalking-oap-server:9.7.0
environment:
- SW_STORAGE=elasticsearch
- SW_STORAGE_ES_CLUSTER_NODES=es:9200
ports:
- "11800:11800" # gRPC 端口(Agent 上报)
- "12800:12800" # HTTP 端口(UI 查询)
depends_on:
- es
ui:
image: apache/skywalking-ui:9.7.0
environment:
- SW_OAP_ADDRESS=http://oap:12800
ports:
- "8080:8080"
es:
image: elasticsearch:7.17.0
environment:
- discovery.type=single-node
- "ES_JAVA_OPTS=-Xms512m -Xmx512m"
volumes:
- ./es-data:/usr/share/elasticsearch/data第二步:下载 Agent
wget https://archive.apache.org/dist/skywalking/9.7.0/apache-skywalking-java-agent-9.0.0.tgz
tar -xzf apache-skywalking-java-agent-9.0.0.tgz第三步:Java 服务接入
# 启动时添加 -javaagent 参数
java -javaagent:/path/to/skywalking-agent/skywalking-agent.jar \
-DSW_AGENT_NAME=order-service \
-DSW_AGENT_COLLECTOR_BACKEND_SERVICES=oap-host:11800 \
-jar order-service.jar在 Spring Boot 的 Dockerfile 里:
FROM openjdk:17-jre-slim
COPY skywalking-agent/ /skywalking-agent/
COPY target/order-service.jar /app.jar
ENV SW_AGENT_NAME=order-service
ENV SW_AGENT_COLLECTOR_BACKEND_SERVICES=oap-service:11800
ENTRYPOINT ["java", \
"-javaagent:/skywalking-agent/skywalking-agent.jar", \
"-jar", "/app.jar"]手动打点:增强追踪粒度
SkyWalking Agent 自动追踪 HTTP 请求、数据库操作、RPC 调用等。但有些业务逻辑(如复杂计算、外部服务调用)需要手动打点:
<dependency>
<groupId>org.apache.skywalking</groupId>
<artifactId>apm-toolkit-trace</artifactId>
<version>9.0.0</version>
</dependency>@Service
public class OrderService {
/**
* 注解方式:自动追踪方法执行时间和参数
*/
@Trace
@Tags({@Tag(key = "orderId", value = "arg[0]"),
@Tag(key = "userId", value = "arg[1]")})
public Order createOrder(String orderId, String userId, OrderRequest request) {
// ...
}
/**
* API 方式:手动控制 Span
*/
public void callExternalService(String serviceUrl) {
AbstractSpan span = ContextManager.createLocalSpan("external-service-call");
span.tag("url", serviceUrl);
try {
// 外部调用
String result = httpClient.get(serviceUrl);
span.tag("result_length", String.valueOf(result.length()));
} catch (Exception e) {
span.log(e); // 记录异常到 Span
span.errorOccurred();
throw e;
} finally {
ContextManager.stopSpan();
}
}
/**
* 获取当前 TraceId(用于日志关联)
*/
public String getCurrentTraceId() {
return TraceContext.traceId();
}
}日志关联:让日志和链路打通
单独看链路追踪,你知道请求经过了哪些服务;单独看日志,你能看到业务细节。把日志和链路追踪关联起来,才是最强的排查工具。
方法:在日志中打印 TraceId,然后在 SkyWalking UI 中可以通过 TraceId 查找对应链路。
<!-- logback-spring.xml -->
<configuration>
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>
%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level
[%X{SW_CTX}] <!-- SkyWalking 自动往 MDC 里注入 TraceId -->
%logger{36} - %msg%n
</pattern>
</encoder>
</appender>
</configuration>SkyWalking Agent 会自动把 TraceId 注入到 SLF4J 的 MDC(SW_CTX 字段),日志里就有了 TraceId。
输出效果:
2024-01-20 14:30:15.123 [main] INFO [TID:8f3d2a1b.123.456789] OrderService - 开始创建订单,orderId=12345通过日志里的 TID 可以直接在 SkyWalking UI 中搜索对应链路。
在 UI 中排查问题
找慢请求
在 SkyWalking UI → Trace → 设置时间范围,按 "Duration" 降序排序,找到响应最慢的请求。
点击某个 TraceId,可以看到完整调用链路:
Browser → Gateway (15ms)
└── order-service (450ms)
├── DB Query: SELECT * FROM orders (3ms)
├── inventory-service (5ms)
│ └── DB Update: UPDATE stock (2ms)
└── logistics-service (430ms) ← 这里!
└── HTTP GET /external/api (428ms)很清楚:logistics-service 调用外部 API 花了 428ms,是慢请求的根因。
分析服务依赖图
SkyWalking UI → Topology 可以看到服务间的调用关系图,发现异常的依赖(循环依赖、意外的直接调用等)。
三大踩坑实录
坑一:Agent 影响 JVM 启动速度
现象: 接入 SkyWalking Agent 后,Spring Boot 应用启动时间从 30 秒变成了 70 秒。K8s 的 Readiness Probe 超时,Pod 不断重启。
原因: SkyWalking Agent 在启动时需要扫描并增强所有字节码,应用越大(依赖越多),启动时间增加越多。
解法: 增大 K8s Readiness Probe 的 initialDelaySeconds 和 failureThreshold:
readinessProbe:
httpGet:
path: /actuator/health
port: 8080
initialDelaySeconds: 120 # 加大初始等待时间
periodSeconds: 10
failureThreshold: 6另外,可以通过 SkyWalking 的 config/agent.config 排除不需要追踪的包,减少扫描范围。
坑二:采样率太高把 OAP 压垮
现象: 生产接入后,OAP 服务 CPU 飙升,ES 写入积压,SkyWalking UI 卡顿,甚至影响了业务服务(OAP 接收不了数据,会阻塞 Agent 的上报线程池)。
原因: 生产环境请求量大(每秒 5000+ 请求),默认采样率 100%,每秒 5000 条 Trace 数据写入 ES,OAP 和 ES 都顶不住。
解法: 降低采样率,一般生产用 10%-20%:
# agent.config
agent.sample_n_per_3_secs=100 # 每3秒采样100条(约33/s)同时调整 OAP 的 ES 写入批次和 ES 硬件配置。
坑三:异步线程的 TraceId 丢失
现象: 某些请求的链路追踪显示不完整——主线程的调用链有,但异步线程里的数据库操作和外部调用没有显示在链路上,像是断掉了。
原因: SkyWalking 的 TraceId 存在 ThreadLocal 中,当使用线程池切换线程时(如 @Async、CompletableFuture),TraceId 不会自动传递到新线程。
解法: 使用 SkyWalking 的 RunnableWrapper / CallableWrapper 在线程切换时传递 Trace 上下文:
// 错误:直接提交 Runnable,TraceId 断掉
executor.submit(() -> {
inventoryService.deductStock(skuId, quantity);
});
// 正确:用 RunnableWrapper 包装
executor.submit(RunnableWrapper.of(() -> {
inventoryService.deductStock(skuId, quantity);
}));
// 对于 CompletableFuture
CompletableFuture.supplyAsync(
SupplierWrapper.of(() -> inventoryService.getStock(skuId)),
executor
);关键指标监控配置
# SkyWalking Alert 配置(alert-rules.yml)
rules:
# 服务错误率超过1%告警
service_resp_time_rule:
metrics-name: service_resp_time
op: ">"
threshold: 2000 # 2000ms
period: 10
count: 3 # 连续3次超过阈值
message: "Response time of service {name} is more than 2000ms in 3 minutes of last 10 minutes"
service_error_rate_rule:
metrics-name: service_sla
op: "<"
threshold: 9900 # 99% 成功率(SLA)
period: 10
count: 2
message: "Service {name} error rate is more than 1%"总结
SkyWalking 是我用过性价比最高的开源 APM 工具——无侵入、功能完整、中文社区活跃。从接入到发挥价值,通常 1 天就能完成。
最重要的习惯是:出问题时,先看链路追踪,再看日志。链路追踪告诉你"慢在哪里、断在哪里",日志告诉你"发生了什么"。两者结合,排查效率能提升 5-10 倍。
