ARTICLE · INTELLIGENCE

战地情报 · 详情页

来自尧图项目组的一线实战观察与深度解析

MES Agent 性能排查实战:从 55 秒到 1 秒的 Trace 优化全记录

MES Agent 性能排查实战:从 55 秒到 1 秒的 Trace 优化全记录

1. 从 55 秒到 1 秒:这次性能排查到底在解决什么问题

做过制造执行系统(MES)的朋友应该都有体会,系统里最怕的不是功能做不出来,而是某个环节突然慢得离谱,还找不到原因。我这次遇到的场景就很典型:一个负责生产工单状态同步的 Agent 服务,在产线高峰期单次请求耗时飙到了 55 秒,下游的看板刷新、报工回传、设备状态联动全部被拖住,现场班组长直接打电话过来问是不是系统挂了。

这个 Agent 的核心职责其实不复杂,它要定时从设备侧拉取工单执行数据,做一轮业务规则校验,再把结果写回 MES 主库并推送给看板服务。逻辑链路清晰,数据量也不算夸张,单批次大概几千条记录。按正常预期,这种量级的处理应该在 1 到 2 秒内完成。但实际监控数据显示,P99 耗时长期在 50 秒以上,平均耗时也在 30 秒左右徘徊,而且这个劣化是渐进式的,不是某次发版突然出现的。

我接手这个问题的第一反应不是去改代码,而是先搞清楚时间到底花在哪了。性能排查最忌讳的就是凭直觉猜,猜对了是运气,猜错了就是白干几天。所以我给自己定了一条原则:先用 Trace 把时间分布打出来,再决定动哪里。这也是我写这篇复盘的核心目的——把一次真实的、从 55 秒压到 1 秒的排查过程完整拆开,让正在被类似问题困扰的同行能直接抄作业。

这篇文章适合几类人看:一是正在做 MES、WMS、SCADA 这类工业软件后端服务的开发者;二是遇到过接口耗时异常但不知道从哪下手排查的工程师;三是对分布式追踪(Trace)体系感兴趣、想了解怎么用它定位真实性能瓶颈的技术人员。不管你用的是 Java、Go 还是 Python 技术栈,排查思路是通用的,工具只是载体。

需要提前说明的是,下面涉及的具体项目名称、公司信息、人员身份我都做了脱敏处理,用代称代替,但技术细节和排查逻辑是真实的,参数和结论都可以直接参考。

2. 排查前的整体设计思路:为什么选 Trace 而不是日志

2.1 为什么传统日志排查在这次场景里不够用

一开始我也试过加日志。在 Agent 的几个关键节点打了时间戳,想看看到底是哪一段慢。结果发现日志能告诉我的信息非常有限:它只能告诉我"进入方法 A 的时间"和"离开方法 A 的时间",但方法 A 内部又调了数据库、又调了缓存、又发了消息队列,这些子调用的耗时在日志里是糊在一起的。更麻烦的是,这个 Agent 是多线程并发处理的,日志交错在一起,根本没法把一次请求的完整链路串起来。

这就是传统日志的天然短板:它是按时间顺序平铺的,不是按调用关系组织的。当一次请求跨越多个线程、多个服务、多个中间件时,日志就像把一堆积木倒在地上,你能看到每块积木,但看不出它们原本搭成了什么形状。

Trace 解决的正是这个问题。它给每一次请求分配一个全局唯一的 TraceId,请求流经的每一个环节都会记录一个 Span,Span 之间有父子关系,最终形成一棵调用树。这棵树一画出来,哪个环节耗时最长、哪个环节被调用了最多次,一目了然。

2.2 Trace 体系选型的几个考量点

市面上做分布式追踪的方案不少,选型时我主要看三个维度。

第一个维度是侵入性。有些方案需要你在代码里手动埋点,每个方法入口出口都加一行,工作量大不说,还容易漏。我倾向于选支持自动埋点的方案,比如基于字节码增强或者探针机制的,这样业务代码基本不用动,升级维护也方便。

第二个维度是采样策略。全量采集当然最准,但存储和性能开销扛不住,尤其是高峰期。我采用的是自适应采样:正常请求按 10% 采样,耗时超过阈值的请求 100% 采集。这样既控制了成本,又保证了慢请求一定有完整链路可查。

第三个维度是与现有监控体系的整合。Trace 不能是孤岛,它得能和指标(Metrics)、日志(Logs)联动。比如我在 Trace 里看到一个 Span 特别慢,能直接跳转到对应的日志详情,或者看到那个时间点的 CPU、内存、连接池指标。这种联动能力在排查时能省大量时间。

最终我用的是一套基于 OpenTelemetry 标准的方案,Agent 侧接入探针,后端存储用列式数据库,查询界面自建。这套组合的好处是标准统一,将来换后端存储或者换采集器都不用改业务代码。

2.3 排查的整体节奏设计

我把整个排查分成四步走,这个节奏后来证明是对的:

  1. 先看全局:把慢请求的 Trace 列表拉出来,看耗时分布是集中在某几个环节,还是均匀分散。
  2. 再钻细节:针对耗时最长的 Span,看它的子 Span 结构,定位到具体的方法或 SQL。
  3. 验证假设:针对怀疑的点做针对性实验,比如单独压测那个 SQL,或者把某个调用临时短路看耗时变化。
  4. 改完复测:每次改动后重新采集 Trace,对比优化前后的耗时分布,确认改动有效且没有引入新问题。

这个节奏的核心逻辑是从粗到细、从观察到验证,避免一上来就扎进代码细节里出不来。

3. 核心细节解析:55 秒到底花在哪了

3.1 第一次看 Trace 的震撼

把慢请求的 Trace 拉出来那一刻,我印象很深。整棵调用树展开后有上百个 Span,但耗时分布极度不均:根 Span 55 秒,下面挂着一个 52 秒的子 Span,而这个 52 秒的 Span 下面又挂着一个 48 秒的孙 Span。也就是说,绝大部分时间都消耗在一条很深的调用链上,其他分支加起来才几秒。

这条深链的路径大致是这样的:Agent 主处理逻辑 → 工单数据聚合 → 设备状态查询 → 数据库查询 → 连接获取。问题就出在最后两步:数据库查询本身耗时 40 多秒,而其中又有相当一部分时间花在等待数据库连接上。

这里有个细节值得说:Trace 里显示的"数据库查询耗时"其实是包含了连接获取时间的。如果你不展开看子 Span,很容易误以为是 SQL 本身慢。我一开始就差点被误导,后来展开才发现,真正执行 SQL 的时间只有 8 秒左右,剩下 30 多秒全在等连接。

3.2 连接等待为什么这么夸张

连接等待时间长,通常有几个原因:连接池太小、连接被长时间占用不释放、或者数据库侧有锁等待。我逐个排查。

先看连接池配置。当时用的是默认配置,最大连接数只有 10。而这个 Agent 是多线程并发的,高峰期同时有几十个线程要查数据库,10 个连接根本不够分,大量线程在排队等连接。这是第一个问题。

再看连接占用时长。我发现有些查询执行完后,连接没有及时归还,原因是代码里用了手动管理连接的方式,在某些异常分支下会漏掉关闭操作。虽然不频繁,但一旦发生,那个连接就被占死了,进一步加剧了连接短缺。这是第二个问题。

最后看数据库侧。我查了数据库的慢查询日志和锁等待情况,发现有一条聚合查询没有走索引,全表扫描了几十万行数据,单次执行就要好几秒。这条 SQL 被高频调用,累积起来就是灾难。这是第三个问题。

三个问题叠加,就造成了 55 秒的惨状。这也说明性能问题往往不是单点的,而是多个小问题共振的结果。

3.3 一个容易被忽略的细节:序列化开销

在排查过程中我还发现一个隐蔽的耗时点:Agent 在把查询结果推送给看板服务时,做了一次全量 JSON 序列化。数据量大的时候,序列化本身就要消耗一两秒。虽然相比 55 秒不算大头,但优化到后面阶段时,这一两秒就变得很显眼了。

这个细节提醒我:性能优化是分阶段的,不同阶段的主要矛盾不一样。55 秒的时候你盯着连接池,1 秒多的时候你就得盯着序列化了。

4. 实操过程:一步步把 55 秒压到 1 秒

4.1 第一步:连接池参数调整与验证

连接池这块,我做了三件事。

第一是调大最大连接数。从 10 调到 50。这个数字不是拍脑袋定的,我算了一下:Agent 高峰期并发线程数大约 40,每个线程处理一次请求最多占用一个连接,考虑到还有少量其他服务共用这个库,50 是比较安全的余量。公式可以简化为:最大连接数 ≥ 峰值并发线程数 × 1.2。

第二是设置合理的连接超时和空闲回收。连接获取超时设为 3 秒,超过就快速失败并记录告警,避免线程无限等待。空闲连接超过 60 秒自动回收,防止连接泄漏累积。

第三是修复连接泄漏。把所有手动管理连接的地方改成用 try-with-resources 或者框架提供的模板方法,确保异常路径下连接也能归还。

改完这三项,重新压测,耗时从 55 秒降到了 20 秒左右。连接等待的 Span 明显缩短了,但还没到位。

# 连接池关键配置参考 maximumPoolSize: 50 connectionTimeout: 3000 idleTimeout: 60000 maxLifetime: 1800000 leakDetectionThreshold: 10000

注意:连接池不是越大越好。连接数超过数据库承载能力后,反而会因为数据库侧线程切换和锁竞争导致整体变慢。调大之后一定要压测验证。

4.2 第二步:慢 SQL 定位与索引优化

连接问题缓解后,SQL 本身的耗时就成了主要矛盾。我把 Trace 里耗时最长的几条 SQL 捞出来,逐条分析执行计划。

问题最大的是一条工单状态聚合查询,它要按设备编号、时间段、工单状态三个条件做分组统计。原来的 SQL 没有针对这三个字段建联合索引,数据库只能全表扫描。我建了一个联合索引,字段顺序是(设备编号,时间段,工单状态)。字段顺序很关键:把区分度最高、过滤性最强的字段放前面,能让索引尽快缩小扫描范围。

建完索引后,这条 SQL 从 8 秒降到了 200 毫秒以内。整个 Agent 耗时降到了 5 秒左右。

这里有个经验:索引不是越多越好,每个索引都会增加写入开销。我建索引前先确认了这张表的读写比例,读远大于写,所以加索引是划算的。如果是一张高频写入的表,就得慎重。

4.3 第三步:批量化与异步化改造

到 5 秒这个阶段,剩下的耗时主要来自两个方面:一是逐条处理数据的循环开销,二是同步推送看板的网络等待。

针对第一点,我把逐条查询改成了批量查询。原来是一个工单查一次数据库,现在改成一次查一批工单,用 IN 条件批量拉取。数据库往返次数从几百次降到几次,效果立竿见影。

针对第二点,我把看板推送改成了异步。Agent 处理完数据后,把推送任务丢进消息队列,由独立的消费者去推送,主流程不再等待推送结果。这样主流程的耗时就不受看板服务响应速度影响了。

这两项改完,耗时降到了 1.5 秒左右。

// 批量查询示意(伪代码) List<Long> orderIds = getPendingOrderIds(batchSize); Map<Long, OrderDetail> detailMap = orderMapper.selectBatchByIds(orderIds); for (Long id : orderIds) { processOrder(detailMap.get(id)); }

4.4 第四步:序列化与缓存收尾

最后这 0.5 秒,主要花在 JSON 序列化和部分重复查询上。

序列化这块,我换了一个性能更好的序列化库,并且只序列化看板真正需要的字段,而不是整个对象全量输出。字段裁剪后,序列化数据量减少了约 60%。

重复查询这块,我加了一层本地缓存。有些设备的基础信息在短时间内不会变化,没必要每次请求都查库。缓存过期时间设为 5 分钟,命中率能达到 90% 以上。

这两项做完,最终耗时稳定在 1 秒左右,P99 也能控制在 1.2 秒以内。

4.5 优化前后对比

优化阶段主要动作耗时关键瓶颈
优化前无55 秒连接等待 + 慢 SQL
第一步连接池调整20 秒慢 SQL
第二步索引优化5 秒循环查询 + 同步推送
第三步批量 + 异步1.5 秒序列化 + 重复查询
第四步序列化 + 缓存1 秒无明显瓶颈

这张表我建议你保存下来,它清晰地展示了性能优化是分阶段推进的,每个阶段解决不同的主要矛盾。

5. 常见问题与排查技巧实录

5.1 排查过程中踩过的坑

坑一:只看平均耗时,忽略 P99。平均耗时 30 秒的时候,我以为问题很均匀,实际上大部分请求可能只要几秒,是少数慢请求把平均值拉高了。后来我改成重点看 P99 和慢请求的 Trace,才定位到真正的瓶颈。

坑二:Trace 采样率设太低。一开始为了省存储,采样率设了 1%,结果慢请求经常采不到,排查时没有样本可看。后来改成自适应采样,慢请求必采,问题就解决了。

坑三:改完不压测直接上线。有一次我调完连接池参数觉得没问题就上线了,结果高峰期数据库连接被打满,影响了其他服务。从那以后我坚持每次改动都先在预发环境压测。

5.2 常见问题速查表

现象可能原因排查方向
接口耗时突然飙升慢 SQL、连接池耗尽、下游服务超时看 Trace 耗时分布,定位最长 Span
耗时逐渐劣化数据量增长、索引失效、连接泄漏对比历史 Trace,看哪个环节在变慢
高峰期慢、低峰期正常并发竞争、连接不足、锁等待看并发量与时耗的相关性
偶发超时网络抖动、GC、慢查询偶发看超时请求的 Trace 和系统指标
优化后效果不明显瓶颈转移、改动未生效重新采集 Trace,确认新瓶颈

5.3 几条实操心得

第一,Trace 要和生产指标联动看。光看 Trace 只能知道哪里慢,结合 CPU、内存、连接池指标才能知道为什么慢。

第二,优化要有优先级。先解决耗时占比最大的环节,不要一上来就抠那些只占几毫秒的细节。

第三,每次只改一个变量。同时改多个地方,出了问题都不知道是哪个改动导致的。

第四,保留优化前的 Trace 快照。这是你对比效果、复盘问题的依据,非常宝贵。

6. 工具选型与落地建议

6.1 Trace 工具选型的实操建议

如果你现在还没上 Trace 体系,我的建议是优先选支持 OpenTelemetry 标准的方案。原因很简单:标准统一,将来换存储、换采集器、换查询界面都不用动业务代码。具体落地时,Agent 侧用探针自动埋点,业务代码零侵入;采集端用 Collector 做统一接收和转发;存储端根据数据量选,量小用关系库也行,量大就上列式数据库。

采样策略上,我强烈建议用自适应采样。固定采样率要么采太多浪费资源,要么采太少漏掉问题。自适应采样能保证慢请求一定被采集,正常请求按比例采集,性价比最高。

6.2 性能优化的通用方法论

这次排查让我总结出一套通用的性能优化方法论,分享给你:

  1. 量化:先用 Trace 把耗时量化,不要凭感觉。
  2. 定位:找到耗时占比最大的环节,集中火力。
  3. 验证:针对怀疑点做实验,确认因果关系。
  4. 优化:改一个变量,压测验证。
  5. 复测:重新采集 Trace,确认效果并寻找新瓶颈。
  6. 固化:把有效的配置和代码固化下来,加上监控告警防止回退。

这套方法论不限于 MES Agent,任何后端服务的性能优化都适用。

6.3 后续还能怎么扩展

这次优化到 1 秒后,我还在继续观察。下一步的优化方向有两个:一是把部分计算逻辑下沉到数据库侧,用存储过程或者物化视图减少数据传输;二是引入更细粒度的缓存分层,把热点数据放到更靠近计算的地方。

另外,我打算把这套 Trace 排查流程沉淀成团队的标准操作手册,让每个成员遇到性能问题都能按图索骥,而不是每次都从头摸索。

我个人在实际操作中的体会是,性能排查最值钱的不是某个具体的优化技巧,而是一套可复用的排查思路和工具链。55 秒到 1 秒这个结果看起来很爽,但真正让我有成就感的,是下次再遇到类似问题时,我知道该从哪里下手、该怎么验证、该怎么收尾。这套东西一旦建立起来,就是团队长期的技术资产。

RELATED READING

延伸阅读

更多一线实战笔记与深度复盘,助您持续精进