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):

rcutils/src/logging.c

Lines 1140 to 1145 in e276dc1

	static void vrcutils_log_internal(
	const rcutils_log_location_t * location,
	int severity, const char * name, const char * format, va_list * args)
	{
	rcutils_time_point_value_t now;
	rcutils_ret_t ret = rcutils_system_time_now(&now);

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.