基础日志实现：用 printf 搭建你的第一个日志系统

说实话，很多嵌入式工程师一开始都觉得日志系统没什么好讲的——不就是 printf 打印吗？我当年也是这么想的。直到有一次调试一个间歇性死机的 bug，我在代码里临时加了十几个 printf，结果打印出来的信息乱成一锅粥，根本分不清哪个先哪个后。嗯，从那天起，我就老老实实开始封装日志函数了。

这一章，我们就从最基础的 printf 开始，一步步搭出一个带时间戳的日志系统。别小看这一步，它是后面所有高级功能的地基。

为什么需要封装日志函数？

你可能会问：直接写 printf 不就行了？我举个例子。假设你在项目里写了 50 个 printf，突然有一天你想给每条日志加个前缀，比如 "[INFO] "。你得一个一个去改，改完还得担心有没有漏掉的。这还不算最痛苦的——

我在一个工业控制项目里遇到过更坑的事：产品量产之后，客户反馈设备偶尔会死机。我想打开日志看看，结果发现所有 printf 都被注释掉了，因为之前调试完忘了恢复。你想想看，这得多抓狂。

所以，封装日志函数的核心目的就三个：

  • 统一管理：改格式、加功能，只改一个地方
  • 开关控制：发布版本一键关闭日志，不影响性能
  • 信息丰富：自动加上时间戳、文件名、行号等上下文

第一版：最朴素的日志封装

我们先从最简单的开始。定义一个宏，把 printf 包一层：

#include <stdio.h>
#include <time.h>

#define LOG_INFO(fmt, ...) \
    do { \
        printf("[INFO] "); \
        printf(fmt, ##__VA_ARGS__); \
        printf("\n"); \
    } while(0)

#define LOG_ERROR(fmt, ...) \
    do { \
        printf("[ERROR] "); \
        printf(fmt, ##__VA_ARGS__); \
        printf("\n"); \
    } while(0)

int main() {
    LOG_INFO("系统启动，传感器数量: %d", 5);
    LOG_ERROR("温度传感器读取失败，错误码: 0x%02X", 0xE3);
    return 0;
}

这里用了 do-while(0) 结构，目的是让宏在 if-else 语句中也能正常工作。我见过有人直接写大括号，结果在 if 后面不加花括号时编译报错——嗯，这种坑踩过一次就记住了。

小技巧：##__VA_ARGS__ 前面的 ## 是 GNU 扩展，作用是当可变参数为空时，自动去掉前面的逗号。大部分嵌入式编译器都支持，如果你用 MSVC，可能需要换成 __VA_ARGS__。

第二版：加上时间戳

光有前缀还不够。调试的时候，最需要知道的就是「这个日志是什么时候发生的」。尤其是分析时序问题，时间戳就是命根子。

我个人的习惯是用两种时间格式：

  • 绝对时间：年-月-日 时:分:秒，适合看整体运行流程
  • 相对时间：系统启动后的毫秒数，适合分析时序关系

下面这个实现同时支持两种：

#include <stdio.h>
#include <time.h>
#include <sys/time.h>

static uint64_t g_start_ms = 0;

// 获取系统启动后的毫秒数（假设在 main 开头调用一次）
void log_init() {
    struct timeval tv;
    gettimeofday(&tv, NULL);
    g_start_ms = (uint64_t)tv.tv_sec * 1000 + tv.tv_usec / 1000;
}

uint64_t get_tick_ms() {
    struct timeval tv;
    gettimeofday(&tv, NULL);
    return (uint64_t)tv.tv_sec * 1000 + tv.tv_usec / 1000 - g_start_ms;
}

// 获取可读的时间字符串
void get_timestamp_str(char *buf, int len) {
    time_t now = time(NULL);
    struct tm *tm_info = localtime(&now);
    strftime(buf, len, "%Y-%m-%d %H:%M:%S", tm_info);
}

#define LOG_INFO(fmt, ...) \
    do { \
        char ts[32]; \
        get_timestamp_str(ts, sizeof(ts)); \
        printf("[%s][INFO] ", ts); \
        printf(fmt, ##__VA_ARGS__); \
        printf("\n"); \
    } while(0)

#define LOG_DEBUG(fmt, ...) \
    do { \
        uint64_t tick = get_tick_ms(); \
        printf("[%llu ms][DEBUG] ", (unsigned long long)tick); \
        printf(fmt, ##__VA_ARGS__); \
        printf("\n"); \
    } while(0)
关键点：gettimeofday 在 Linux 和大部分 RTOS 中都可用。如果你在裸机环境下，可以用硬件定时器来实现 get_tick_ms()。我在 STM32 上就常用 SysTick 来提供毫秒级时间戳。

第三版：加上文件名和行号

日志里只有消息还不够。当你的项目有几十个源文件时，看到一条 "传感器读取失败"，你根本不知道是哪个文件哪一行打印的。这时候，__FILE__ 和 __LINE__ 这两个预定义宏就派上用场了。

#define LOG_INFO(fmt, ...) \
    do { \
        char ts[32]; \
        get_timestamp_str(ts, sizeof(ts)); \
        printf("[%s][%s:%d][INFO] ", ts, __FILE__, __LINE__); \
        printf(fmt, ##__VA_ARGS__); \
        printf("\n"); \
    } while(0)

输出效果类似这样：

[2025-01-15 14:23:45][main.c:127][INFO] 系统启动，传感器数量: 5
[2025-01-15 14:23:46][sensor.c:89][ERROR] 温度传感器读取失败，错误码: 0xE3

你看，现在一眼就能定位到问题出在哪个文件的哪一行。我在调试一个多线程程序时，就靠这个快速找到了一个竞态条件——两个线程同时操作了同一个全局变量，日志里文件名和行号直接暴露了问题点。

注意：__FILE__ 会输出完整路径，如果你不想暴露源码目录结构，可以在编译时用 -D 宏定义来替换。比如在 Makefile 里加一句：-DBASE_FILE=\"$(notdir $<)\"，然后用 BASE_FILE 代替 __FILE__。

知识结构图

下面这张图总结了本章的核心内容，从最原始的 printf 到封装好的日志系统，每一步做了什么、解决了什么问题，一目了然：

基础日志系统演进 原始 printf 散落在代码各处 宏封装 统一格式、开关控制 加时间戳 绝对/相对时间 日志级别 INFO/ERROR/DEBUG 文件+行号 __FILE__ / __LINE__ 开关控制 发布版关闭日志 最终日志输出 [时间戳][文件:行号][级别] 消息内容 从散乱到规范，每一步解决一个实际问题

实际项目中的避坑指南

讲到这里，我想分享几个我在项目中踩过的坑，希望能帮你少走弯路。

我曾经犯过的错：
  • 日志缓冲区溢出：有一次在中断服务函数里调用了 printf，结果 printf 内部用了动态内存分配，直接导致系统崩溃。后来我才知道，中断里绝对不能调用不可重入的函数。
  • 时间戳精度不够：用 time() 函数只能精确到秒，调试高速通信协议时根本不够用。后来改用硬件定时器，精度提到了微秒级。
  • 日志太多拖慢系统：在循环里每毫秒打印一次日志，结果系统响应时间从 1ms 变成了 100ms。解决方案是加一个日志频率限制，或者用环形缓冲区异步输出。
我的建议：刚开始做日志系统时，不要追求大而全。先实现最核心的功能——时间戳、文件名、行号、日志级别。等用顺手了，再慢慢加颜色输出、文件存储、远程日志等功能。一口吃不成胖子，日志系统也是迭代出来的。

完整示例代码

最后，给你一个可以直接用的完整示例。把下面这段代码复制到你的项目里，稍微改改时间戳获取函数，就能跑起来了：

#include <stdio.h>
#include <time.h>

// 日志级别
typedef enum {
    LOG_LEVEL_DEBUG,
    LOG_LEVEL_INFO,
    LOG_LEVEL_WARN,
    LOG_LEVEL_ERROR
} log_level_t;

// 当前日志级别（可以全局修改）
static log_level_t g_log_level = LOG_LEVEL_DEBUG;

// 获取时间字符串
static const char* get_time_str() {
    static char buf[20];
    time_t now = time(NULL);
    struct tm *tm = localtime(&now);
    strftime(buf, sizeof(buf), "%H:%M:%S", tm);
    return buf;
}

// 日志级别名称
static const char* level_name(log_level_t level) {
    switch(level) {
        case LOG_LEVEL_DEBUG: return "DEBUG";
        case LOG_LEVEL_INFO:  return "INFO";
        case LOG_LEVEL_WARN:  return "WARN";
        case LOG_LEVEL_ERROR: return "ERROR";
        default: return "UNKNOWN";
    }
}

#define LOG(level, fmt, ...) \
    do { \
        if (level >= g_log_level) { \
            printf("[%s][%s:%d][%s] ", \
                   get_time_str(), __FILE__, __LINE__, level_name(level)); \
            printf(fmt, ##__VA_ARGS__); \
            printf("\n"); \
        } \
    } while(0)

// 便捷宏
#define LOG_DEBUG(fmt, ...)  LOG(LOG_LEVEL_DEBUG, fmt, ##__VA_ARGS__)
#define LOG_INFO(fmt, ...)   LOG(LOG_LEVEL_INFO,  fmt, ##__VA_ARGS__)
#define LOG_WARN(fmt, ...)   LOG(LOG_LEVEL_WARN,  fmt, ##__VA_ARGS__)
#define LOG_ERROR(fmt, ...)  LOG(LOG_LEVEL_ERROR, fmt, ##__VA_ARGS__)

int main() {
    LOG_INFO("系统启动完成");
    LOG_DEBUG("传感器初始化，地址: 0x%02X", 0x76);
    LOG_WARN("电池电量低: %d%%", 15);
    LOG_ERROR("通信超时，重试次数: %d", 3);
    return 0;
}

这段代码里，我用了日志级别控制。你把 g_log_level 改成 LOG_LEVEL_WARN，那么 DEBUG 和 INFO 级别的日志就不会输出了。这在发布版本里特别有用——保留 ERROR 和 WARN 日志用于现场排查，同时去掉调试信息提升性能。

好了，基础日志实现就讲到这里。你现在已经掌握了最核心的三个要素：封装、时间戳、文件定位。下一章我们会在这个基础上，加入颜色输出和日志文件存储功能。到时候你的日志系统就能「看得清、存得下、找得到」了。

公众号:蓝海资料掘金营，微信deep3321

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