1. 引子：凌晨三点十七分的陌生告警
凌晨 3 点 17 分 28 秒，几乎每隔一天，归档日志里就会出现一次同样的告警。时间稳定得吓人，前后误差不超过两秒。我在做历史日志迁移时接触到这批 2010 年的数据——sess_srv 是当时线上运行的会话状态服务，维护一批 TCP 长连接上的会话，连接断开时负责收尾清理。迁移本来只是把 syslog 灌进新的检索平台，顺手做了一次消息模板聚类，结果所有告警都能在源码对应的日志语句里找到归属，唯有一条落空：
2010-11-02 03:17:28.304 32241:32241 WARN session.cpp:124 session_finalize: rsv not empty (count=7, last_task=0)我在整个代码仓库里grep -R "rsv not empty"，零命中。git grep --all把全部分支翻遍，还是零命中。可日志里明明白白写着session.cpp:124，说明编译进生产二进制的这份session.cpp，和源码仓库里现在的这份根本不是同一份。这就留下了一处"可疑的痕迹"：程序运行时的行为，与我手上掌握的全部源码都对不上。
这篇记录的是我如何沿着这条痕迹做了一次完整的代码回溯——从二进制考古开始，到反汇编、调用链回溯、git 历史翻找，再到复现验证和收尾处理。整个过程下来你会发现，所谓回溯代码，很多时候不是在逆向所谓的"恶意攻击"，而是在还原一段被遗忘的时间线。这是《回溯代码》系列的第二集，上一集我们处理的是服务启动阶段的段错误，这次则是另一类问题：一段生产环境里真实运行、但源代码里完全不存在的逻辑。
2. 先确认二进制身份：怎么判断"版本号相同，产物不同"
2.1 版本号相同，md5 不同
排查这类问题时，第一个容易踩的坑就是依赖版本号判断"生产二进制 == 源码仓库状态"。那台 2010 年的 sess_srv 有个启动 banner：
SESS_SRV 3.2.1 BUILD_TS=20100915而仓库里 3.2.1 这个 tag 对应的源码，理论上构建出来的也是SESS_SRV 3.2.1。单看版本号，二者一致；但md5sum一对比，立刻分道扬镳：
| 项目 | 生产二进制 | 重新构建产物 |
|---|---|---|
| md5 | c4e321... | 98a40f... |
| 版本号 | 3.2.1 | 3.2.1 |
| 构建时间字符串 | 20100915 | 20101120 |
同样的版本号，不同的哈希。说明生产上跑的二进制，不是从当前仓库的 3.2.1 源码构建出来的，甚至可能不是从任何一条已被记录的提交构建的。这一步很关键，原因在于：正因为版本号没有跟着代码变化，团队里没有任何一个人会注意到生产行为和源码已经脱节。这是"痕迹"能够潜伏一年多的直接前提。如果当年构建系统把 git 修订号嵌进版本字符串，这种异常会在发布对比的那一刻就被发现。
2.2 没人认识的日志字符串，先问二进制
既然源码里找不到那个字符串，下一步就要直接问生产二进制本身。老规矩，先做只读侦查，不急着上 gdb：
strings -t x /export/servers/sess_srv/bin/sess_srv | grep "rsv not empty" strings -t x /export/servers/sess_srv/bin/sess_srv | grep "last_task" file /export/servers/sess_srv/bin/sess_srvstrings加上-t x可以拿到字符串在文件里的十六进制偏移，配合 ELF 节区信息能定位到它处在.rodata的位置。file的输出确认了这是 32 位 ELF 可执行文件。接着用nm拿到函数入口，用objdump反汇编出来看逻辑：
nm -a sess_srv | grep session_finalize objdump -d --start-address=0x08054a20 --stop-address=0x08054c00 sess_srv > finalize.asm那个年代内部服务普遍带符号发布，nm直接给了入口地址，省去了从裸机器码猜函数名的功夫。readelf -n sess_srv看完两个细节，我心里基本有数了：这个二进制没有 build-id，注释段写着GCC: (GNU) 4.4.5。没有 build-id 意味着 ELF 文件本身没有唯一身份标识，厂商和构建信息缺失，这让"产物与源码一一对应"彻底失去抓手。GCC 4.4.5 这个版本倒与 2010 年第三季度的服务器环境对得上。
2.3 反汇编里多出一块"不属于源码"的代码
拿到session_finalize的函数地址后，我用addr2line做了一次地址到源码行的映射：
addr2line -e sess_srv 0x08054b10它吐回session.cpp:124。这个行号，和告警日志里__LINE__打出来的 124 完全一致。再往外圈一小块区域，映射到的源码行号一直延续到 142 行，而当前源码里session_finalize只写到 96 行就结束了。
把反汇编里那段多出来的代码摘出来简化一下，长这样：
0x08054b10: 83 7d f4 00 cmpl $0x0, -0xc(%ebp) ; rsv_index 0x08054b14: 74 20 je 0x08054b36 ; 为 0 则跳过 0x08054b16: 8b 45 f8 mov -0x8(%ebp), %eax ; session 指针 0x08054b19: 8b 80 1c 04 00 00 mov 0x41c(%eax), %eax ; g_task_table ... 0x08054b30: e8 ... call log_printf ; 打印 "rsv not empty" 0x08054b36: c9 leave这不是编译优化产生的差异，而是真正的逻辑增量：函数里平白多了一个判断、一个遍历、一个日志分支。而它引用的g_task_table是个文件内的 static 全局变量，符号在nm里是小写t，说明这段逻辑完全没有对外导出，像是被人直接塞在里面、不想让外部察觉的一样。到了这一步，"源码里找不到的日志"已经变成"源码里找不到的函数"。下一步要解决的是：这个函数到底在清理什么，以及它为什么偏偏在凌晨三点十七分被触发。
3. 顺着调用链回溯：rsv 字段与一段被删掉又复活的逻辑
3.1 rsv 是什么：翻结构体定义才明白
要读懂那段反汇编，得先弄清楚rsv字段是什么。2010 年的session.h里结构体定义很朴素：
struct session { int fd; int state; int rsv; /* 保留的任务计数 */ task_node *tasks; /* 实际任务链表 */ int last_task; };注释写着"保留的任务计数"，但从 3.2 分支开始，rsv实际上已废弃：新代码不再依赖它分配任务槽位，任务的增删都走tasks链表。反汇编里那段逻辑却还在用rsv判断"是否有未清理任务"，显然是旧设计留下的行为残影。正常会话收尾时，rsv应该是 0，任务链表为空，所以那段多出来的逻辑会直接je跳过。只有当某些异常路径让rsv非零地进入session_finalize时，警告才会炸出来。
3.2 用 gdb 抓真实调用链：为什么偏偏是 03:17
静态反汇编只能说明"存在这段代码"，不能说明"谁在什么时机调用它"。为了搞清楚 03:17 这个诡异的触发时机，我在一个可控的测试环境里布置了同样的二进制，按历史日志提供的线索，模拟了一次上游网关的定时维护。方案是在实时系统里对session_finalize下断点，等告警路径触发后直接backtrace：
(gdb) break session_finalize (gdb) continue Breakpoint 1, session_finalize (s=0x8a4c2c0, rsv_index=7) at session.cpp:124 (gdb) bt #0 session_finalize (s=0x8a4c2c0, rsv_index=7) at session.cpp:124 #1 0x08057b30 in abort_session_by_peer (s=0x8a4c2c0) at session.cpp:177 #2 0x0805d1a0 in peer_reconnect (link_id=3) at peer.cpp:340 #3 0x0806f010 in event_loop () at main.cpp:88这条调用链把时间疑点解释清楚了：每天 03:17 前后，上游网关做例行维护，会主动断开一批旧连接并重连。peer_reconnect触发后，服务要清理所有建立在这个连接上的会话，走abort_session_by_peer最终进入session_finalize。正常情况下，被中断的会话任务已经被事件循环提前处理完，rsv归零；但 2010 年新上线的一版客户端协议存在消息乱序，会把"任务下发"和"会话确认"的顺序调换，导致 session 状态机里rsv被加一却没有立刻减一。流程一被中断，残值就留在了session_finalize的门口。这就是典型的栈回溯场景：问题不在告警这一层，而在调用链上方的peer_reconnect以及更上层的协议乱序。只看日志的话，会一直以为session_finalize有 bug，实际它只是在给上游的乱序买单。
3.3 git 历史里找到了"被蒸发"的提交
接下来是代码考古最有意思的一步：既然生产二进制里有这段逻辑，源码仓库里却没有，那这段逻辑总有一个来源。我把注意力放到 2010 年第三季度的提交历史上：
git log --all --oneline -- session.cpp git reflog show --date=iso git fsck --lost-found在git reflog的一条末端记录里，找到一个早已被删除的分支2010-hotfix-session，其上有一个提交7e91c4d，提交信息写的是"drain rsv counter before finalize"。git show 7e91c4d的内容和反汇编出来的逻辑几乎一一对应：遍历rsv计数范围内的残留任务，释放掉，再打一条警告日志。时间线拼出来是这样的：
| 时间 | 事件 |
|---|---|
| 2010-08-12 | 主干提交ca84201，删除了旧的rsv计数路径 |
| 2010-09-03 | 有人基于旧状态拉分支，写了drain_stale_tasks补丁 |
| 2010-09-15 | 生产二进制从该分支构建并部署，banner 日期即BUILD_TS=20100915 |
| 2010-09-27 | 分支被删除，补丁从未合并回主干，源码从此"蒸发" |
| 2010-11 起 | 新客户端协议上线，乱序概率上升，告警频率开始抬头 |
也就是说，那段"可疑的痕迹"不是攻击者埋的，也不是后门，而是一个没有走正规流程的线上热修复。团队里查了一圈，没人记得这件事。所有人都默认生产二进制和主干源码等价，这种"代码漂移"在长寿命服务里太常见了。
3.4 先排除恶意，再谈宿命
当然，面对一段反汇编出来的陌生逻辑，第一反应必须是在"良性热修复"和"可疑恶意代码"之间做个快速排查。我当时的检查路径是：
- 是否有网络外联行为？反汇编里没有
socket、send、connect调用。 - 是否有文件写入或敏感的 shell 调用？只有
log_printf一条日志出口。 - 是否被导出成公共接口？
nm里是小写t，即文件内 static，外部无法按符号调用。 - 逻辑语义是否自洽？遍历
rsv残留并释放，符合防御式清理的动机。
四条硬件排查加一条语义分析，结论基本能定下来：这是一段防御性质的历史补丁，不是外联后门。但这个结论不能靠猜——后面必须用复现验证闭环，这也是第四步要做的事。
4. 复现验证：让老痕迹在可控环境里再露一次面
4.1 老环境的坎：缺库、缺工具链、缺时代感
复现的前提，是我先把 2010 年那台机器的运行环境搭出来。刚开始我直接在现网开发机上跑生产二进制，结果弹了这么一句：
error while loading shared libraries: libssl.so.0.9.8: cannot open shared object file这句和 Windows 上常见的"由于找不到 msvcp140.dll，无法继续执行代码"本质上是同一类问题：二进制依赖的运行时库已经不在当前环境里。2010 年的 sess_srv 是 32 位编译，依赖老版 OpenSSL、老版运行时，年代感拉满。解决办法是搭了一个基于旧发行版镜像的容器，装回 GCC 4.4、binutils 2.20 和配套的 32 位运行库。这一步千万别省：用新工具链强行重编老代码，编译器优化行为、结构体对齐、库函数签名都可能发生变化，最后对比 md5 时你会得到一堆假阴性/假阳性。
4.2 把缺失源码补回去，让 md5 闭环
复现这件事的好处是，它逼着我把"猜测"变成"证据"。我从 git 分支提交7e91c4d里拿回那段drain_stale_tasks，合进当前 3.2.1 源码，用老工具链重新构建。构建完第一件事就是比对：
md5sum sess_srv /export/servers/sess_srv/bin/sess_srv两边哈希相等。这段逻辑确实就是生产二进制里那段逻辑的来源。此时我已经不是通过反汇编猜测它"可能长这样"，而是确认它"就是长这样"。然后再跑一轮带消息乱序的测试用例，模拟上游网关定时维护。断点重新触发，rsv not empty (count=7, last_task=0)的日志如期出现，调用链也和反汇编、历史日志三方对上。到这里，"可疑的痕迹"的来龙去脉已经闭环。
4.3 复现暴露出的真正问题：不是代码坏了，是链路断了
复现完成之后，我再回头看那个"版本号既相同又不同"的尴尬，意识到真正危险的并不是这段额外逻辑本身，而是整个构建链路上缺少了可追溯性。2010 年的构建脚本没有嵌入 git 修订号，发布流程里没有"源码树必须干净"的检查，合并纪律也允许热修复走野路子。生产二进制的BUILD_TS只能告诉我们"什么时候构建的"，不能告诉我们"从什么代码构建的"。这个结论直接决定了第五步的处理方案——不是简单删掉那段代码，而是把追溯能力补回来。
5. 处理方案与给后来人的排查手册
5.1 三路取舍：入库、回滚、还是归档
面对"生产有、源码无"的差异，通常有三条路可走：
| 方案 | 适用场景 | 我的取舍 |
|---|---|---|
| 把热修复正式合入源码 | 行为对线上稳定有实质帮助 | 选择此方案 |
| 用干净源码重建并覆盖 | 生产行为属于历史包袱 | 否，因为缺少清理会导致任务残留 |
| 保留二进制、写清差异归档案 | 无法确认行为来源 | 否，因为 md5 已闭环 |
最终我选择的不是"回到源码的干净状态"，而是"让源码长成和生产一致的样子"——把drain_stale_tasks正式合回，同时补上边界检查、注释和测试用例，记录它存在的业务原因。对已经稳定运行多年的线上服务，宁可让代码库明明白白地"丑"，也不要让线上行为悄悄地和代码库"分家"。
5.2 代码审计中的快速检查清单
整理一下这次排查沉淀出的动作，以后遇到类似"找不到日志来源"的痕迹，可以按这个顺序推进：
- 先在消息模板层聚类，列出所有"源码中无归属"的日志模板。
- 对比线上二进制与 CI/发版产物：
md5sum、build-id、strings里的编译时间。 - 检查二进制调试信息里的源码路径，
addr2line指到的源码行号若与日志里不一致，立刻集中关注。 - 用
git log --all、git fsck --lost-found、git reflog把孤儿分支和已删提交捞出来。 - 用 gdb 在触发条件上打断点拿
backtrace，把"何时调用"与"为何触发"钉死。 - 先做恶意代码排除（网络、文件、shell、导出符号），再做良性热修复定性。
5.3 一点个人体会
代码考古做到最后，收获往往不只在某一处 bug。这台服务提醒我的事很简单：构建系统里一定要记录"从哪个提交构建"，-Wl,--build-id必须开，启动日志里要打出完整修订号，版本号字符串不能只写"3.2.1"这三个字。那条凌晨三点十七分的告警之所以能潜伏一年多，不是因为它藏得深，而是因为我们没有给它留下一把能对上号的钥匙。至于那段被"蒸发"的代码，后来我给它补了充分的注释和单测，正式合并回主干。它从一个没有身份的野补丁，变成了有史可查的正常代码。代码里最可疑的痕迹，往往不是别人故意留下的陷阱，而是一个团队忘了收尾的半成品——只要沿着调用链和提交历史认真回溯，总能找到它原本的主人。
