分布式链路追踪实战：从下单到支付，我如何定位到了慢在第3毫秒

分布式链路追踪实战从下单到支付我如何定位到了慢在第3毫秒大家好我是迪哥。在微服务架构下最让人头疼的不是系统挂了而是请求慢却不知道慢在哪个环节——就像我家那只叫Docker的哈士奇它闯祸拆家你永远抓不到现行等发现时沙发已经烂了一片。今天我就和大家聊聊我们团队是如何通过分布式链路追踪把一次完整下单流程中那耗时占比80%的第3毫秒给揪出来的。背景大促前的性能噩梦离618还有两周我们的压测结果显示下单接口的 P99 已经飙到了 1.2 秒而目标是 300ms。但看服务监控所有服务的 P99 都在 100ms 以内这就奇怪了——单个服务都很快拼在一起怎么就慢成狗了呢选型为什么是 SkyWalking当时调研了主流的链路追踪方案方案侵入性存储UI我们团队Jaeger低Elasticsearch简洁但要自己维护ESZipkin中等MySQL/ES一般社区不如SkyWalking活跃SkyWalking低H2/ES/MySQL/InfluxDB功能全面中文文档友好开箱即用最终我们选了SkyWalking——无侵入的 Java Agent 方案对我们这种 20 微服务的团队来说接入成本几乎为零。部署10分钟搞定的全链路接入1. 部署 SkyWalking OAP UI# docker-compose.yml version: 3.8 services: oap: image: apache/skywalking-oap-server:9.4.0 ports: - 11800:11800 # gRPC - 12800:12800 # HTTP environment: SW_STORAGE: elasticsearch SW_STORAGE_ES_CLUSTER_NODES: elasticsearch:9200 ui: image: apache/skywalking-ui:9.4.0 ports: - 8080:8080 environment: SW_OAP_ADDRESS: http://oap:12800 elasticsearch: image: docker.elastic.co/elasticsearch/elasticsearch:8.8.0 environment: - discovery.typesingle-node - xpack.security.enabledfalse2. 微服务接入 Agent# 启动脚本里加一行 -javaagent:/path/to/skywalking-agent.jar \ -Dskywalking.agent.service_nameorder-service \ -Dskywalking.collector.backend_serviceoap-server:11800没错就这么简单重启服务后全链路数据自动上报了。关键功能SkyWalking 三板斧第一板斧Topology Map 看架构打开 SkyWalking UI首先看Topology Map拓扑图gateway → order-service ──┬── stock-service ├── payment-service └── user-service拓扑图一眼就能看出系统调用关系还能看到每个服务的响应时间、错误率。第二板斧Trace 看请求链路我们找了个耗时 1.2s 的下单请求 TraceID点进去看详细链路┌─────────────────────────────────────────────────────────────────────┐ │ Trace: a1b2c3d4e5f6a7b8 (1.2s) │ ├─────────────────────────────────────────────────────────────────────┤ │ 1. gateway: POST /api/order/create [0.2ms] │ │ 2. order-service: createOrder [0.1ms] → 700ms │ │ ├─ 2.1 user-service: getUserInfo [0.3ms] → 50ms │ │ ├─ 2.2 stock-service: deduct [0.2ms] → 80ms │ │ ├─ 2.3 payment-service: preCreate [0.4ms] → 120ms │ │ ├─ 2.4 DB: INSERT INTO orders [1.2ms] → 200ms │ │ └─ 2.5 ✨ 发现了Redis: GET user:cache:12345 [1.5ms] → 450ms │ └─────────────────────────────────────────────────────────────────────┘哦问题找到了GET user:cache:12345这个 Redis 操作竟然耗时450ms占了总请求时间的37.5%第三板斧Profile 看代码级火焰图光知道慢在 Redis 还不够为什么慢我们开启了Profile采样分析Trace public User getUserInfo(Long userId) { // 第1行 String key user:cache: userId; String json stringRedisTemplate.opsForValue().get(key); // ← 这里 if (json ! null) { return JSON.parseObject(json, User.class); } // ... }火焰图显示问题出在stringRedisTemplate.opsForValue().get(key)——但 Redis GET 命令怎么可能 450ms继续往下看发现是网络问题我们的应用服务在阿里云华北 2Redis 却在上海跨区域调用了踩过的坑坑一链路数据丢失初期发现有些 Trace 数据不全。排查后是 SkyWalking 的采样率默认是 100%但我们 QPS 很高OAP 内存不够直接丢弃了数据。解决方案# application.yml # 只采样 30% 的请求 skywalking: agent: sample_n_per_3_secs: 100坑二自定义 Span 如何加有些业务逻辑需要单独追踪比如我们的风控规则引擎这时候可以手动加 SpanTrace public boolean checkRisk(Long userId, OrderRequest request) { // 手动创建子 Span Span riskSpan ContextManager.createLocalSpan(risk.checkRules); try { boolean result doCheckRisk(request); riskSpan.setComponent(new Component(risk-engine)); return result; } catch (Exception e) { riskSpan.errorOccurred(); riskSpan.log(e); throw e; } finally { ContextManager.stopSpan(); } }告警把问题消灭在发生前SkyWalking 支持配置告警规则比如# alarm-settings.yml rules: slow_service_resp_time: metrics-name: service_resp_time op: threshold: 1000 # 超过1秒告警 period: 5 count: 3 silence-period: 10 message: 服务 {name} 响应时间超过 1 秒!配合 Webhook可以直接发到企业微信群再也不用等用户投诉才发现问题。最终效果解决了跨区域 Redis 问题后指标优化前优化后下单接口 P991200ms280ms最慢环节占比37.5%不到 5%问题定位时间几小时3分钟经验总结链路追踪越早接入越好别等出了问题才想起搭前期成本最低采样率不是越高越好根据业务量调整能抓到问题就行善用 Profile 功能比 Arthas 还方便定位代码级瓶颈告警规则要配套发现问题只是第一步能及时通知才是关键拓扑图是好东西新人入职看一遍拓扑图比读一周文档还强顺便说一句我家那只叫 Docker 的哈士奇最近拆家技术升级了从沙发拆到了书架——看来我也得给它的拆家路径做个追踪了 我是迪哥我们下期再见往期推荐《从单体到微服务一次核心交易系统的架构拆分实战》《Redis 高可用架构实战》