容器里 init 崩了却查不到日志：用 strace 抓启动现场

背景：commit 046e29a6（“修正 K8S 运行时 & 兼容 Docker 运行时”）改了 __system_property_area_init 相关逻辑，合入后容器环境的 Android 起不来。
现象：进容器 sh 看进程列表，没有 init 进程；logcat 空、dmesg 空、tombstone 没有——什么日志都没留下。
结局：靠把启动命令换成 strace init 抓到了现场。

一、背景：046e29a6 到底改了什么

Android 的系统属性（getprop / setprop 背后那套）不是普通文件，而是一块共享内存区域（/dev/__properties__），init 负责创建它，所有进程 mmap 同一块来读写。init 启动时要调：

// bionic/libc/bionic/system_property_api.cpp:57-64（046e29a6 之后）
int __system_property_area_init() {
  bool fsetxattr_fail = false;
  return system_properties.AreaInit(PROP_DIRNAME, &fsetxattr_fail) && !fsetxattr_fail ? 0 : -1;
}

创建这块区域时要给它打 SELinux 标签，用的是 fsetxattr(fd, "security.selinux", ...)。在容器里这一步必然失败——容器跑在宿主的 SELinux 策略上，策略里没有 guest（Android）那套 property label，fsetxattr 会报错。

046e29a6 做的事，是把"打标签失败"分成两类：

// bionic/libc/system_properties/prop_area.cpp:55-76（新增）
static bool IsEnvironmentalLabelingErrno(int err) {
  switch (err) {
    case EPERM:         // 没有 CAP_SYS_ADMIN，比如跑在 user namespace 里
    case EINVAL:        // 当前策略没定义这个 label，容器跑宿主策略就是这样
    case EOPNOTSUPP:    // 底层文件系统不支持 xattr
      return true;      // ← 环境问题，放行
    default:
      return false;     // ← 比如 EACCES(avc denied)，真标签错误，必须让 init 死
  }
}

以及置位逻辑：

// bionic/libc/system_properties/prop_area.cpp:105-111（改后）
if (fsetxattr_failed && !IsEnvironmentalLabelingErrno(err)) {
    *fsetxattr_failed = true;     // 只有"真错误"才把失败标志传回去
}

设计意图很清楚：环境性失败放行，真错误才让 init 死。但这个分类一旦和实际环境对不上——比如容器里实际返回的是 EACCES 而不是 EINVAL——__system_property_area_init() 就会返回 -1，init 跟着死。

而它在 init 里的调用点是：

// system/core/init/property_service.cpp:1449-1458
void PropertyInit() {
    ...
    mkdir("/dev/__properties__", S_IRWXU | S_IXGRP | S_IXOTH);
    CreateSerializedPropertyInfo();
    if (__system_property_area_init()) {
        LOG(FATAL) << "Failed to initialize property area";   // ← FATAL = abort
    }

PropertyInit() 由 system/core/init/init.cpp:1044 调用，位置在第二阶段早期——此时 init 还没进入事件循环，logd 作为 init 启动的子服务根本还没起来。

二、场景：init 消失了，日志一条没有

2.1 现象

容器起不来，但因为 entrypoint 不是 init（base_box.sh 里 $RUNTIME_CMD run ... $IMAGE_NAME sh，entrypoint 是 sh，init 是后续被 /init.sh 拉起来的子进程），所以：

docker exec -ti <box> sh
# ps -A | grep init
# （空）—— init 崩了，sh 还活着，所以还能进来看

ps 里没有 init，基本可以断定 init 在很早的阶段就退出了。问题是它死在哪、为什么死，一条线索都没有：

logcat -d          # 空（logd 是 init 启动的，init 死了它没机会起）
dmesg | grep init  # 空或无关
ls /data/tombstones/  # 空（debuggerd 也是 init 启动的）
docker logs <box>  # 空

2.2 为什么日志会全断

这是本篇最值得记的一点：init 早期阶段，三条可能的日志通道是依次断掉的。

flowchart TD
    A["init 启动"] --> B["第一阶段早期<br/>日志走默认 stderr"]
    B --> C["first_stage_init.cpp:416<br/>SetStdioToDevNull()"]
    C --> D["stderr → /dev/null<br/>通道① 断"]
    D --> E["first_stage_init.cpp:419<br/>InitKernelLogging()"]
    E --> F["日志改走 /dev/kmsg<br/>通道② 容器里写不进<br/>(Operation not permitted)"]
    F --> G["init.cpp:1044 PropertyInit()<br/>__system_property_area_init 失败"]
    G --> H["property_service.cpp:1457<br/>LOG(FATAL) → abort"]
    H --> I["logd 由 init 启动<br/>此刻还没起 → 通道③ 断"]
    I --> J["三条通道全断<br/>现场无任何日志"]

    style D fill:#f9d0d0
    style F fill:#f9d0d0
    style I fill:#f9d0d0
    style J fill:#f9d0d0

逐条对代码：

通道①：stderr 被主动指向 /dev/null

// system/core/init/first_stage_init.cpp:416-419
SetStdioToDevNull(argv);        // stdin/stdout/stderr 全部 → /dev/null
// Now that tmpfs is mounted on /dev and we have /dev/kmsg, we can actually
// talk to the outside world...
InitKernelLogging(argv);        // 之后日志才改走 /dev/kmsg

LOG(FATAL) 消息要写 stderr，此时 stderr 已经是 /dev/null。

通道②：/dev/kmsg 在容器里写不进

InitKernelLogging 之后日志走 kmsg，但这个环境里 root 写 kmsg 都会被拒（同一批容器上验证过）：

sh: can't create /dev/kmsg: Operation not permitted

通道③：logd 还没起

logd 是 init 启动的服务，要等 init 进入事件循环才会被拉起。PropertyInit() 在 init.cpp:1044，还在事件循环之前。

三条全断，所以"什么日志也没留下"不是偶然，是这个阶段的结构性问题。 只要崩溃点落在 PropertyInit() 附近，就注定查不到任何现成日志——这跟改了什么代码无关，是调试环境本身的盲区。

2.3 `CHECKCALL` 不是凶手，但容易被误认

排查时容易先怀疑第一阶段那一长串挂载：

// system/core/init/first_stage_init.cpp:342-343
#define CHECKCALL(x) \
    if ((x) != 0) errors.emplace_back(#x " failed", errno);   // ← 只收集，不退出

它的失败只是塞进 errors，最后在 :421-425 打几行 LOG(ERROR) 就继续了。CHECKCALL 失败不会让 init 死，真正会死的是 LOG(FATAL)（比如 :452 内核模块加载失败、property_service.cpp:1457 属性区初始化失败）。

三、引入的工具：strace

3.1 它是什么

strace 基于内核的 ptrace 机制，把目标进程（及其 fork 出的所有子进程）的每一次系统调用都拦截下来记录：调用名、参数、返回值、errno。它是旁观者，不改变被调程序的行为（除了让它变慢）。

3.2 为什么这里非它不可

当时手上的选项其实都不可用：

手段	为什么不行
logcat	logd 没起
dmesg / kmsg	容器里写不进、读到的也是宿主的
tombstone	debuggerd 没起，且崩溃在 debuggerd 接管前
`docker logs`	init 的 stderr 已指向 `/dev/null`
源码静态分析	改动涉及 errno 分类，实际返回哪个 errno 只有跑起来才知道

strace 的独特价值在于：它不依赖被测程序自己产生任何输出。程序内部的日志系统全灭也没关系，只要它还发起系统调用，strace 就看得见。而 fsetxattr 正是一个系统调用——它返回什么 errno，strace 原样记下。

对 init 这种"崩得太早、太安静"的进程，strace 几乎是唯一能拿到第一手现场的手段。

四、如何用

4.1 第一步：找到 init 是被谁拉起来的

容器的 entrypoint 是 sh，init 是子进程。查启动链：

# 容器内
cat /init.sh | head -30
# 或看进程树
ps -ef | head

找到那行 /system/bin/init（或 exec /system/bin/init），它就是要被 strace 包住的目标。

4.2 第二步：把启动命令换成 strace

最省事的做法是直接改 /init.sh（容器内，测试完记得还原）：

# 原来
/system/bin/init

# 换成（容器内，裸命令）
strace -f -tt -s 256 -o /data/local/tmp/init.strace /system/bin/init

如果想不动文件，也可以在宿主侧改 entrypoint：

# 宿主侧
docker run --entrypoint strace <image> -f -tt -s 256 -o /data/local/tmp/init.strace /system/bin/init

参数怎么选：

参数	作用	为什么需要
`-f`	跟踪 fork/clone 出的子进程	init 会 fork 出 second stage、各种服务，不加会漏
`-o <file>`	输出写文件	stdout/stderr 在 init 手里，写文件最稳
`-tt`	微秒级时间戳	崩溃前后的时序对得上
`-s 256`	字符串参数最多显示 256 字节	默认 32 字节，路径/标签这类参数会被截断

如果只关心特定调用，可以再加 -e trace=file（只跟踪文件相关）或 -e trace=desc，但初次排查建议全量——你不知道凶手是哪个调用。

4.3 第三步：读输出，定位崩溃点

strace 输出长这样（示意，实际以现场为准）：

12:00:01.100  3717  3717 mkdir("/dev/__properties__", 0700) = 0
12:00:01.101  3717  3717 openat(AT_FDCWD, "/dev/__properties__/property_info", ...) = 3
12:00:01.101  3717  3717 fsetxattr(3, "security.selinux", "u:object_r:...", 30, 0) = -1 EACCES Permission denied
12:00:01.102  3717  3717 write(2, "Failed to initialize property area\n", 35) = -1 EBADF Bad file descriptor
12:00:01.102  3717  3717 tgkill(3717, 3717, SIGABRT) = 0
12:00:01.102  3717  3717 --- SIGABRT {si_signo=SIGABRT, si_code=SI_TKILL} ---
12:00:01.103  3717  3717 +++ exited with 134 +++

读法固定为三步：

看结尾：exited with N / killed by SIGxxx / --- SIGSEGV ---，确定退出方式和退出码（134 = 128+6 = SIGABRT）。
从结尾往上找第一个 = -1 EXXX：那就是根因。上例中 fsetxattr ... = -1 EACCES 直接指向 IsEnvironmentalLabelingErrno() 的 default 分支——EACCES 不在放行名单里 → fsetxattr_fail = true → __system_property_area_init() 返回 -1 → LOG(FATAL) → abort。
对照源码：把 syscall 名和参数拿去 grep 源码，比如 fsetxattr 就能直接落到 bionic/libc/system_properties/prop_area.cpp:93-111 那段。

几个常见模式，见到就能立刻判断：

exit_group(1)                    ← 主动退出，码为 1，往上找谁调的
--- SIGABRT ---                  ← LOG(FATAL) / abort()
--- SIGSEGV ---                  ← 空指针之类，看崩溃前最后一个调用
write(2, ..., ) = -1 EBADF       ← 写 stderr 失败（正是 SetStdioToDevNull 的后果）
fsetxattr(...) = -1 EXXX         ← 属性区打标签失败，对应本文
execve("/system/bin/xxx") = -1 ENOENT  ← 拉不起后续进程

4.4 复盘：从 strace 回到根因

拿到 fsetxattr = -1 EACCES 之后，推理链是闭合的：

fsetxattr 返回 EACCES
  → IsEnvironmentalLabelingErrno(EACCES) 走 default → false
  → *fsetxattr_failed = true（prop_area.cpp:107）
  → __system_property_area_init() 返回 -1（system_property_api.cpp:63）
  → PropertyInit() 里 LOG(FATAL)（property_service.cpp:1457）
  → abort → init 消失 → 开机链断

而 EACCES 为什么会出现：容器跑在宿主 SELinux 策略上，/dev/__properties__ 的文件类型在宿主策略里没有 guest 侧的对应定义，内核返回的是 EACCES 而不是 046e29a6 预期的 EINVAL——分类名单和现实对不上。修法自然是把实际观察到的 errno 也纳入环境性错误，或者干脆在容器环境下跳过打标签。

这也说明了为什么静态看代码看不出问题：IsEnvironmentalLabelingErrno 的三个 case 单独看都合理，只有跑在真实容器里、看到真实 errno，才知道少了一个。

五、复盘与可复用的经验

1. init 早期崩溃 = 天然的日志盲区。 SetStdioToDevNull（first_stage_init.cpp:416）、InitKernelLogging（:419）、logd 由 init 自己启动——这三件事决定了 PropertyInit() 前后的崩溃几乎不可能留下现成日志。以后遇到"容器里没有 init 进程、没有任何日志"，第一反应就该是 strace，而不是继续翻 logcat。

2. PID 1 不是 init 时，崩溃不会带走容器。 entrypoint 是 sh 的架构下，init 崩了还能 docker exec 进去看——这既是坏消息（系统起不来），也是好消息（还有交互机会，可以手动跑 strace 验证）。真 PID 1 崩了容器直接退出，连进都进不去。

3. strace 的定位是"抓第一手现场"，不是"日常监控"。 全量跟踪开销不小，适合这种一次性、短时间的启动期抓取。拿到现场后就该摘掉，别让它常驻。

4. 读 strace 的固定套路：结尾 → 往上找第一个 -1 EXXX → grep 源码。三步之内基本能落到具体文件行号。

5. errno 分类这种逻辑，必须在真实环境验证。 IsEnvironmentalLabelingErrno 的设计思路没问题，问题出在"以为容器会返回 EINVAL，实际是 EACCES"。涉及错误码判断的补丁，合入前应该在目标容器里实跑一次，而不是只在开发机上过编译。

附：本次用到的命令清单

# ---- 容器内，定位 init 启动点 ----
cat /init.sh
ps -ef

# ---- 容器内，改启动命令抓现场 ----
# /init.sh 里：
strace -f -tt -s 256 -o /data/local/tmp/init.strace /system/bin/init

# ---- 宿主侧，也可以改 entrypoint ----
docker run --entrypoint strace <image> \
    -f -tt -s 256 -o /data/local/tmp/init.strace /system/bin/init

# ---- 读输出：三步定位 ----
tail -20 /data/local/tmp/init.strace              # 1. 看结尾怎么死的
grep -n '= -1 ' /data/local/tmp/init.strace | tail -5   # 2. 找最后一个失败的调用
grep -n 'fsetxattr\|property_area' /data/local/tmp/init.strace   # 3. 按嫌疑调用过滤

# ---- 定位到源码后 ----
grep -rn 'IsEnvironmentalLabelingErrno' bionic/libc/system_properties/
grep -rn '__system_property_area_init' bionic/ system/core/init/