ROS 2 ログシステムの使い方
海洋ロボコンをやってた人です。
今回はROS 2ログシステムのチップスを記載していきます。
毎度コンソールがログだらけになり、実機確認時にもログが出ていると本当に確認したい情報を見つけるのが大変であり、ログON/OFFや状況に応じた使い分けがしたいというのが経緯です。
チュートリアルレベルの内容になりますので、見たいSectionからご確認ください。
修正点等あればご遠慮なくご指摘ください。
以下箇条書きになりますが、よろしくお願いします。
1. LoggerLevel
ログシステムは、あらゆるシステム（ロボットアプリケーション、車載、IoTデバイス）のデバッグや監視において重要な現場でも日常的に利用される機能です。
適切なログレベルでの出力で、システムの動作状況を把握し、問題の特定や解決を効率的に行うことができます。
コードフリーズ(プログラムに変更を加えない期間）、各種評価、テストする際にログOFF/ログONするため、アジャイル開発において重要な機能となります。
ROS 2では、以下の特徴を持つ強力なログシステムが提供されており、これらを活用することでデバックしやすいソフトウェア開発を行うことができます。
後述しますが、ROS 2のログシステムはデフォルトでカラー設定もされており、非常に見やすいのも良い点です。
ログレベルはLoggerLevel: This is a ROS message definition.で定義されており、下記（重要度順）となります。
| レベル | 値 | 用途 | 説明 |
|---|---|---|---|
| DEBUG | 10 | デバッグ情報 | 開発時の詳細な動作確認用 |
| INFO | 20 | 一般情報 | 正常な動作状況の記録 |
| WARN | 30 | 警告 | 問題の可能性があるが動作継続可能 |
| ERROR | 40 | エラー | 処理に失敗したが致命的ではない |
| FATAL | 50 | 致命的エラー | システム停止を要する重大な問題 |
1.1 C++ Basic Log Output
ログ出力スタイルはprintfスタイルとC++スタイルの２種類があります。
#include <rclcpp/rclcpp.hpp>
class Logger : public rclcpp::Node
{
public:
Logger(){
// printf スタイル
RCLCPP_DEBUG(this->get_logger(), "デバッグメッセージ: %d", value);
RCLCPP_INFO(this->get_logger(), "情報メッセージ: %s", status.c_str());
RCLCPP_WARN(this->get_logger(), "警告メッセージ: %f", temperature);
RCLCPP_ERROR(this->get_logger(), "エラーメッセージ: %d", error_code);
RCLCPP_FATAL(this->get_logger(), "致命的エラー: %s", error_msg.c_str());
// C++ ストリームスタイル
RCLCPP_DEBUG_STREAM(this->get_logger(), "デバッグ: " << value);
RCLCPP_INFO_STREAM(this->get_logger(), "情報: " << status);
RCLCPP_WARN_STREAM(this->get_logger(), "警告: " << temperature);
RCLCPP_ERROR_STREAM(this->get_logger(), "エラー: " << error_code);
RCLCPP_FATAL_STREAM(this->get_logger(), "致命的: " << error_msg);
}
1.2 Python Basic Log Output
pythonの場合も同様です。
import rclpy
from rclpy.node import Node
# 基本的なログ出力
node.get_logger().debug('デバッグメッセージ: %d' % value)
node.get_logger().info('情報メッセージ: %s' % status)
node.get_logger().warning('警告メッセージ: %f' % temperature)
node.get_logger().error('エラーメッセージ: %d' % error_code)
node.get_logger().fatal('致命的エラー: %s' % error_msg)
# f-string を使用した方法
node.get_logger().info(f'処理完了: {result}')
2. Conditional logging
続いて、条件付きのログ出力についても見ていきます。
2.1. ONCE
特定のログメッセージを初回のみ出力したい場合は下記のように記述します。
// C++
RCLCPP_INFO_ONCE(node->get_logger(), "この警告は初回のみ表示されます");
RCLCPP_INFO_STREAM_ONCE(node->get_logger(), "初回のみ: " << value);
# Python
node.get_logger().info('初回のみのメッセージ', once=True)
2.2. SKIPFIRST
初回の呼び出しをスキップし、2回目以降にログを出力したい場合は下記のように記述します。
// C++
RCLCPP_WARN_SKIPFIRST(node->get_logger(), "初回はスキップされる警告: %d", count);
RCLCPP_WARN_STREAM_SKIPFIRST(node->get_logger(), "初回スキップ: " << message);
# Python
node.get_logger().warning('初回スキップメッセージ', skip_first=True)
2.3. THROTTLE
指定した間隔でのみログを出力したい場合は下記のように記述します。
// C++ - 1秒間隔でのみ出力
RCLCPP_ERROR_THROTTLE(node->get_logger(), *node->get_clock(), 1000, "スロットリングエラー: %d", error_count);
RCLCPP_ERROR_STREAM_THROTTLE(node->get_logger(), *node->get_clock(), 1000, "スロットリング: " << message);
// Duration オブジェクトを使用する場合
RCLCPP_ERROR_STREAM_THROTTLE(node->get_logger(), *node->get_clock(),
msg_interval.nanoseconds()/1000000, "メッセージ: " << data);
# Python - 1秒間隔でのみ出力
node.get_logger().error(f'スロットリングエラー: {error_count}', throttle_duration_sec=1)
2.4. SKIPFIRST_THROTTLE
初回をスキップし、かつ指定間隔でのみ出力したい場合は下記のように記述します。
// C++
RCLCPP_DEBUG_SKIPFIRST_THROTTLE(node->get_logger(), *node->get_clock(), 1000, "複合条件: %d", value);
# Python
node.get_logger().debug(f'複合条件メッセージ: {value}',
skip_first=True, throttle_duration_sec=1.0)
3. Logger Demo
ログの挙動を確認するためのデモも見ていきます。
ros2 run logging_demo logging_demo_main
Section 1.で記載したログが表示されます。
ros2 run rqt_console rqt_console
rqtで確認することができます。
--ros-args --log-level debug
--ros-args --log-level info
--ros-args --log-level warn
--ros-args --log-level error
--ros-args --log-level fatal
を末尾につけると、そのログレベル以上を出力することができます。
例えばよく使う、demo_node_cppもdebug, infoで分けてみると、
ros2 run demo_nodes_cpp talker --ros-args --log-level info
ros2 run demo_nodes_cpp talker --ros-args --log-level debug
とログ出力でdebug記載されている記述も確認できるようになります。
Reference
ROS 2 Foxy Tutorials/Demos/Logging
以上、Likeいただけると大変励みになりますので、よろしくお願いいたします。
Discussion