Debug 记录：一个缺失的“\0”和一个意外的“%”引发的挂死

在最近的实习过程中，遇到了一个上线模块的挂死问题，经排查发现这是一次由数据源头污染、内存越界读取以及格式化字符串漏洞三者巧合叠加引发的教科书级 Crash。这里记录一下这个问题的发现与解决过程。

1. 案发现场#

模块挂死，我拿到的是一个 core dump 文件，使用 gdb 查看崩溃堆栈，主要内容如下：

[Current thread is 1 (Thread 0xffff8effd090 (LWP 9372))]
(gdb) bt
#0  raise (sig=6) ...
#1  <signal handler called>
#2  __GI_raise (sig=sig@entry=6) ...
#3  0x0000ffffa117c974 in __GI_abort () at abort.c:79
#4  0x0000ffffa11b572c in __libc_message ...
#5  0x0000ffffa11b5778 in __GI___libc_fatal (message=0xffffa12705d0 "*** %n in writable segment detected ***\n") at ../sysdeps/posix/libc_fatal.c:191
#6  0x0000ffffa1191288 in _IO_vfprintf_internal (format=... "[tte_app] event_id: ...LK6ADAE45RB756122% not found...\n", ...) at vfprintf.c:1642
...
#14 0x0000aaaadfe70f48 in tte::OnboardServiceApp::flQueryRecordVoiceCallback ...

plaintext

重点是 frame #5 的错误信息：%n in writable segment detected，查阅资料发现，这是 Linux glibc 的一种安全保护机制。它意味着 printf 系列函数在解析格式化字符串时，发现在可写的内存段（堆或栈）中出现了 %n。由于 %n 会将已打印字符数回写到内存，极易被黑客用于覆盖栈数据，所以 glibc 检测到这种情况会直接让进程自杀。

2. 代码回溯#

根据堆栈，崩溃发生在 flQueryRecordVoiceCallback 函数中。我找到了对应的业务代码：

// 崩溃所在的业务逻辑
int32_t OnboardServiceApp::flQueryRecordVoiceCallback(
    dcos::ConstMsg<sys_msgs::tte_service::VoiceStatusReq> const& req) {

  // ... 前面是初始化代码 ...

  // 直接强制转换原始字节流为 string
  std::string target_event_id =
      std::string(reinterpret_cast<const char*>(req->event_id));

  LOG_INFO(tte_header, "query event_id: %s\n", target_event_id.c_str());

  // 在锁内查找 event_id ...
  {
    std::lock_guard<std::mutex> l(resource_mutex_);
    for (auto it = process_tree_list_.begin(); it != process_tree_list_.end(); ++it) {
       // ... 省略查找逻辑 ...
       if (event_id == target_event_id) {
         // ... 找到后返回成功 ...
         return 0;
       }
    }
  }

  // [崩溃点] 未找到 ID，打印警告日志
  LOG_WARN(tte_header, "event_id: %s not found, returning error status\n",
           target_event_id.c_str());

  // ... 返回错误 ...
  return 0;
}

cpp

结合堆栈信息，崩溃点是在这个函数的 LOG_WARN 语句处，字符串里混入了一个诡异的 %，而且它后面紧接着 not found。

3. 根因分析#

经过一步步分析，发现这里发生了三个致命巧合，导致了模块的崩溃。

3.1 第一环：缺失的终止符 `\0`#

首先 target_event_id 里面出现 % 是意料之外的，正常来说应该只有数字和字母，VoiceStatusReq 结构体定义如下：

constexpr int32_t kEventIdSize{128};

struct VoiceStatusReq {
  uint8_t event_id[kEventIdSize];
} __attribute__((packed));

cpp

req->event_id 是一个固定大小的数组，发送方在填充这个数组时，没有在实际的 event_id 字符串末尾添加字符串终止符 \0。因此当我们直接将其转换为 std::string 时：

std::string target_event_id = std::string(reinterpret_cast<const char*>(req->event_id));

cpp

在接收端的代码中，std::string 的构造函数会从首地址一直往后读，直到读到内存里的某一个 0x00 为止。这一次刚好读到了栈上的垃圾数据。而在这些垃圾数据中，恰好有一个字节是 0x25（即 ASCII 码 %）。是的，发送方一直都没有做这个处理，其实接收方解析出来的 event_id 很多都是乱码，但是因为没有影响到业务，所以一直没被发现。

3.2 第二环：日志函数的“二次格式化”漏洞#

拿到带有乱码的 target_event_id 后，程序执行到了最后的 LOG_WARN。日志库的封装大概是这样的：

void Log(dlog::LogLevel level, const std::string& prefix, const std::string& fmt, ...) {
  // 1. 第一步格式化：将用户参数拼接到 buffer
  char buffer[8192];
  va_list args;
  va_start(args, fmt);
  vsnprintf(buffer, sizeof(buffer), fmt.c_str(), args); // 这里生成了包含 "%" 的 buffer
  va_end(args);

  std::string formatted_msg = "[" + prefix + "] " + buffer;

  // 2. 第二步格式化：致命错误发生在这里
  // logger->Print 的底层是 printf 风格的变参函数
  // 这里直接把包含 "%" 的动态内容当成了 format string
  logger->Print(level, formatted_msg.c_str()); 
}

cpp

在 vsnprintf 完成拼接后，buffer 的内容变成了： ...LK6ADAE45RB756122% not found...。接着，logger->Print 被调用，它底层依赖 printf 逻辑。它拿这个 buffer 当作格式化字符串去解析。

3.3 第三环：致命的 `%n`#

当 printf 解析到 ...% not found 时：

它看到了 %。
它忽略了后面的空格（在某些实现或复杂上下文中），或者因为字符串处于可写段引起了警觉。
它看到了 n。
% + n = %n。这是一个合法的格式控制符，意为“将已输出字符数量写入指针”。但由于这个字符串是在栈上动态生成的，glibc 判定这是一次格式化字符串攻击尝试，直接 Abort。

4. 意外发现#

在审查日志库底层代码时，我还发现了一个可能导致架构级崩溃的隐患。原有的日志接口定义如下：

void Log(dlog::LogLevel level, const std::string& prefix, const std::string& fmt, ...) {}

cpp

C++ 标准明确规定：传递给 va_start 的最后一个固定参数如果是引用类型，则是未定义行为。虽然在 x86 上可能侥幸能跑，但在 ARM64 等架构下，这会导致 va_list 指针计算错误，无法获取后续参数，甚至导致野指针访问。

5. 问题修复#

首先是修复日志库的格式化漏洞，永远不能信任动态拼接的字符串，必须显式指定格式：

// logger->Print(level, buffer); 错误
logger->Print(level, "%s", buffer);// 正确

cpp

同时将日志接口的 fmt 参数类型从 const std::string& 改为 const char*，确保 va_start 行为符合标准。

在业务层，不能假设网络发来的数据一定以 \0 结尾，需要限制一下读取的最大长度：

size_t len = strnlen(reinterpret_cast<const char*>(req->event_id), kEventIdSize);
std::string target_event_id(reinterpret_cast<const char*>(req->event_id), len);

cpp

6. 总结#

这个 LOG_WARN 的崩溃，实际上是一个完美的连锁反应：

发送端少发一个 0。
接收端越界读取到了 %。
日志库错误地对内容进行了二次解析。
乱码 % 恰好碰上了固定文案里的 n。

这四个环节缺一不可，才导致了这个崩溃。因此在日常的开发中，要建立防御性编程的意识，不要信任网络包，不要信任内存里的数据，更不要把用户输入直接传给 printf。