3. 日志级别详解（DEBUG、INFO、WARN、ERROR）

日志级别这东西，说白了就是给调试信息贴标签。你贴得越细，排查问题越快。我其实见过不少同学，一上来就全用 printf，结果线上出问题，日志刷屏根本找不着重点。用对级别，就像给工具箱分了层——哪个螺丝刀干什么活，心里有数。

3.1 DEBUG 级别——开发者的显微镜

DEBUG 日志记录非常详细的信息。通常只在开发环境、单元测试或复现特定 bug 时开启。生产环境要关了它，否则性能扛不住，日志也会爆炸。

我个人习惯，在加密 SDK 的签名、验签、密钥派生这类核心函数里，埋最细的入参、中间变量和出参。举个例子：

// 加密SDK内部，伪代码
int sdk_sign(const uint8_t *data, size_t len, uint8_t *sig) {
    log_debug("sdk_sign: data len=%zu, data[0..15]=%02x%02x...", len, data[0], data[1]);
    int ret = internal_hmac_sha256(data, len, sig);
    log_debug("sdk_sign: internal_hmac_sha256 returned %d, sig=%02x%02x...", ret, sig[0], sig[1]);
    return ret;
}

我在项目里遇到过一件糗事：同一条请求，在 Windows 上签名正确，到 Linux 上就失败。开了 DEBUG 日志一看，哦，内部 hash 函数在处理传入的长度时，两个平台的 sizeof(size_t) 不同，数据截断出问题了。要是没这些细粒度的 DEBUG 日志，我可能还在怀疑网络字节序呢。

注意：DEBUG 日志绝不能打印密钥明文、私钥、密码等敏感信息。我曾在 Review 同学代码时发现有 log_debug("private key hex: ...") 这种写法，果断要求删掉。真要调试密钥相关，用脱敏后的哈希值或部分摘要。

3.2 INFO 级别——日常巡检的仪表盘

INFO 日志记录关键的执行步骤、状态变更或配置加载。不追求细节，但要能串联起一次完整调用的大致流程。

我会在下面这些地方打 INFO：

  • SDK 初始化完成：log_info("SDK initialized, version 2.3.0, provider HW")
  • 每次加解密操作开始和结束：log_info("Encrypt session started, seq=%u", seq_id)
  • 会话超时或重连事件：log_info("Session timeout, initiating re-handshake")

你想想看，线上出问题时，运维第一反应就是看 INFO 日志。如果每条都有清晰的时间戳和操作名，定位到异常大概发生在哪个请求、哪个时间点，那就省了一半排查时间。

3.3 WARN 级别——黄灯预警，不能忽视

WARN 表示“可能出现问题”，但当前还能继续运行。比如证书即将过期、重试次数接近上限、使用了降级算法、条件分支走了非最佳路径。

我曾经吃过一次亏：线上服务突然变慢，查了半天才发现，早在三周前就有 WARN 日志 “HW module not available, fallback to SW crypto, performance may degrade”。所有人都觉得“应急降级嘛，正常”，结果积少成多，CPU 用满才暴露。嗯，这里要注意——WARN 是给开发者看的“潜在炸弹”，不能随手忽略。

常见的 WARN 场景：

  • 证书有效期剩 30 天
  • 硬件安全模块（HSM）返回重试错误
  • 输入参数非规范但可容错处理
  • 随机数源熵不足，改用软件伪随机
建议：在 CI/CD 的测试报告中，把 WARN 级别的事件汇总成一张表。每两周回顾一次，看看哪些 WARN 是反复出现的。如果同一个 WARN 连续出现一周还没处理，那它大概率会变成明天的 ERROR。

3.4 ERROR 级别——必须立刻响应的红灯

ERROR 指已经发生的错误，导致当前操作失败，但 SDK 整体仍可继续服务其他请求。比如签名验证失败、内存分配失败、网络发送超时、密钥不存在。

这个时候，日志必须包含足够多的上下文，让你能复现问题或快速定位故障点：

log_error("verify_signature: signature mismatch, key_id=%u, data_hash=%s, expected_sig=%s, actual_sig=%s",
          key_id, hash_hex, expected_hex, actual_hex);

我自己一般会在 ERROR 日志里附加以下信息（视安全策略决定）：

  • 操作名称、会话 ID、请求 ID
  • 错误码及其对应说明
  • 关键输入摘要（非完整原文）
  • 当前 SDK 状态快照（如硬件模块是否在线）

要注意避免“假报 ERROR”。比如内部重试机制第一次失败，不一定算 ERROR；等所有重试都耗尽，再记录一次 ERROR 就好。我曾经接手过一个项目，里面网络库在每次 socket 连接失败时都打 ERROR，哪怕后面重试成功了。结果监控系统天天告警，大家都麻了，真出事儿反而被淹没。

3.5 级别选择与使用原则

上面四个级别怎么选？我归纳了一张表，你存下来，下次写日志的时候扫一眼：

级别 生产环境 主要作用 典型输出频率（单次调用）
DEBUG 关闭 开发/调式阶段细节追踪 10~50 条
INFO 开启 记录关键流程和里程碑 2~5 条
WARN 开启 标记非致命但需关注的异常 0~1 条
ERROR 开启 记录已发生的失败操作 0~1 条（重试耗尽后）

还有一个决策小技巧：如果你不确定一条日志该用哪个级别，就反问——这条信息，正常运行时我需不需要每天看？如果答案是“需要”，INFO；如果是“可能有用但不用天天看”，WARN 或 DEBUG；如果是“永远不会出现”，那就别打日志了，直接断言或返回错误。

画个图把这四个级别的关系串起来，方便你记忆：

日志级别金字塔 日志级别金字塔——越往上越紧急 ERROR 操作失败，需立即处理 WARN 潜在风险，需关注 INFO 正常流程的里程碑 DEBUG 详细调试信息（生产关闭） 💡 注意：DEBUG 日志最详细也最笨重，生产环境务必关闭；ERROR 条数最少但最重要。

最后给出一个比较完整的日志范例，把四个级别都用到同一段加密操作的场景中，你感受一下：

int sdk_encrypt(const uint8_t *plaintext, size_t len, uint8_t *ciphertext) {
    log_debug("enter sdk_encrypt, len=%zu, first_8_bytes=%02x%02x...", len, plaintext[0], plaintext[1]);

    if (!hsm_available) {
        log_warn("HSM not available, using software AES (slower)");
    }
    log_info("encrypt session started, algo=AES-256-GCM, key_id=%u", key_id);

    int ret = crypto_aes_gcm_encrypt(plaintext, len, ciphertext);
    if (ret != 0) {
        log_error("encrypt failed, err=%d, plaintext_hash=%s", ret, sha256_hex(plaintext, len));
        return -1;
    }

    log_info("encrypt succeeded, ciphertext_len=%zu", len);  // GCM 不改变长度
    log_debug("exit sdk_encrypt, ciphertext_first_8=%02x%02x...", ciphertext[0], ciphertext[1]);
    return 0;
}

你看，每个级别各司其职：DEBUG 给开发者看内部细节，INFO 记录调用流程，WARN 标记降级事件，ERROR 在出错时带上足够上下文。这样组合下来，线上排障基本不慌。

← 上一章 📖 返回目录 下一章 →