4、日志系统入门:OP-TEE 日志框架、日志级别与输出目标

调试嵌入式安全系统,说白了就是跟日志打交道。OP-TEE 的日志系统设计得挺巧妙,但刚上手时容易摸不着头脑。我记得第一次调 OP-TEE 的 TA 时,死活看不到自己的打印信息,折腾了半天才发现是日志级别没配对。今天咱们就把这块彻底捋清楚。

4.1 OP-TEE 日志框架的整体结构

OP-TEE 的日志系统分为三层:内核态(Core)、用户态(TA)和底层驱动。每一层都有自己的打印宏,但最终都会汇聚到同一个输出通道。

我个人习惯把这三层想象成一个管道:

  • Core 层:运行在安全世界的内核态,负责初始化、内存管理、中断处理等底层操作。
  • TA 层:运行在安全世界的用户态,也就是我们写的可信应用。
  • 驱动层:运行在非安全世界的 Linux 内核中,负责把日志从安全世界搬运到非安全世界。

你想想看,TA 打印的日志怎么才能被我们看到?它得先经过 OP-TEE 内核,再通过安全监控调用(SMC)传到 Linux 驱动,最后写到串口或文件里。这个链路一旦断了,日志就丢了。

OP-TEE 日志框架三层结构 安全世界(Secure World) TA 层(用户态) DMSG() / IMSG() / EMSG() Core 层(内核态) DMSG() / IMSG() / EMSG() 非安全世界(Normal World) Linux 驱动层(OP-TEE 驱动) SMC 调用 串口(UART) 内核日志(dmesg) 文件 / 网络

核心要点:TA 和 Core 使用同一套日志宏,但编译时链接的库不同。TA 的日志会先经过 Core 的 tee-supplicant 处理,再转发到非安全世界。

4.2 日志级别:从 TRACE 到 ERROR

OP-TEE 定义了四个日志级别,从低到高分别是:TRACE、DEBUG、INFO、ERROR。每个级别对应一个宏,用法很简单:

// TRACE 级别:最详细的调试信息
TRACE("进入函数 func_a, param=%d", value);

// DEBUG 级别:开发阶段的调试信息
DMSG("TA 已初始化,会话 ID=%x", session_id);

// INFO 级别:关键流程信息
IMSG("TA 加载成功,UUID=%pU", uuid);

// ERROR 级别:错误信息
EMSG("内存分配失败,size=%zu", size);

这里有个容易踩的坑——编译时日志级别过滤。OP-TEE 在编译时会通过 CFG_TEE_TA_LOG_LEVEL 和 CFG_TEE_CORE_LOG_LEVEL 两个宏来控制哪些日志能被编译进二进制。举个例子:

// 在 TA 的 Makefile 中设置
CFG_TEE_TA_LOG_LEVEL = 2  // 对应 DEBUG 级别

// 在 Core 的配置中设置
CFG_TEE_CORE_LOG_LEVEL = 1  // 对应 TRACE 级别

级别数字的含义如下:

级别 数值 宏 用途
TRACE 1 TRACE() 最详细的调试信息,比如函数进出、变量值
DEBUG 2 DMSG() 开发阶段的调试信息,推荐日常使用
INFO 3 IMSG() 关键流程信息,比如初始化完成、连接建立
ERROR 4 EMSG() 错误信息,必须被记录

我曾经在调试一个 TA 的内存泄漏问题时,怎么都看不到 DMSG 的打印。查了半天才发现 Makefile 里把 CFG_TEE_TA_LOG_LEVEL 设成了 3(INFO),导致所有 DEBUG 级别的日志都被编译器优化掉了。记住:编译时级别决定了哪些日志能存在,运行时没有二次过滤。

4.3 日志输出目标:日志到底去了哪里?

日志输出目标取决于平台和配置。我总结了几种常见情况:

  • 串口(UART):开发板最常用的方式。OP-TEE 通过 PL011 或 NS16550 等串口驱动直接输出日志。优点是实时性强,缺点是需要物理连接。
  • 内存缓冲区:日志先写入内存中的环形缓冲区,再通过 tee-supplicant 定期读取。这种方式适合日志量大的场景。
  • Linux dmesg:通过 OP-TEE 驱动,日志会被转发到 Linux 内核的 printk 系统,最终出现在 dmesg 或 /var/log/kern.log 中。
  • 文件系统:部分平台支持将日志重定向到安全世界或非安全世界的文件系统,方便离线分析。

配置输出目标通常通过 CFG_TEE_CORE_LOG_METHOD 和 CFG_TEE_TA_LOG_METHOD 来控制。举个例子:

// 使用串口输出(QEMU 平台默认)
CFG_TEE_CORE_LOG_METHOD = uart

// 使用内存缓冲区
CFG_TEE_CORE_LOG_METHOD = mem

// 通过 tee-supplicant 转发到 Linux
CFG_TEE_CORE_LOG_METHOD = supplicant

小技巧:在 QEMU 环境下,我习惯同时开启串口和内存缓冲区。串口看实时日志,内存缓冲区用来回溯崩溃前的信息。配置方法是在 build/conf.mk 中加上 CFG_TEE_CORE_LOG_METHOD = uart,mem。

4.4 实战:快速验证日志是否工作

说了这么多理论,咱们来点实际的。写一个最简单的 TA,验证日志系统是否正常工作:

#include <tee_internal_api.h>
#include <tee_internal_api_extensions.h>

TEE_Result TA_CreateEntryPoint(void)
{
    IMSG("TA 入口点被调用");
    DMSG("调试信息:TA 创建成功");
    TRACE("TRACE 级别:当前时间戳=%lu", TEE_GetSystemTime());
    return TEE_SUCCESS;
}

TEE_Result TA_OpenSessionEntryPoint(uint32_t param_types,
                                    TEE_Param params[4],
                                    void **session_ctx)
{
    IMSG("会话已打开,param_types=0x%x", param_types);
    EMSG("这只是一个测试错误,请忽略");
    return TEE_SUCCESS;
}

编译时记得把日志级别设低一点:

# 在 TA 的 Makefile 中
CFG_TEE_TA_LOG_LEVEL = 1  # 允许所有级别

运行后,你应该能在串口或 dmesg 中看到类似这样的输出:

[OP-TEE] IMSG: TA 入口点被调用
[OP-TEE] DMSG: 调试信息:TA 创建成功
[OP-TEE] TRACE: TRACE 级别:当前时间戳=12345678
[OP-TEE] EMSG: 这只是一个测试错误,请忽略

如果看不到任何输出,按这个顺序排查:

  1. 检查 CFG_TEE_TA_LOG_LEVEL 是否 ≤ 你使用的宏的级别
  2. 检查 CFG_TEE_CORE_LOG_METHOD 是否配置正确
  3. 检查串口是否被其他程序占用(比如 Linux 的 console)
  4. 检查 TA 是否真的被加载了(用 xtest 或直接调用)

嗯,这里要注意:有些平台默认关闭了 TA 的日志输出。如果你在 dmesg 里看不到 TA 的日志,试试在 OP-TEE 内核配置中打开 CFG_TEE_CORE_TA_TRACE 选项。

日志系统是调试的基石。搞清楚了日志级别和输出目标,后面咱们讲动态开关日志、日志格式化、性能分析时,你就能快速上手了。说白了,日志就是你的眼睛——眼睛亮了,问题就好找了。