Replace print() in python demos with logger calls #190
Conversation
| @@ -25,11 +26,15 @@ class ListenerQos(rclpy.Node): | |||
|
|
|||
| def __init__(self, qos_profile): | |||
| super().__init__('listener_qos') | |||
| if qos_profile.reliability is QoSReliabilityPolicy.RMW_QOS_POLICY_RELIABILITY_RELIABLE: | |||
| self.get_logger().info('Reliable listener') | |||
There was a problem hiding this comment.
It's not obvious to me that this is actually performing a logging action compared to the API suggested originally in ros2/rclpy#103, maybe just calling the function loginfo or a log function taking a severity keyword would be clearer.
I know the recent discussion was focused on the c++ API but how do we expect the API to look like for the users in python?
There was a problem hiding this comment.
the .log(,INFO) option is also available on this logger, following ros2/rclpy#103 (comment) (which came from a team discussion), .info() is offered for convenience. Both options mirror what is offered by python logging, we seem to prefer the .info(): https://github.com/ros2/ros2cli/blob/9fce6a08381bb67cf17e7160b0b2c6556ffec1e6/ros2cli/ros2cli/entry_points.py#L87
There was a problem hiding this comment.
Ok so the goal is to use an API as close as python native logging as possible rather than something closer to ROS 1. We do provide both but will use this one in our examples. Fair enough.
With ros2/rclpy#148 (comment) it now make sense why we don't something like self.mylogger.loginfo()
There was a problem hiding this comment.
Following up on this, if I understand correctly your initial concern was referring to how we would use the generic logging functions (e.g. rclpy.logging.loginfo()) as opposed to log calls being made on specific logger objects (which weren't around in ROS 1).
On the use of mylogger.info() as opposed to mylogger.log(, severity=INFO), as you noted I've chosen to mirror the typical usage of native python logging. https://docs.python.org/3/howto/logging-cookbook.html, for example, uses mylogger.info() in all cases except where the severity is chosen programatically, for which case the mylogger.log(, severity=INFO) form is available
There was a problem hiding this comment.
LGTM with one tiny change.
It's not caused by this PR, but it seems like the logged messages are really long. What do you think about having just the filename and leaving out the directory when printing to console?
[INFO] [talker_qos]: Publishing: "Hello World: 0" (timer_callback() at /workspace/ros2_ws/build_isolated/demo_nodes_py/demo_nodes_py/topics/talker_qos.py:43)
| if qos_profile.reliability is QoSReliabilityPolicy.RMW_QOS_POLICY_RELIABILITY_RELIABLE: | ||
| self.get_logger().info('Reliable listener') | ||
| else: | ||
| self.get_logger().info('Best effort listener') |
ros2/rcutils#72 shortens the default console output formatting |
|
Is this ready for review? |
|
yes, I moved the connected tickets across and asked for its review in ros2/rclpy#148 but the label didn't update here |
dhood
added
in review
|
|
||
|
|
||
| def main(service_type, lifecycle_node, change_state_args='', args=None): | ||
| rclpy.init(args=args) | ||
|
|
||
| if not rclpy.ok(): |
There was a problem hiding this comment.
This is not necessary anymore because init would raise on failure ?
There was a problem hiding this comment.
yep, thanks for making it explicit 😄
| @@ -25,6 +26,10 @@ def main(): | |||
| package = 'topic_monitor' | |||
| executable = get_executable_path(package_name=package, executable_name='data_publisher') | |||
|
|
|||
| # Strip the logger name from the message format in favor of the shorter executable name | |||
| os.environ['RCUTILS_CONSOLE_OUTPUT_FORMAT'] = '[{severity}] {message}' | |||
There was a problem hiding this comment.
Does this modified environment need to be passed to the launched processes ? (maybe it's not necessary as the same environment is used for the launchfile and each launched process). Otherwise there's an example of custom environment passed to launched processes here:
https://github.com/ros2/system_tests/blob/a4e81e348f7d2b25076f2b11dfde0f073e3850de/test_communication/test/test_publisher_subscriber.py.in#L28-L32
There was a problem hiding this comment.
yeah any children processes will inherit this environment automatically
| @@ -24,6 +25,7 @@ | |||
| from std_msgs.msg import Float32, Header | |||
|
|
|||
| QOS_DEPTH = 10 | |||
| logger = rclpy.logging.get_named_logger('topic_monitor') | |||
There was a problem hiding this comment.
This line fails for me with:
AttributeError: module 'rclpy' has no attribute 'logging'
There was a problem hiding this comment.
sounds like another side effect of ros2/rclpy#147, will fix
There was a problem hiding this comment.
Well, the referenced PR was merged way before this one. So this change hasn't worked when it was merged.
There was a problem hiding this comment.
not trying to play the blame game here, just to understand and document what went wrong. The reason why that PR is relevant is because it broke many demos without us realising (and this PR was tested before that one was opened), and we intend to investigate how to undo the side effects. therefore knowing that this is one of them is important
Connects to ros2/rclpy#148
Requires ros2/rclpy#148