Should logging use ROS time instead of system time?

[jrutgeer]

On each log message, the time is passed to the log handlers so it can be included in the log message output.

Currently, this is the system time (rcutils_system_time_now):

https://github.com/ros2/rcutils/blob/e276dc1fe5a0e450e53423ec71d57cbe05b129f8/src/logging.c#L1140-L1145

This seems strange, as it means that you can't relate log message time to other data time (e.g. message time stamps) in case of use_sim_time:=true.

• Is this intentional?
• What would be the impact of changing rcutils_system_time_now() to rcl_get_ros_time()?

[clalancette]

• What would be the impact of changing rcutils_system_time_now() to rcl_get_ros_time()?

Unfortunately we can't do that, as it would introduce a circular dependency between rcutils and rcl.

That said, I see the overall need for this. What we'd have to do is use a "dependency injection" design, where we have a callback that can be set by users of rcutils. By default, this callback would call rcutils_system_time_now, but during rcl initialization we could replace that callback with a call to rcl_get_ros_time. I think that would work, but there may be some details I'm not thinking of right now.

[jrutgeer]

Ok, given it's a non-trivial change and aparently not an issue that a lot of people run into, I will close this and add a reference here so this can be evaluated whenever the log system gets overhauled.