I have been bothered by the verbosity of ROS2 logging macros for a while, so today I tried my hand at building an alternative. I wanted a solution built around C++ streams, that was terse and compositional, and minimized the number of arguments I’d have to provide in a logging statement.
What I did was to create a template class log with two parameters, the severity level and a Logger callable class. log encapsulates a stringstream, and on destruction passes the severity and the accumulated state of that object to the Logger callable. By default Logger simply prints the accumulated statement with the given severity, but it can be replaced by e.g. a throttle logger that implements throttling logging.
See the code below for details:
/**
* @file
*
* Logging utilities.
*
* @author Helio Perroni Filho
*/
#ifndef ROS_COMMONS_LOG_H
#define ROS_COMMONS_LOG_H
#include <rclcpp/rclcpp.hpp>
namespace ros_commons {
namespace ros = rclcpp;
/**
* @brief Debug severity level.
*/
constexpr enum RCUTILS_LOG_SEVERITY debug = RCUTILS_LOG_SEVERITY_DEBUG;
/**
* @brief Info severity level.
*/
constexpr enum RCUTILS_LOG_SEVERITY info = RCUTILS_LOG_SEVERITY_INFO;
/**
* @brief Warning severity level.
*/
constexpr enum RCUTILS_LOG_SEVERITY warn = RCUTILS_LOG_SEVERITY_WARN;
/**
* @brief Error severity level.
*/
constexpr enum RCUTILS_LOG_SEVERITY error = RCUTILS_LOG_SEVERITY_ERROR;
/**
* @brief Fatal error severity level.
*/
constexpr enum RCUTILS_LOG_SEVERITY fatal = RCUTILS_LOG_SEVERITY_FATAL;
/**
* @brief Simple logger, emits statements with given severity level.
*/
struct simple {
inline void operator () (enum RCUTILS_LOG_SEVERITY severity, ros::Node *node, const std::string &statement) {
RCUTILS_LOG_COND_NAMED(
severity,
RCUTILS_LOG_CONDITION_EMPTY, RCUTILS_LOG_CONDITION_EMPTY,
node->get_logger().get_name(), "%s", statement.c_str()
);
}
};
/**
* @brief Throttled logger, emits statements with given severity level at a set interval.
*/
template<rcutils_duration_value_t duration>
struct throttle {
inline void operator () (enum RCUTILS_LOG_SEVERITY severity, ros::Node *node, const std::string &statement) {
auto get_time_point = [node](rcutils_time_point_value_t *time_point) -> rcutils_ret_t {
try {
*time_point = node->now().nanoseconds();
}
catch (...) {
RCUTILS_SAFE_FWRITE_TO_STDERR("[rclcpp|logging.hpp] RCLCPP_DEBUG_THROTTLE could not get current time stamp\n");
return RCUTILS_RET_ERROR;
}
return RCUTILS_RET_OK;
};
RCUTILS_LOG_COND_NAMED(
severity,
RCUTILS_LOG_CONDITION_THROTTLE_BEFORE(get_time_point, duration), RCUTILS_LOG_CONDITION_THROTTLE_AFTER,
node->get_logger().get_name(), "%s", statement.c_str()
);
}
};
/**
* @brief Build and execute a log statement.
*/
template<enum RCUTILS_LOG_SEVERITY severity, class Logger = simple>
class log {
/** @brief Logging function. */
Logger log_;
/** @brief Pointer to underlying ROS node. */
ros::Node *node_;
/** @brief String stream to build log statement. */
std::stringstream stream_;
public:
/**
* @brief Create the log statement builder.
*/
inline log(ros::Node *node):
node_(node)
{
// Nothing to do.
}
/**
* @brief Class destructor.
*/
inline ~log() {
log_(severity, node_, stream_.str());
}
/**
* @brief Add the given value to the log statement.
*/
template<class T>
inline log &operator << (const T &value) {
stream_ << value;
return *this;
}
};
} // namespace ros_commons
#endif
With appropriate using statements the above allows me to write logging calls as below:
using ros_commons::log;
using ros_commons::info;
using ros_commons::warn;
using ros_commons::error;
using ros_commons::fatal;
using ros_commons::throttle;
// ...
// "this" here is assumed to be of type Node*.
log<info>(this) << "A logging statement of INFO severity."
log<warn, throttle<1000>>(this) << "A warning that is repeated every " << 1 << " second at most."
Compared to standard ROS2 macros, this has the disadvantage that logging statements can’t be as easily suppressed at compile time: I thought of setting the severity levels to RCUTILS_LOG_SEVERITY_UNSET depending on the value of RCLCPP_LOG_MIN_SEVERITY, then using template specialization to select an empty version of ~log(), but that still wouldn’t suppress the operator << calls.
On the bright side, this does tick all my boxes: logging statements are simpler and more compact, with an easier to remember API. And I don’t usually play with compile-time severity level filtering, so the loss of that ability doesn’t really affect me.
Thoughts?
