上周三晚上十点，我正准备睡觉，手机突然响了，是运维打来的电话。

"线上的AI工具链出问题了，用户反馈生成的文件都是空的，你赶紧看看。"

我一下子就清醒了。这个AI工具链是我们团队最近上线的核心功能，用户上传文档，系统自动解析、调用大模型处理、生成结果文件，整个链路涉及前端、后端、AI服务、存储等好几个组件。上线一周，用户量增长很快，这时候出问题，影响很大。

我打开电脑，连上VPN，开始排查。这一查，就是一整夜，直到第二天早上七点，才终于找到根因，修复上线。

这篇文章，我想记录一下这次排查的过程。从故障发现、初步定位、层层深入到最终找到根因和修复，分享一下排查思路、踩过的坑和总结的经验。如果你也做过全栈或者AI相关的开发，希望这篇文章能给你一些参考。

故障现象：生成的文件都是空的

先说说故障现象。

用户反馈，使用AI工具链处理文档的时候，最后生成的结果文件都是空的，打开之后什么内容都没有。但整个处理流程看起来是正常的，没有报错，状态显示"处理完成"，下载链接也能正常生成，就是下载下来的文件是空的，0字节。

我先登录了线上的管理后台，看了一下监控。果然，从晚上九点半开始，生成的文件大小都是0字节，之前都是正常的，几KB到几MB不等。而且不是个别用户，是所有用户的所有任务，生成的文件都是空的。

这说明不是某个用户的问题，也不是某个文档的问题，而是整个系统的问题，某个环节出了故障，导致所有的生成结果都写不进去。

我先看了一下各个服务的状态。前端服务正常，后端API服务正常，AI推理服务正常，对象存储也正常，CPU、内存、磁盘都没有异常。日志里也没有明显的报错。

这就奇怪了，所有服务都正常，没有报错，但生成的文件就是空的。这种"静默失败"的问题，比直接报错更难排查，因为没有明显的错误信息告诉你哪里出了问题。

我深吸一口气，告诉自己不要慌，一步步来。先把整个链路理清楚，然后逐个环节排查。

第一步：理清链路，缩小范围

排查问题的第一步，是理清整个处理链路，看看数据是怎么流动的，每个环节做了什么，然后逐个环节检查，缩小范围。

这个AI工具链的处理流程是这样的：

  1. 用户在前端上传文档，调用后端API，后端把文件存到对象存储，创建一个处理任务，状态设为"待处理"。
  2. 任务队列消费任务，调用文档解析服务，把文档解析成纯文本。
  3. 把解析后的文本分段，调用大模型API进行处理，比如摘要、翻译、分析等。
  4. 把大模型返回的结果，按照模板格式化成最终的文档内容。
  5. 把格式化后的内容写入结果文件，上传到对象存储。
  6. 更新任务状态为"处理完成"，生成下载链接，通知用户。

整个链路涉及前端、后端API、任务队列、文档解析服务、大模型API、格式化服务、对象存储等好几个组件。

我先看了一下各个环节的日志和数据。

第一步，用户上传文档，没问题，原始文件都正常存到了对象存储里，文件大小正常。

第二步，文档解析，也没问题，解析出来的文本内容正常，长度也正常。

第三步，调用大模型API，返回的结果也正常，内容不为空，长度也正常。

第四步，格式化，把大模型返回的结果按照模板格式化，这一步的输出，日志里显示也是正常的，内容不为空。

第五步，把格式化后的内容写入结果文件，上传到对象存储。这一步，日志显示上传成功，返回了文件URL。

第六步，更新任务状态，生成下载链接，也正常。

所有环节看起来都正常，每一步的输出都不为空，但最后用户下载的文件就是空的。

这就奇怪了，每一步都正常，为什么最后文件是空的？

我决定从最后一步开始往前查。既然最后文件是空的，那要么是上传的时候内容就空了，要么是上传成功了但存储里的文件是空的，要么是下载的时候出了问题。

我先去对象存储里看了一下生成的结果文件。果然，存储里的文件就是0字节。这说明问题出在上传之前或者上传过程中，文件内容在上传的时候就是空的，或者上传过程中内容丢失了。

但第四步格式化的输出，日志里显示是有内容的，长度也正常。那为什么到第五步上传的时候就变成空的了？

我决定仔细看看第五步上传文件的代码和日志。

第二步：深入上传环节，发现异常

我找到了上传文件的代码。这部分代码的逻辑是这样的：

  1. 从上下文里取出格式化后的内容，是一个字符串。
  2. 把字符串转换成字节流。
  3. 调用对象存储的SDK，把字节流上传到指定的bucket和key。
  4. 上传成功后，返回文件的URL。

代码看起来很简单，没什么问题。我又看了一下这一步的日志，日志里打印了上传的文件名、文件大小、返回的URL。

等等，我发现了一个异常。日志里打印的文件大小，是0！

但第四步格式化的输出，日志里明明显示内容长度是正常的，比如几千个字符。为什么到了上传的时候，文件大小就变成0了？

这说明，内容在第四步到第五步之间丢失了。格式化服务返回的内容是正常的，但传到上传服务的时候，就变成空的了。

这两个服务之间是怎么传递数据的呢？我看了一下，是通过消息队列传递的。格式化服务处理完之后，把结果放到消息队列里，上传服务消费消息，取出内容，上传到对象存储。

那问题可能出在消息队列这里。要么是格式化服务放进去的时候内容就空了，要么是上传服务取出来的时候内容空了，要么是消息队列本身丢数据了。

我先去看了一下消息队列里的消息。找了一条最近的消息，看了一下消息体。果然，消息体里的内容字段是空的！

但格式化服务的日志里，明明显示输出的内容是正常的。为什么放到消息队列里就变成空的了？

我决定仔细看看格式化服务发送消息的代码。

第三步：发现序列化的坑

格式化服务发送消息的代码，大概是这样的：

result = format_content(model_output, template)
logger.info(f"格式化完成，内容长度: {len(result)}")

message = {
    "task_id": task_id,
    "filename": filename,
    "content": result,
}
queue.send(json.dumps(message))

看起来很正常，把格式化后的结果放到message的content字段里，然后序列化成JSON，发送到消息队列。

日志里打印的内容长度是正常的，说明result变量是有内容的。那为什么发送到消息队列里content就空了？

我仔细看了一下json.dumps这一行，没发现什么问题。然后我又看了一下消息队列的SDK，也没发现什么异常。

这时候我有点困惑了。代码看起来没问题，日志也没问题，但消息体里的内容就是空的。

我决定在本地复现一下这个问题。我写了一个简单的测试脚本，模拟格式化服务的逻辑，构造一个有内容的result，然后json.dumps，发送到测试队列，然后消费出来看看。

测试结果让我很意外：本地测试是正常的，消息体里的content有内容，不是空的。

这就更奇怪了，本地正常，线上异常。那说明不是代码逻辑的问题，而是线上环境的问题？或者是某些特定条件下才会触发的问题？

我又仔细对比了本地和线上的环境差异。本地用的是测试队列，线上用的是生产队列。本地的Python版本是3.9，线上是3.10。本地的消息队列SDK版本是2.1.0，线上是2.3.0。

等等，SDK版本不一样！线上的SDK版本比本地新。会不会是新版本的SDK有什么变化，导致了这个问题？

我去查了一下消息队列SDK的更新日志。2.2.0版本的更新日志里有一条："优化大消息的处理，默认开启消息体压缩"。2.3.0版本又有一条："修复压缩消息在某些情况下解码异常的问题"。

压缩？解码异常？这会不会和我们的问题有关？

我仔细看了一下新版本SDK的文档。原来，从2.2.0版本开始，SDK默认会对超过一定大小（默认1MB）的消息体进行压缩，发送的时候压缩，消费的时候自动解压。但2.2.0版本有个bug，在某些情况下，压缩后的消息消费的时候解压失败，会返回空内容。2.3.0版本说修复了这个问题，但看起来并没有完全修复，或者我们遇到的是另一个类似的问题。

我们的消息体有多大呢？我看了一下，格式化后的内容，一般是几千到几万字符，序列化之后大概是几KB到几十KB，远小于1MB的压缩阈值。按理说不应该触发压缩啊。

但等等，我突然想到一个问题。我们的消息体里，除了content，还有其他字段吗？我看了一下，没有，就task_id、filename、content三个字段，加起来也就几十KB。

那为什么会触发压缩？或者说，不是压缩的问题？

这时候我有点卡住了。SDK的压缩阈值是1MB，我们的消息远小于这个值，不应该触发压缩。但消息体里的内容确实是空的，而且和SDK版本升级的时间点吻合（我们是上周升级的SDK，正好是上线后一周，故障也是从升级后开始的）。

我决定再仔细看看SDK的源码，或者做个实验。

第四步：根因终于找到了

我写了一个更详细的测试脚本，在测试环境用线上同样版本的SDK，发送不同大小的消息，看看会不会出现空内容的问题。

测试了1KB、10KB、100KB、500KB、1MB的消息，都正常，没有出现空内容的问题。

这就奇怪了，测试环境正常，线上异常。那到底是什么导致的？

这时候已经是凌晨三点了，我有点疲惫，但还是告诉自己再坚持一下。我决定再仔细看看线上的消息，看看有没有什么规律。

我找了几十条线上的空内容消息，仔细分析。突然，我发现了一个规律：这些消息的content字段，虽然是空的，但消息体的总大小并不是0，而是有几百字节。而且，task_id和filename字段都是正常的，只有content是空的。

这说明，消息体本身是正常的，序列化和反序列化也正常，只是content字段的值是空的。也就是说，格式化服务在构造message的时候，content字段就是空的？

但格式化服务的日志里，明明打印了内容长度是正常的啊？

等等，日志里打印的是len(result)，也就是格式化结果的长度。但message里的content字段，真的是result吗？

我又仔细看了一遍格式化服务的代码。突然，我发现了一个问题。

代码是这样的：

result = format_content(model_output, template)
logger.info(f"格式化完成，内容长度: {len(result)}")

message = {
    "task_id": task_id,
    "filename": filename,
    "content": result,
}

看起来没问题，content就是result。但等等，format_content函数返回的是什么类型？我看了一下函数定义，返回的是str。那len(result)应该是字符数，没问题。

但我突然想到，会不会是变量名冲突？或者result在后面被修改了？我看了一下，构造message之前，result没有被修改。

这时候我真的有点绝望了。代码看起来完全没问题，但线上就是出问题。

我决定加更详细的日志，重新部署一个版本，看看构造message的时候content到底是不是空的。

但重新部署需要时间，而且是线上环境，不能随便部署。我决定先在测试环境用线上的配置和数据跑一遍，看看能不能复现。

我把线上的一个任务数据导出来，在测试环境跑。结果，测试环境也复现了！格式化服务的日志显示内容长度正常，但消息队列里的content就是空的！

太好了，能复现就好办了。我在测试环境加了详细的日志，在构造message之前和之后，分别打印result的内容、类型、长度，以及message['content']的内容、类型、长度。

日志结果让我大吃一惊：构造message之前，result是正常的，有内容，类型是str；但构造message之后，message['content']居然是空的！

这怎么可能？明明是把result赋值给content，为什么赋值之后就空了？

我仔细看了一下代码，突然发现了问题所在。

原来，formatcontent函数返回的不是普通的str，而是一个自定义的字符串子类！这个子类是我们项目里定义的，叫LazyString，它的特点是懒加载，实际的内容存在一个内部的content属性里，只有在需要的时候才会真正加载。

len(LazyString)是正常的，因为它重写了len方法，返回内部_content的长度。str(LazyString)也是正常的，因为它重写了str方法，返回内部的内容。

但是！json.dumps的时候，它不会调用str方法，而是会检查对象的类型。对于str的子类，json.dumps会直接把它当成str处理，但它取的是对象内部的字符串缓冲区，而不是调用str方法！

而LazyString这个子类，内部的字符串缓冲区是空的，实际内容存在_content属性里。json.dumps的时候，取到的就是那个空的字符串缓冲区，所以序列化之后content就是空的！

而len(result)正常，是因为LazyString重写了len，返回的是_content的长度。日志里打印的长度是正常的，但实际序列化的时候，取到的是空内容！

这就是根因！

为什么之前没问题？因为之前我们用的是旧版本的消息队列SDK，发送消息的时候，SDK会先对消息体做一次str()转换，把LazyString转换成普通的str，然后再序列化。所以之前是正常的。

但上周我们升级了SDK版本，新版本的SDK为了提升性能，去掉了那一步str()转换，直接把dict传给json.dumps。结果，LazyString没有被转换成普通的str，json.dumps直接处理，取到了空的字符串缓冲区，所以content就空了！

本地测试为什么正常？因为本地测试的时候，我用的是普通的str，不是LazyString，所以没问题。

找到根因之后，修复就很简单了。在构造message的时候，把result强制转换成普通的str：

message = {
    "task_id": task_id,
    "filename": filename,
    "content": str(result),
}

或者在format_content函数里，直接返回普通的str，不要返回LazyString。

我改了代码，在测试环境验证了一下，问题解决了，消息体里的content正常了。然后紧急修复上线，凌晨七点，线上恢复正常，生成的文件不再是空的了。

排查过程中踩过的坑

回顾这次排查，我踩了好几个坑，也走了不少弯路。

第一个坑，是太相信日志。格式化服务的日志里打印了内容长度，显示正常，我就想当然地认为内容是正常的，没有怀疑content本身有问题。结果，日志里的len()是正常的，但实际序列化的内容是空的，因为LazyString的len和str表现不一致。

教训：日志不能只打印长度，关键内容要打印实际的值（或者前几个字符），确认内容真的是正常的。特别是对于自定义类型，更要小心，它的各种魔法方法可能表现不一致。

第二个坑，是一开始怀疑错了方向。最开始我怀疑是对象存储的问题，然后怀疑是上传服务的问题，然后怀疑是消息队列丢数据，然后怀疑是SDK压缩的bug，绕了一大圈，最后才发现是序列化的问题。

教训：排查问题要从现象出发，一步步缩小范围，不要凭经验猜测。每一步都要有证据，不要想当然。这次如果我一开始就仔细检查消息体的内容，可能会更快发现问题。

第三个坑，是本地测试没有复现。因为本地用的是普通str，不是LazyString，所以本地测试一直正常，导致我一度以为是线上环境的问题，走了很多弯路。

教训：本地测试要尽量模拟线上的真实环境，包括数据类型、配置、依赖版本等。不要用简化的测试数据，要用真实的、完整的数据来测试，才能复现线上的问题。

第四个坑，是依赖升级没有充分测试。这次问题的直接原因，是升级了消息队列SDK版本，新版本去掉了str()转换，触发了LazyString的问题。但升级的时候，我们只做了简单的功能测试，没有做完整的回归测试，没有发现这个问题。

教训：依赖升级是高风险操作，一定要做充分的回归测试，覆盖所有的使用场景。特别是核心依赖的升级，更要谨慎，最好先在测试环境跑一段时间，确认没问题再上线。

第五个坑，是自定义类型的使用不规范。LazyString这个自定义类型，虽然实现了len和str，但没有处理好json序列化的问题，导致在json.dumps的时候表现异常。这种自定义类型，如果要在系统间传递，一定要确保它能被正确地序列化和反序列化。

教训：尽量不要自定义基础类型的子类，特别是str、list、dict这些，如果一定要自定义，一定要充分测试各种使用场景，包括序列化、比较、拼接等，确保行为和普通类型一致。

总结的经验

这次通宵排查，虽然很辛苦，但也让我学到了很多。总结一下经验。

第一，线上故障排查，要有系统化的思路。

不要一上来就乱猜，要先理清整个链路，然后从现象出发，一步步缩小范围，逐个环节排查。每一步都要有证据，用日志、数据、测试来验证你的假设，不要凭经验和感觉。

可以用二分法，先确定问题出在链路的前半段还是后半段，然后再继续二分，快速缩小范围。也可以用对比法，对比正常和异常的情况，对比本地和线上的差异，找出不同点，往往不同点就是问题所在。

第二，日志和监控要完善。

这次排查，日志帮了很大的忙，但也因为日志不够详细，走了很多弯路。完善的日志和监控，是快速排查问题的基础。

日志要记录关键环节的输入输出，包括内容的实际值（或者摘要）、类型、长度、耗时等。不要只打印"处理成功"，要打印足够的信息，方便排查问题。监控要覆盖各个环节，包括成功率、失败率、耗时、数据量等，出现异常的时候能及时告警。

第三，要重视静默失败。

这次故障的特点是"静默失败"，所有服务都正常，没有报错，但结果是错的。这种问题比直接报错更难排查，也更容易被忽视。

在设计系统的时候，要尽量避免静默失败。每一步都要做校验，发现异常要及时报错和告警，不要默默吞掉错误。比如，上传文件之后，要校验文件大小，如果是0字节，就要报错，不要认为上传成功了。如果这次上传之后校验了文件大小，发现是0字节就报错，那故障会更早被发现，排查也会更容易。

第四，依赖升级要谨慎。

这次问题的直接原因是依赖升级。在日常开发中，我们经常会升级各种依赖，包括SDK、库、框架等。每次升级，都可能引入不兼容的变化，导致意想不到的问题。

升级依赖之前，要仔细看更新日志，了解有哪些变化，特别是不兼容的变化和行为变化。升级之后，要做充分的回归测试，覆盖所有的使用场景。核心依赖的升级，最好先在测试环境跑一段时间，确认没问题再上线。

第五，代码质量和规范很重要。

这次问题的根源，是自定义的LazyString类型在json序列化时表现异常。如果代码更规范，不自定义这种有坑的类型，或者充分测试了各种场景，这个问题就不会发生。

在开发中，要尽量使用标准类型和标准做法，不要过度设计，不要为了炫技而使用复杂的自定义类型。代码要简单、清晰、易懂，复杂的地方要有充分的注释和测试。代码质量高了，bug自然就少了。

第六，要保持冷静和耐心。

线上故障排查，特别是深夜排查，人很容易焦虑和急躁。越急越容易出错，越容易走弯路。这时候一定要保持冷静，有条不紊地一步步排查。

遇到卡住的时候，不要死磕，可以换个思路，或者休息一下，喝点水，让大脑清醒一下。很多时候，问题的答案就在你放松的时候突然冒出来了。

写在最后

这次线上故障，我排查了一整夜，从晚上十点到第二天早上七点，终于找到了根因，修复上线。

虽然过程很辛苦，熬了一夜，第二天还得继续上班，但解决问题之后的那种成就感，是无法用语言形容的。而且，通过这次排查，我对整个系统的理解更深了，也积累了宝贵的排查经验。

做开发，线上故障是不可避免的。重要的不是不出故障，而是出了故障之后，能不能快速定位、快速修复，并且从故障中学习，避免以后再犯同样的错误。

每一次故障，都是一次成长的机会。认真对待每一次故障，做好复盘，总结经验，你会变得越来越强。

最后，用一句话来结束这篇文章："排查bug的过程，就像侦探破案，需要细心、耐心和逻辑。每一个bug背后，都有一个等待被发现的故事。"

愿每一个开发者，都能少遇bug，遇到bug也能快速解决，睡个好觉。