企业官网建设流程全解析

这事儿得从昨天下午说起。

周五，下午四点半，我已经在收拾东西准备跑路了。测试那边丢过来一个issue，说生产环境有个接口偶尔超时，让我看一眼。偶尔超时，这种词儿在程序员字典里基本等于"大概率是你的问题但我懒得查日志"。

我打开skywalking，看了下调用链，没毛病啊，响应时间平均120ms，挺正常的。又翻了翻nginx日志，也没有明显慢请求。我就回了一句"这边看正常，再观察一下"。

然后测试就炸了。

他贴了张截图，请求时间15:47:23，响应时间3.2秒。我一看这个时间点，心里咯噔一下——那个时间我刚发完一个版本，重启了服务。

你以为的bug，其实是feature

接下来就是一个小时的血泪排查。

先怀疑是缓存失效导致回源DB，查了redis命中率，99.8%，正常。

再怀疑是日志打印太多，把IO堵了，看了下logback的异步队列，积压为0，正常。

怀疑是GC问题，看了眼GC日志，频率正常，单次耗时也都在50ms以内。

然后我注意到一个细节：这个超时请求里带了一个特殊的header，x-request-id的格式是abc-123-def这种，但正常我们内部生成的格式是UUID.randomUUID().toString()，全是横杠分段的那种。

我就顺着这个header往上查，发现这个请求经过了一个网关服务，而网关里有个拦截器，会对这个header做一次MD5计算然后塞到MDC里用于链路追踪。

MD5计算本身不慢，但这个拦截器的实现是这样的：

String requestId = request.getHeader("x-request-id"); if (StringUtils.isNotBlank(requestId)) { // 为了兼容旧版本，对非标准格式的requestId做一次摘要 if (!requestId.matches("^[0-9a-f]{8}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{12}$")) { requestId = DigestUtils.md5DigestAsHex(requestId.getBytes()); } }

这个正则，每次请求进来都要执行一次。大部分请求的requestId都是标准UUID，匹配很快。但那个特殊请求的requestId是不带横杠的短格式，正则引擎在做回溯匹配的时候，复杂度直接起飞了。

再加上那个时间点服务刚重启，JIT还没热身，解释执行模式下这个正则匹配的耗时从纳秒级飙升到了秒级。

问题找到了，改法很简单：把正则匹配改成尝试按UUID格式解析，抛异常就说明不是标准格式，再做MD5。

try { UUID.fromString(requestId); } catch (IllegalArgumentException e) { requestId = DigestUtils.md5DigestAsHex(requestId.getBytes()); }

三行代码，改完测试环境验证通过，预发布验证通过，准备发生产。

有时候顺风顺水反而让人害怕

发生产的流程走了半个多小时——code review、merge、构建镜像、滚动更新。整个过程异常顺利，顺到我心里有点发毛。

果然，上线后五分钟，监控突然弹出一堆告警：错误率飙到15%，全是NullPointerException。

我当时整个人是懵的。改的就是一个拦截器里的小逻辑，怎么干出NPE了？

赶紧回滚。回滚后服务恢复，然后我开始看错误日志。堆栈指向的代码行是：

String traceId = MDC.get("traceId"); Span span = tracer.buildSpan(traceId).start();

traceId是null，所以buildSpan的时候抛了NPE。

那traceId为什么是null呢？因为设置traceId的逻辑就在我改的那个拦截器里，在requestId的基础上又加了一层处理。我改完之后，对于非标准格式的requestId走MD5分支，这个没问题。但问题是我改代码的时候，把一个前置的判断条件顺手优化掉了。

原来的代码是：

if (StringUtils.isNotBlank(requestId)) { // 设置traceId MDC.put("traceId", generateTraceId(requestId)); }

我重构的时候，觉得isNotBlank这个判断跟后面正则匹配的逻辑有重叠，就给合并了，变成了：

java

if (requestId != null && requestId.matches("...")) { // 只对标准格式处理 }

这样非标准格式的requestId就直接跳过了整个逻辑，连MDC都没设置。

更隐蔽的是，之前那个拦截器的逻辑里，即使requestId是空，也会用UUID.randomUUID()生成一个兜底的traceId。我重构的时候把这个兜底逻辑挪到了一个我认为"更合适"的位置，但那个位置在某些异常路径下根本执行不到。

所以结果就是：部分请求的traceId没设置，下游服务拿不到traceId就崩了。

凌晨两点的感悟

问题最终在凌晨两点修复了。改回去三行，加了三行注释，发版，观察了二十分钟，一切正常。

回家路上我在想一个问题：我为什么会在周五下午去动一个看起来"可以优化"但已经在线上跑了两年的代码？

答案其实挺简单的——我看到那段正则匹配的时候就难受，职业病犯了。总觉得"这种写法不优雅""性能有隐患""应该重构一下"。但事实上那个接口的QPS也就200多，那个正则匹配即使是最差情况，对整个系统的影响也微乎其微。

我花了一个小时定位了一个非关键问题，然后用一个不那么稳妥的方案修复了它，最后引入了一个更严重的bug。

你说这事儿怪谁？怪测试没覆盖全？怪CR没看出来？说到底还是怪我自己没守住"线上代码能不动就不动"这条底线，尤其是周五下午四点半这个死亡时间点。

写这段文字的时候已经是周六了。我给自己立了个规矩：以后周五下午三点之后，除了紧急故障，任何代码变更都不做。优化代码这种事儿，留给周三上午脑子最清醒的时候干。

别学我。