Draft: Document internals of logging system by tylerjw · Pull Request #2028 · ros2/ros2_documentation

tylerjw · 2021-10-17T20:57:33Z

Signed-off-by: Tyler Weaver tylerjw@gmail.com

Closes #2026

@JafarAbdi would you mind reviewing this for correctness and completeness? You recently had to trace this code to create your PR against it for file based configuration.

@clalancette here is my initial attempt at documenting this. Would you mind reviewing this for structure, organization, and completeness from a high level? I'm unsure how to organize this documentation within the existing page(s) describing the logging system.

tylerjw · 2021-10-17T21:10:28Z

Here are warnings that I get when I build locally. I need to read up on rst syntax and fix these:

/home/tyler/code/websites/ros2_documentation/source/Concepts/About-Logging.rst:139: WARNING: 'any' reference target not found: ../Tutorials/Logging-and-logger-configuration.html#logger-level-configuration-command-line
/home/tyler/code/websites/ros2_documentation/source/Concepts/About-Logging.rst:229: WARNING: 'any' reference target not found: INFO
/home/tyler/code/websites/ros2_documentation/source/Concepts/About-Logging.rst:256: WARNING: 'any' reference target not found: isatty

Signed-off-by: Tyler Weaver <tylerjw@gmail.com>

JafarAbdi

@tylerjw Thank you for starting this effort!

JafarAbdi · 2021-10-18T17:07:55Z

source/Concepts/About-Logging.rst

+There is currently only one external library interface defined and that is ``rcl_logging_spdlog``.
+The external-lib implementation is set during the CMake configure step of the package ``rcl``.
+It can be overridden with the variable ``RCL_LOGGING_IMPLEMENTATION``.
+The ``rcl_logging`` README says there is a ``rcl_logging_log4cxx`` implementation, however that does not appear to exist yet.


This was supported previously and got removed

Maybe another PR can be created updating the rcl_logging README, or at least an issue opened?

Suggested change

The ``rcl_logging`` README says there is a ``rcl_logging_log4cxx`` implementation, however that does not appear to exist yet.

JafarAbdi · 2021-10-18T17:24:12Z

source/Concepts/About-Logging.rst

+Log files
+---------
+
+Log output files written to a directory that defaults to ``~/.ros/log`` but can be changed through enviroment variables.  The filenames follow this pattern:
+
+  ``<exe>_<pid>_<milliseconds-since-epoch>.log``
+
+These are created per operating system process.
+The external lib logging using ``spdlog`` is what writes these files in the current implementation.


Should we move this part to https://github.com/ros2/ros2_documentation/blob/rolling/source/Tutorials/Logging-and-logger-configuration.rst?, I see there's a section about Logging directory configuration

clalancette · 2021-10-22T14:53:06Z

source/Concepts/About-Logging.rst

+Logging from a Python ROS Node
+------------------------------
+
+The Python interfaces are built on top of ``rclcpp`` and therefore share the same functionality.


This is definitely not true; rclcpp and rclpy are siblings. It may be true that rclpy depends on rcl, though I'm not sure of that; Python has robust logging facilities of its own, we may be using those instead.

clalancette

This is a good start to this documentation.

That said, adding this information to this document mixes up the user-facing portion of the Concept with the technical details on how things are implemented. I might suggest that we split this into two documents; the current Concepts/About-Logging.rst talks about the logging system from the users POV (with some additional notes from what you've written below), and then a new Concepts/Logging-Implementation.rst which describes how it is implemented. What do you think?

audrow

This looks like great content to add. I agree with @clalancette about splitting it up.

Some general feedback, that may be more from it being a "Draft" state is that there are several times that things are implicitly referenced (e.g., "This is necessary because..." and "One implication of this is..."). It is often not clear to me what "this" is referring to. It would be good to be more specific, even if you feel it is a bit needlessly wordy.

audrow · 2021-12-21T23:45:21Z

source/Concepts/About-Logging.rst

+Compiling out logging
+^^^^^^^^^^^^^^^^^^^^^
+
+To compile wihtout logging set ``RCLCPP_LOGGING_ENABLED=0`` and ``RCLCPP_LOG_MIN_SEVERITY=RCLCPP_LOG_MIN_SEVERITY_NONE``.


Suggested change

To compile wihtout logging set ``RCLCPP_LOGGING_ENABLED=0`` and ``RCLCPP_LOG_MIN_SEVERITY=RCLCPP_LOG_MIN_SEVERITY_NONE``.

To compile without logging, set ``RCLCPP_LOGGING_ENABLED=0`` and ``RCLCPP_LOG_MIN_SEVERITY=RCLCPP_LOG_MIN_SEVERITY_NONE``.

audrow · 2021-12-21T23:46:33Z

source/Concepts/About-Logging.rst

+
+One implication of this is that in any ROS process based on ``rclcpp`` it is single-threaded during logging.
+To combat the performance implications of this you can use throttling.
+This is necessary because the logging system writes to file streams (stderr, stdout, normal files) which cannot be done from multiple threads in a sane way.
+A possible technique to log from a thread you need to be lock-free would be to use internal queues to send data to another thread that then logs your data.


Suggested change

One implication of this is that in any ROS process based on ``rclcpp`` it is single-threaded during logging.

To combat the performance implications of this you can use throttling.

This is necessary because the logging system writes to file streams (stderr, stdout, normal files) which cannot be done from multiple threads in a sane way.

A possible technique to log from a thread you need to be lock-free would be to use internal queues to send data to another thread that then logs your data.

One implication of this is that in any ROS process based on ``rclcpp`` is single-threaded during logging.

This is necessary because the logging system writes to file streams (stderr, stdout, normal files) which cannot easily be done from multiple threads.

I think this paragraph can have some explanation cut and can be combined with the above paragraph.

Maybe add the cutout segments as notes, for example.

audrow · 2021-12-21T23:48:45Z

source/Concepts/About-Logging.rst

+
+To compile wihtout logging set ``RCLCPP_LOGGING_ENABLED=0`` and ``RCLCPP_LOG_MIN_SEVERITY=RCLCPP_LOG_MIN_SEVERITY_NONE``.
+
+Will this only work with a source build of ros2 or can this be done per project that depends on ros2?


Suggested change

Will this only work with a source build of ros2 or can this be done per project that depends on ros2?

Will this only work with a source build of ROS 2, or can this be done per project that depends on ROS 2?

We prefer "ROS 2."

audrow · 2021-12-21T23:51:02Z

source/Concepts/About-Logging.rst

+rclcpp ``Logger`` class
+^^^^^^^^^^^^^^^^^^^^^^^
+
+Stores a name string.


Suggested change

Stores a name string.

The ``Logger`` class stores a name string, which is used to identify the logger.

audrow · 2021-12-21T23:55:39Z

source/Concepts/About-Logging.rst

+``RCLCPP`` macros
+^^^^^^^^^^^^^^^^^
+
+Defined by generated header in rclcpp (rclcpp/resource/logging.hpp.em).


It would be nice to make the first lines of sections full sentences, or to format them differently, in a way that clearly indicates this is a definition.

audrow · 2021-12-22T00:01:34Z

source/Concepts/About-Logging.rst

+rosout logging
+^^^^^^^^^^^^^^
+
+Publishes a ``rcl_interfaces::Log`` message to the topic /node-name/rosout.


Suggested change

Publishes a ``rcl_interfaces::Log`` message to the topic /node-name/rosout.

Publishes a ``rcl_interfaces::Log`` message to the topic ``/node-name/rosout``.

audrow · 2021-12-22T00:02:55Z

source/Concepts/About-Logging.rst

+There is currently only one external library interface defined and that is ``rcl_logging_spdlog``.
+The external-lib implementation is set during the CMake configure step of the package ``rcl``.
+It can be overridden with the variable ``RCL_LOGGING_IMPLEMENTATION``.
+The ``rcl_logging`` README says there is a ``rcl_logging_log4cxx`` implementation, however that does not appear to exist yet.


Maybe another PR can be created updating the rcl_logging README, or at least an issue opened?

audrow · 2021-12-22T00:03:37Z

source/Concepts/About-Logging.rst

+There is currently only one external library interface defined and that is ``rcl_logging_spdlog``.
+The external-lib implementation is set during the CMake configure step of the package ``rcl``.
+It can be overridden with the variable ``RCL_LOGGING_IMPLEMENTATION``.
+The ``rcl_logging`` README says there is a ``rcl_logging_log4cxx`` implementation, however that does not appear to exist yet.


Suggested change

The ``rcl_logging`` README says there is a ``rcl_logging_log4cxx`` implementation, however that does not appear to exist yet.

audrow · 2021-12-22T00:04:15Z

source/Concepts/About-Logging.rst

+RCUTILS internals
+-----------------
+
+``rcutils`` contains macros and functions that define some of the non-ros low-level logging behavior in C.


Suggested change

``rcutils`` contains macros and functions that define some of the non-ros low-level logging behavior in C.

``rcutils`` contains macros and functions that define some of the non-ROS low-level logging behavior in C.

audrow · 2021-12-22T00:05:09Z

source/Concepts/About-Logging.rst

+     - Don't use colours.
+
+If it is unset, colors are used depending on if the target stream is a terminal or not.
+See `isatty` documentation.


It would be nice to add a link here.

clalancette · 2022-09-23T12:50:05Z

Closing in favor of the just merged #3025. It doesn't have quite as much detail as this one has, but I think it is good enough for the end-user to understand what is going on. We should probably have a separate design document somewhere about the real internals of the logging subsystem, but that would probably live in https://github.com/ros-infrastructure/rep .

tylerjw force-pushed the logging-concepts branch from ba0c61e to 3ab8894 Compare October 17, 2021 21:03

tylerjw force-pushed the logging-concepts branch from 3ab8894 to 1ee4ffe Compare October 17, 2021 21:13

Document internals of logging system

2f50b88

Signed-off-by: Tyler Weaver <tylerjw@gmail.com>

tylerjw force-pushed the logging-concepts branch from 1ee4ffe to 2f50b88 Compare October 17, 2021 21:17

JafarAbdi reviewed Oct 18, 2021

View reviewed changes

clalancette reviewed Oct 22, 2021

View reviewed changes

clalancette self-assigned this Nov 11, 2021

audrow requested changes Dec 22, 2021

View reviewed changes

clalancette mentioned this pull request Sep 16, 2022

Significantly clean up and expand the documentation about logging. #3025

Merged

clalancette closed this Sep 23, 2022

tylerjw deleted the logging-concepts branch September 23, 2022 14:54

	To compile wihtout logging set ``RCLCPP_LOGGING_ENABLED=0`` and ``RCLCPP_LOG_MIN_SEVERITY=RCLCPP_LOG_MIN_SEVERITY_NONE``.
	To compile without logging, set ``RCLCPP_LOGGING_ENABLED=0`` and ``RCLCPP_LOG_MIN_SEVERITY=RCLCPP_LOG_MIN_SEVERITY_NONE``.


		To compile wihtout logging set ``RCLCPP_LOGGING_ENABLED=0`` and ``RCLCPP_LOG_MIN_SEVERITY=RCLCPP_LOG_MIN_SEVERITY_NONE``.

		Will this only work with a source build of ros2 or can this be done per project that depends on ros2?

	Stores a name string.
	The ``Logger`` class stores a name string, which is used to identify the logger.

	Publishes a ``rcl_interfaces::Log`` message to the topic /node-name/rosout.
	Publishes a ``rcl_interfaces::Log`` message to the topic ``/node-name/rosout``.

	``rcutils`` contains macros and functions that define some of the non-ros low-level logging behavior in C.
	``rcutils`` contains macros and functions that define some of the non-ROS low-level logging behavior in C.

Conversation

tylerjw commented Oct 17, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

tylerjw commented Oct 17, 2021

Uh oh!

JafarAbdi left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

clalancette left a comment

Choose a reason for hiding this comment

Uh oh!

audrow left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

clalancette commented Sep 23, 2022

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

tylerjw commented Oct 17, 2021 •

edited

Loading

audrow left a comment •

edited

Loading