3、高级日志技巧：条件日志、一次性日志、节流日志、日志文件持久化

日志这东西，说白了就是程序的「黑匣子」。

但很多人的日志，要么刷屏刷到怀疑人生，要么关键信息全被淹没了。我刚开始用ROS2那会儿，就吃过这个亏——一个高频循环里打印了太多日志，结果系统直接卡死，连问题出在哪都看不出来。

嗯，今天咱们就来聊聊高级日志技巧。学会了这些，你的调试效率至少翻一倍。

3.1 条件日志：只在需要的时候打印

什么叫条件日志？就是满足特定条件才输出日志。ROS2里用 RCLCPP_DEBUG_EXPRESSION 这类宏来实现。

举个例子，你有个传感器数据处理的回调函数，每秒调用100次。正常情况下你不想看日志，但数据异常时你想看。怎么办？

// 只在数据超出阈值时打印
if (sensor_value > 100.0) {
    RCLCPP_INFO(rclcpp::get_logger("sensor_logger"), 
                "传感器数据异常: %.2f", sensor_value);
}

这其实是最朴素的条件日志。但ROS2提供了更优雅的方式——直接用宏里的表达式参数：

RCLCPP_INFO_EXPRESSION(
    rclcpp::get_logger("my_logger"),
    sensor_value > 100.0,  // 条件表达式
    "传感器数据异常: %.2f", sensor_value
);

我个人习惯用这种方式，代码更干净。条件表达式可以是任何返回bool的表达式，比如变量比较、函数调用结果等。

小技巧：条件日志特别适合调试「偶发bug」。比如某个节点偶尔崩溃，你可以在关键路径上加上条件日志，只记录异常状态下的信息，避免日志刷屏。

3.2 一次性日志：只打印一次

有些日志信息，你只想让它出现一次。比如节点启动时的配置信息、版本号、警告提示等。

ROS2提供了 RCLCPP_INFO_ONCE 系列宏：

RCLCPP_INFO_ONCE(
    rclcpp::get_logger("my_logger"),
    "节点已启动，版本: %s", VERSION_STRING
);

这个宏内部维护了一个静态标志位。第一次调用时打印，之后就不再打印了。实现原理其实很简单，但用起来特别方便。

我在项目中遇到过一个问题：某个警告信息在循环里被打印了上万次，导致日志文件膨胀到几百MB。后来换成 RCLCPP_WARN_ONCE，问题立刻解决。

注意：一次性日志的「一次性」是针对每个logger实例而言的。如果你创建了多个同名的logger，每个logger都会打印一次。不过大多数情况下，一个节点只有一个logger，所以不用担心。

3.3 节流日志：控制打印频率

节流日志，说白了就是「别刷屏」。高频循环里，你不想每毫秒都打印日志，但你又不想完全关掉它——万一出问题了呢？

ROS2提供了 RCLCPP_INFO_THROTTLE 宏：

RCLCPP_INFO_THROTTLE(
    rclcpp::get_logger("my_logger"),
    *clock,  // 需要传入时钟对象
    1000,    // 节流时间，单位毫秒
    "当前处理速度: %d msg/s", current_rate
);

这个宏的意思是：每1000毫秒（1秒）最多打印一次。不管循环跑得多快，日志输出频率都被限制住了。

你想想看，如果你的循环每秒跑1000次，不加节流的话，日志文件1分钟就能写满几个G。加了节流，1分钟只输出60条日志，信息量一点没少，但文件大小可控多了。

我曾经调试一个电机控制节点，PWM频率是10kHz。一开始没加节流，日志文件每秒生成几百MB，硬盘直接爆了。后来加上 RCLCPP_DEBUG_THROTTLE，每500毫秒打印一次状态，问题定位效率反而更高了——因为不会被海量日志淹没。

核心要点：节流时间的选择要结合你的调试需求。调试高频信号时，100-500ms比较合适；调试低频任务时，1-5秒也可以。别设得太短，否则节流失去意义；也别设得太长，否则关键信息可能错过。

3.4 日志文件持久化：把日志写到文件里

前面说的都是控制台日志。但真正生产环境里，日志必须写到文件里，方便事后分析。

ROS2的日志持久化，核心是配置日志输出后端。默认情况下，ROS2使用 spdlog 作为日志后端，它支持文件输出。

配置方式有两种：

方式一：通过环境变量配置

# 设置日志文件路径
export ROS_LOG_DIR=/var/log/my_robot

# 设置日志级别
export RCUTILS_CONSOLE_OUTPUT_FORMAT="[{severity}][{time}]: {message}"
export RCUTILS_LOGGING_USE_STDOUT=0  # 关闭控制台输出
export RCUTILS_LOGGING_BUFFERED_STREAM=1  # 启用缓冲

这种方式适合快速部署。我一般在测试阶段用控制台输出，正式部署时切到文件输出。

方式二：通过代码配置

#include <rclcpp/rclcpp.hpp>
#include <spdlog/spdlog.h>
#include <spdlog/sinks/rotating_file_sink.h>

int main(int argc, char** argv) {
    rclcpp::init(argc, argv);
    
    // 创建循环日志文件，最大10MB，保留3个备份
    auto max_size = 10485760;  // 10MB
    auto max_files = 3;
    auto file_sink = std::make_shared<spdlog::sinks::rotating_file_sink_mt>(
        "/var/log/my_robot/node.log", max_size, max_files);
    
    // 配置日志格式
    file_sink->set_pattern("[%Y-%m-%d %H:%M:%S.%e][%l] %v");
    
    // 注册到ROS2日志系统
    auto logger = rclcpp::get_logger("my_logger");
    // ... 后续使用logger
    
    rclcpp::spin(std::make_shared<MyNode>());
    rclcpp::shutdown();
    return 0;
}

这种方式更灵活，可以自定义日志文件大小、备份数量、格式等。我个人推荐用循环日志文件（rotating file），因为日志文件不会无限增长。

避坑指南：我曾经遇到过日志文件写满磁盘导致系统崩溃的情况。后来养成了两个习惯：一是用循环日志文件，限制最大大小；二是把日志目录挂载到独立分区，避免影响系统盘。

3.5 综合实战：一个完整的日志配置示例

说了这么多，咱们来个完整的例子。假设你有一个机器人导航节点，需要同时输出控制台日志和文件日志：

#include <rclcpp/rclcpp.hpp>
#include <spdlog/spdlog.h>
#include <spdlog/sinks/stdout_color_sinks.h>
#include <spdlog/sinks/rotating_file_sink.h>

class NavigationNode : public rclcpp::Node {
public:
    NavigationNode() : Node("navigation_node") {
        // 配置日志
        setup_logging();
        
        // 定时器，模拟高频日志
        timer_ = this->create_wall_timer(
            std::chrono::milliseconds(10),
            [this]() {
                // 节流日志：每秒最多打印一次
                RCLCPP_INFO_THROTTLE(
                    this->get_logger(),
                    *this->get_clock(),
                    1000,
                    "导航状态: 位置(%.2f, %.2f), 速度: %.2f",
                    position_x_, position_y_, speed_
                );
                
                // 条件日志：只在异常时打印
                if (speed_ > 2.0) {
                    RCLCPP_WARN_EXPRESSION(
                        this->get_logger(),
                        speed_ > 2.0,
                        "速度异常: %.2f m/s", speed_
                    );
                }
                
                // 一次性日志：只在第一次启动时打印
                static bool first_run = true;
                if (first_run) {
                    RCLCPP_INFO_ONCE(
                        this->get_logger(),
                        "导航节点启动完成，目标位置: (%.2f, %.2f)",
                        target_x_, target_y_
                    );
                    first_run = false;
                }
            }
        );
    }

private:
    void setup_logging() {
        // 创建控制台输出
        auto console_sink = std::make_shared<spdlog::sinks::stdout_color_sink_mt>();
        console_sink->set_pattern("[%H:%M:%S] %v");
        
        // 创建文件输出（循环日志）
        auto file_sink = std::make_shared<spdlog::sinks::rotating_file_sink_mt>(
            "/var/log/navigation/nav_node.log", 
            10485760,  // 10MB
            5          // 保留5个备份
        );
        file_sink->set_pattern("[%Y-%m-%d %H:%M:%S.%e][%l] %v");
        
        // 组合多个sink
        auto logger = std::make_shared<spdlog::logger>(
            "navigation_logger", 
            spdlog::sinks_init_list{console_sink, file_sink}
        );
        
        // 设置日志级别
        logger->set_level(spdlog::level::debug);
        
        // 注册到ROS2
        // 注意：实际项目中需要通过rclcpp的日志接口注册
    }
    
    double position_x_ = 0.0;
    double position_y_ = 0.0;
    double speed_ = 0.0;
    double target_x_ = 10.0;
    double target_y_ = 10.0;
    rclcpp::TimerBase::SharedPtr timer_;
};

这个例子把今天讲的四个技巧都用上了：条件日志、一次性日志、节流日志、日志文件持久化。你想想看，如果不用这些技巧，这个导航节点跑起来，日志文件会变成什么样子？

嗯，大概率是几秒钟就刷爆硬盘，然后你连问题出在哪都找不到。

总结一下：
  • 条件日志：用 RCLCPP_*_EXPRESSION 控制打印条件
  • 一次性日志：用 RCLCPP_*_ONCE 避免重复打印
  • 节流日志：用 RCLCPP_*_THROTTLE 控制打印频率
  • 文件持久化：用spdlog的rotating file sink实现循环日志

这些技巧，说白了就是让你在「信息完整」和「日志可控」之间找到平衡。我做了这么多年调试，最大的体会就是：日志不是越多越好，而是越精准越好。

下一章，咱们聊聊日志的格式化输出和自定义日志处理器，到时候你会看到更多实用技巧。

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