Update throttle logging docs with units and data type hints (re: rclcpp/issues/1929)

[danzimmerman]

Relates to the discussion in ros2/rclcpp#1929 about changing the throttled macros.

In the interim, since RCLCPP_INFO_THROTTLE and related macros are pretty basic functionality that newer C++/ROS2 users might want, it's worth adding an explicit note about how to convert a rclcpp::Duration to a usable type for the message interval in those macros.

[fujitatomoya]

@danzimmerman thanks for contributing.

Will we support the Duration? If so, why we add the document for that when we do support it?

I think complication for now is that there is no clear description that these throttle macro only accepts millisecond? so probably adding that note would be helpful for user?

How about adding the note to API section?

https://github.com/ros2/ros2_documentation/blob/rolling/source/Concepts/About-Logging.rst#apis

[danzimmerman]

I think complication for now is that there is no clear description that these throttle macro only accepts millisecond? so probably adding that note would be helpful for user?

Yes, I think that a note about milliseconds as an integer argument will be necessary even after a PR against rclcpp/#1929 is merged. Makes sense to add that where you suggest.

I also see that an IDE will help more once I upgrade rclcpp and get the Humble backport of rcutils/pull/359. Then I know it is an integer in milliseconds from an IDE hint👍

I think that I still want to find a hint for a new user that you can get a rclcpp::Duration::nanoseconds() to get integer nanoseconds if you need or want to do some math to get the argument. Maybe a link to the API docs is sufficient? (It took me forever to find them, see below)

I have several reasons after encountering the above that I think some kind of simple hint is worthwhile until the simple beginner code below compiles and works correctly. Imagine a fast external caller is giving me a rclcpp::Duration called period, like in a plugin framework:

RCLCPP_INFO_THROTTLE(this->get_node()->get_logger(),
    clk,
    period/50, 
    "update() returns OK at 1/50th the loop rate"
);

Here's what happens.

• The compiler error suggests you need a rcutils_duration_value_t but of course can't tell you that you should use milliseconds. Why can't I just call rclcpp::Duration::nanoseconds(), which returns rcutils_duration_value_t? I feel like hints are nice if you're leaking abstractions.
• I want to understand what a rclcpp::Duration is, but the API documentation for recent releases is obscure and barely discoverable.
  • Thanks again to @aprotyas for this comment that I found after a long time. I found this ROS Discourse post, I conducted a search of this repository's issues for "API", and found #2309.
  • I now know that rclcpp::Duration for my release is documented at https://docs.ros.org/en/ros2_packages/humble/api/rclcpp/generated/classrclcpp_1_1Duration.html?highlight=duration#_CPPv4NK6rclcpp8Duration11nanosecondsEv
  • Google search results and the search box on the Galactic/Humble/Rolling documentation sites do not surface this latest documentation. In this discussion, we may know that it hasn't changed since Dashing/Foxy but how do I know that for sure?
• It feels helpful and convenient to point out that .nanoseconds() is a getter for the entire duration in integer nanoseconds. ROS2 message stamps and ROS1 Time both use .seconds and .nanoseconds differently, which can cause headaches for a new developer. The terse documentation in my IDE suggests these methods return the entire duration, but it's difficult to double check to be sure, especially in C++ with a non-source install. Again, @aprotyas is helping out nicely on ROS Answers (the third google search result for something), but shouldn't the documentation help out too?

Maybe, per the last point, I just want the Doxygen comment on .nanoseconds() to say "Returns the entire duration in nanoseconds." or something?

Or I should make a PR on API documentation discoverability?

Or write a page on rclcpp/rclpy Time API to go in the main docs?

Possibly all of the above?

I understand that this is kind of a messy conflation of documentation discoverability issues and actual documentation issues.

Thanks for the suggestion and I think over time I will try to

• Change this PR as @fujitatomoya suggests, which remains helpful after the macros support Duration
• Think about how to change the comment on the .seconds() and .nanoseconds() methods to emphasize that they return the entire duration, not a whole and fractional part
• Try to draft a page on the Time API for the main docs. (Is it okay to discuss the differences from ROS1 there?)
• Think if I can contribute to Links to rclcpp and rclpy API in rolling distro documentation refer to foxy related API #2309, but it seems like that's a pretty far-reaching backend issue since the various API links aren't good for templating across distribution name.
• See if there's a place to manually add the distros' generated API docs links to docs.ros.org

Unfortunately my C chops aren't good enough to efficiently work on
rclcpp/#1929, because that certainly solves many of the issues for RCLCPP_*_THROTTLE

[fujitatomoya]

@danzimmerman thanks for the information.

I have several reasons after encountering the above that I think some kind of simple hint is worthwhile until the simple beginner code below compiles and works correctly.

I see, that example makes sense and user application perspective, that something user would do.

as @clalancette mentioned here, ros2/rclcpp#1929 (comment), probably we can add new macro for that case to keep backward compatibility.

[clalancette]

I don't think we should phrase it like this. It is enough to say:

The data type of the interval parameter needs to be implicitly convertible to an ``rcutils_duration_value_t`` (an int64_t).

[gavanderhoorn]

If this is for beginners/new users as @danzimmerman writes, implicitly convertible might not be something the reader would understand.

[danzimmerman]

Took a stab at text that captures both of these. I retained a code example of how to use rclcpp::Duration::nanoseconds() to use an existing variable, but happy to remove that if it's not appropriate.

[clalancette]

One more change since it was mixing printf and stream styles.

Otherwise this seems reasonable to me.

[danzimmerman]

@clalancette @fujitatomoya There's still the question of whether or not this PR should include a similar brief note about integer milliseconds at https://github.com/ros2/ros2_documentation/blob/rolling/source/Concepts/About-Logging.rst

Happy to add that too.

[clalancette]

@clalancette @fujitatomoya There's still the question of whether or not this PR should include a similar brief note about integer milliseconds at https://github.com/ros2/ros2_documentation/blob/rolling/source/Concepts/About-Logging.rst

I think it does make sense to update this block:

ros2_documentation/source/Concepts/About-Logging.rst

Lines 47 to 81 in 375b6cf

	.. tabs::
	.. group-tab:: C++
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}`` - output the given printf-style message every time this line is hit
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_ONCE`` - output the given printf-style message only the first time this line is hit
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_EXPRESSION`` - output the given printf-style message only if the given expression is true
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_FUNCTION`` - output the given printf-style message only if the given function returns true
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_SKIPFIRST`` - output the given printf-style message all but the first time this line is hit
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_THROTTLE`` - output the given printf-style message no more than the given rate
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_SKIPFIRST_THROTTLE`` - output the given printf-style message no more than the given rate, but skip the first
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM`` - output the given C++ stream-style message every time this line is hit
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM_ONCE`` - output the given C++ stream-style message only the first time this line is hit
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM_EXPRESSION`` - output the given C++ stream-style message only if the given expression is true
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM_FUNCTION`` - output the given C++ stream-style message only if the given function returns true
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM_SKIPFIRST`` - output the given C++ stream-style message all but the first time this line is hit
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM_THROTTLE`` - output the given C++ stream-style message no more than the given rate
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM_SKIPFIRST_THROTTLE`` - output the given C++ stream-style message no more than the given rate, but skip the first
	Each of the above APIs takes an ``rclcpp::Logger`` object as the first argument.
	This can be pulled from the node API by calling ``node->get_logger()`` (recommended), or by constructing a stand-alone ``rclcpp::Logger`` object.
	* ``rcutils_logging_set_logger_level`` - Set the logging level for a particular logger name to the given severity level
	* ``rcutils_logging_get_logger_effective_level`` - Given a logger name, return the logger level (which may be unset)
	.. group-tab:: Python
	* ``logger.{debug,info,warning,error,fatal}`` - output the given Python string to the logging infrastructure. The calls accept the following keyword args to control behavior:
	* ``throttle_duration_sec`` - if not None, the duration of the throttle interval
	* ``skip_first`` - if True, output the message all but the first time this line is hit
	* ``once`` - if True, only output the message the first time this line is hit
	* ``rclpy.logging.set_logger_level`` - Set the logging level for a particular logger name to the given severity level
	* ``rclpy.logging.get_logger_effective_level`` - Given a logger name, return the logger level (which may be unset)

. That is, instead of just saying "rate", say "rate in milliseconds". Also, for the Python version, it should be "rate in seconds as a double".

[fujitatomoya]

@clalancette @fujitatomoya There's still the question of whether or not this PR should include a similar brief note about integer milliseconds at https://github.com/ros2/ros2_documentation/blob/rolling/source/Concepts/About-Logging.rst

I think it does make sense to update this block:

ros2_documentation/source/Concepts/About-Logging.rst

Lines 47 to 81 in 375b6cf

	.. tabs::
	.. group-tab:: C++
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}`` - output the given printf-style message every time this line is hit
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_ONCE`` - output the given printf-style message only the first time this line is hit
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_EXPRESSION`` - output the given printf-style message only if the given expression is true
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_FUNCTION`` - output the given printf-style message only if the given function returns true
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_SKIPFIRST`` - output the given printf-style message all but the first time this line is hit
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_THROTTLE`` - output the given printf-style message no more than the given rate
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_SKIPFIRST_THROTTLE`` - output the given printf-style message no more than the given rate, but skip the first
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM`` - output the given C++ stream-style message every time this line is hit
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM_ONCE`` - output the given C++ stream-style message only the first time this line is hit
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM_EXPRESSION`` - output the given C++ stream-style message only if the given expression is true
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM_FUNCTION`` - output the given C++ stream-style message only if the given function returns true
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM_SKIPFIRST`` - output the given C++ stream-style message all but the first time this line is hit
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM_THROTTLE`` - output the given C++ stream-style message no more than the given rate
	* ``RCLCPP_{DEBUG,INFO,WARN,ERROR,FATAL}_STREAM_SKIPFIRST_THROTTLE`` - output the given C++ stream-style message no more than the given rate, but skip the first
	Each of the above APIs takes an ``rclcpp::Logger`` object as the first argument.
	This can be pulled from the node API by calling ``node->get_logger()`` (recommended), or by constructing a stand-alone ``rclcpp::Logger`` object.
	* ``rcutils_logging_set_logger_level`` - Set the logging level for a particular logger name to the given severity level
	* ``rcutils_logging_get_logger_effective_level`` - Given a logger name, return the logger level (which may be unset)
	.. group-tab:: Python
	* ``logger.{debug,info,warning,error,fatal}`` - output the given Python string to the logging infrastructure. The calls accept the following keyword args to control behavior:
	* ``throttle_duration_sec`` - if not None, the duration of the throttle interval
	* ``skip_first`` - if True, output the message all but the first time this line is hit
	* ``once`` - if True, only output the message the first time this line is hit
	* ``rclpy.logging.set_logger_level`` - Set the logging level for a particular logger name to the given severity level
	* ``rclpy.logging.get_logger_effective_level`` - Given a logger name, return the logger level (which may be unset)

. That is, instead of just saying "rate", say "rate in milliseconds". Also, for the Python version, it should be "rate in seconds as a double".

@danzimmerman I am with @clalancette on this. thanks for the effort 👍

[clalancette]

This looks good to me, thanks for the updates.

@fujitatomoya what do you think?

[fujitatomoya]

@danzimmerman thank you for iterating, i am good to go!