Logging

[nburek]

Connects to ros2/rcl#327

Summary

This change is part of a set of changes for new logging features. These changes include the following features:

rcutils

• Slight refactor to the buffer used in logging to make it more generic and reusable
• A new output handler that allows multiple output handlers to be set (default is still only the console output function). This includes the following three output handlers: 1) The console output handler 2) The external logging lib output handler 3) The rosout output handler
• Change to the output format to accept only the log string instead of the format and vargs. The log will be formatted before being sent to the output so that there will be a consistent format across all the outputs
• Added an interface for an external logging library, an output handler function for sending logs to this library, and cmake changes so that the external logging lib can be specified (default is rc_logging_log4cxx)

rcl

• Added new command line parameters for disabling various logging output handlers
• Added new command line parameter for passing in a config file to the external logging library
• Called the new configuration function in the rcutils logging to configure the logging during the ROS init process

rclcpp

• Fixing a broken unit test

rc_logging_log4cxx

• An external logging implementation that uses log4cxx under the hood
• Sets up a default FileAppender logger to forward logs to files
• Uses the process Id as the filename by default

Remaining Feature Work

• The rosout handlers is stubbed out in rcutils right now, but more work will need to be done to actually support sending logs to a rosout topic on a node. This will likely include moving the rosout handler up to rcl so that it can use the node interfaces to publish.

Links

https://discourse.ros.org/t/ros2-logging/6469
https://github.com/nburek/rc_logging_log4cxx

Pull requests for change

rclcpp: ros2/rclcpp#582
rcl: ros2/rcl#327
rcutils: #127

[dirk-thomas]

It would be good to cover the newly added API with tests.

[wjwwood]

I have some high level concerns about the design, that I think we need to work on before I continue the review. In general, these are some red flags for me (code smells):

• rcutils should not need to depend on log4cxx or any third-party logging library
• rcutils should never mention "ROS topics" or "rosout", implementation of a topic based logging output handler should, in my opinion, be completely outside rcutils
• supporting multiple output handlers could be done in rcutils, but could also be done outside of rcutils (unless I'm missing some conceptual issue with that) and I think we should aim for the latter without a decent design reason to do it locally
• I'm not keen on the unmanaged buffer option for the char_array
• I'm slight more ok with the new utility functions in char_array, but most could be replaced with if (size_i_need > char_array.capacity) {resize(char_array, size_i_need);} do_the_thing(char_array, ...);

Much of the logic and code changes look ok, so I think most of these design decision issues, if we decide to go another way, will be largely moving code around.

[wjwwood]

What's the logic behind this change? (sorry if you explained it somewhere else)

[nburek]

I switched to this for two reasons. 1) I wanted to make sure the log message was consistent for every output handler. 2) I wanted to reduce the amount of redundancy in both the runtime execution of formatting logs and in the code. From what I saw, there wasn't an easy way to provide named key replacement during log formatting in libraries such as log4cxx. This would require external libraries written on top of those to either reimplement the code that replaces those keywords or restructure/move the existing code in rcutils that does that formatting/replacement so that it could be used by the external libraries.

[wjwwood]

So I remember now why this is like this. The reason was so that that the output handler being used could decide how to do the formatting, specifically if they wanted to use a fixed sized string for the destination and truncate if too long (avoiding memory allocations) or if they wanted to use dynamic memory and something like snprintf.

For passing to something like log4cxx you can just vsnprintf the format string and arg list into a log string right before passing it to log4cxx. That means redundant code (every output handler needs to do this), but it also means they have control over how the formatting happens.

Given this, I think we should roll back on this specific change. Sorry for being back and forth about it.

[nburek]

I have some high level concerns about the design, that I think we need to work on before I continue the review. In general, these are some red flags for me (code smells):

• rcutils should not need to depend on log4cxx or any third-party logging library

The current direct dependency is due to my misunderstanding of something someone told me. If I fix this then it should only require a group dependency. In the short term you could replace the log4cxx by adding a different external logger lib to the group and setting the environment variable when you build. A later improvement to this would be to make the library selectable at runtime similar to the rmw implementation, but this seemed like an improvement that could come later.

• rcutils should never mention "ROS topics" or "rosout", implementation of a topic based logging output handler should, in my opinion, be completely outside rcutils

Yes, the rosout stuff was in here mostly as a place holder before I had started the feature work for the rosout topic. Now that I've started I can see that the rosout needs to be outside of rcutils. I was looking at moving it up into rcl, but I'm open to other suggestions of where it should live as well.

supporting multiple output handlers could be done in rcutils, but could also be done outside of rcutils (unless I'm missing some conceptual issue with that) and I think we should aim for the latter without a decent design reason to do it locally

I don't have a strong opinion on where the output handlers should live. Adding them to rcutils was a convenient place to start. I'm perfectly happy to move them somewhere else. How would you feel about moving the two new output handlers to the rcl package? I'm open to other suggestions as well.

I'm not keen on the unmanaged buffer option for the char_array

A lot of the functionality of the buffer used in the logging code to format messages seemed to be very close to the functionality needed by char_array, even going beyond to provide useful functionality not currently in the char_array. I'll admit that it does feel like overloading the functionality of char_array to provide the option for a buffer not managed by the char_array but it seemed like a useful way to move a lot of the buffer management code out of logging.c while keeping the functionality of a stack buffer for faster allocation. If you feel like it's a blocking change then I can see a few ways forward:

1. I can move the unmanaged buffer code out of char_array and create a new data structure for it. This will create a lot of duplicate functions, but would leave char_array cleaner for buffer management.
2. We can remove the unmanaged buffer code all together and change logging to just use a buffer on the heap instead of starting with a buffer on the stack.
3. If you think this is a bigger design question that we don't want to try to tackle as part of this pull request then I can try to revert some of these changes to moving the buffer management outside of the logging and we can look at doing it in a separate pull request.

I'm slight more ok with the new utility functions in char_array, but most could be replaced with if (size_i_need > char_array.capacity) {resize(char_array, size_i_need);} do_the_thing(char_array, ...);

Yes, most of the new functions are mostly convenience functions to help clean up the code and abstract away the need for managing the size of your buffer from the business logic in your code.

Much of the logic and code changes look ok, so I think most of these design decision issues, if we decide to go another way, will be largely moving code around.

Thanks for all your feedback. I agree that most of the design concerns you brought up seem like a matter of deciding where things should live and what makes sense for dependencies. I don't have very strong opinions on these, so let me know what specifically you'd like to address your concerns.

[nburek]

I've fixed all of the requested formatting changes and ran ament_uncrustify on the repository. I think it picked up a few files weren't part of my change when it ran the uncrustify, but I included them because I figured they would break the uncrustify test if I reverted them. All unit tests were passing locally when I ran "colcon test" in a Docker Linux image.

I also moved the the rosout, ext_lib, and multiplexing handlers out of rcutils and up to rcl as that is where they were being configured and added as the handler. Let me know if you would prefer for it to live someplace else entirely.

There were several other questions/concerns that I answered in the comment above. Let me know what you still have concerns about after this change.

[dirk-thomas]

I've fixed all of the requested formatting changes and ran ament_uncrustify on the repository. I think it picked up a few files weren't part of my change when it ran the uncrustify, but I included them because I figured they would break the uncrustify test if I reverted them.

This is a bit suspicious since the current master branch passed all linter tests just fine on all targeted platforms in our nightly CI.

[nburek]

I've fixed all of the requested formatting changes and ran ament_uncrustify on the repository. I think it picked up a few files weren't part of my change when it ran the uncrustify, but I included them because I figured they would break the uncrustify test if I reverted them.

This is a bit suspicious since the current master branch passed all linter tests just fine on all targeted platforms in our nightly CI.

I noticed that the automated tests failed here as well due to a linter and uncrustify issue, even though they are all passing for me locally. Maybe I'm running an old version of ament?

[nburek]

I noticed that the automated tests failed here as well due to a linter and uncrustify issue, even though they are all passing for me locally. Maybe I'm running an old version of ament?

I've fixed the linter and uncrustify differences so that they pass the automated test here. Looks like most of the files that ament_uncrustify picked up outside my changes were actually in the rcl package not this one and I've removed those from the change.

[wjwwood]

Sorry for the lag in feedback, I've been trying to get out of the way of one of our crystal milestones and it's been all consuming.

The current direct dependency is due to my misunderstanding of something someone told me. If I fix this then it should only require a group dependency. In the short term you could replace the log4cxx by adding a different external logger lib to the group and setting the environment variable when you build.

That's fine, however, I was expecting this group dependency and a future "hard dependency on the default external logger" to be in rcl not rcutils. I think we're still not on the same page there. I was expecting something this at runtime in rcl:

• rcl_get_default_external_logger() -> finds loggers and returns handle to default
• rcutils_set_external_logger(handle_to_external_logger)

Alternatively, it could be done at compile time, but still it would be figuring out which one in rcl, and then passing the necessary pointers to rcutils for it to use. This can be done at shared library construction to try to ensure as much logging as possible goes to the external one.

In the end, I think what I'm looking for is rcutils not having any direct or indirect dependency on any external logger and instead having the user of rcutils (rcl or rmw_X or whatever) specify the external logger.

Yes, the rosout stuff was in here mostly as a place holder before I had started the feature work for the rosout topic. Now that I've started I can see that the rosout needs to be outside of rcutils. I was looking at moving it up into rcl, but I'm open to other suggestions of where it should live as well.

rcl is the appropriate place I think. This goes back to the idea that rcutils doesn't need the ability to handle multiple output handlers for logging, and instead I was envisioning that rcl would pass a single output handler to rcutils which would dispatch to the original (printf) handler, rosout when available, and the external logger which was setup by rcl itself.

I recognize that the rmw_X implementations use RCUTILS_LOG_* directly and if they do so before rcl sets all this up those messages only go to the default printf output handler provided by rcutils, but I think that's ok personally. We can try to make rcl setup the output handler as soon as possible (shared library constructor or static variable initialization or have rcutils check for a weak linked symbol which rcl could provide and rcutils could call on fist logging).

I don't have a strong opinion on where the output handlers should live. Adding them to rcutils was a convenient place to start. I'm perfectly happy to move them somewhere else. How would you feel about moving the two new output handlers to the rcl package? I'm open to other suggestions as well.

I think that's the right approach in order to keep rcutils light on dependencies.

I can move the unmanaged buffer code out of char_array and create a new data structure for it. This will create a lot of duplicate functions, but would leave char_array cleaner for buffer management.

I like this approach the most, because it feels like to me we're trying to combine the equivalent of std::vector and std::array_view (so I feel that despite the duplication of interfaces keep them separate is perhaps the right thing to do), but I don't want to make that a road block for this work. I think it's ok to leave as-is and create an issue to clean that up in the future (maybe community contribution).

The other reason I'm wary of expanding features of char_array since a lot of them seem to be about treating it like a string object. In which case it might be more appropriate to have a string struct which composes in a char array. Again, not for now, but something to think about.

Yes, most of the new functions are mostly convenience functions to help clean up the code and abstract away the need for managing the size of your buffer from the business logic in your code.

Well we can keep them for now, though I have a slight preference for rcutils_char_array_expand_as_needed(array); mymcpy(array, ...); over rcutils_char_array_memcpy(array, ...), because it makes it more obvious what going on (I have to read the docs of rcutils_char_array_memcpy to know it will resize if needed) and because it reduces the number of functions we have to document, test, and maintain.

---

Again, sorry for holding you up on feedback I'll try to be more responsive in the next few weeks.

[nburek]

Sorry for the lag in feedback, I've been trying to get out of the way of one of our crystal milestones and it's been all consuming.

Not a problem. I've also been a bit slow to respond to the initial feedback due to some unforeseen travel. Hopefully I can stay focused on this now and get it closed out quickly.

The current direct dependency is due to my misunderstanding of something someone told me. If I fix this then it should only require a group dependency. In the short term you could replace the log4cxx by adding a different external logger lib to the group and setting the environment variable when you build.

That's fine, however, I was expecting this group dependency and a future "hard dependency on the default external logger" to be in rcl not rcutils. I think we're still not on the same page there. I was expecting something this at runtime in rcl:

• rcl_get_default_external_logger() -> finds loggers and returns handle to default
• rcutils_set_external_logger(handle_to_external_logger)

Alternatively, it could be done at compile time, but still it would be figuring out which one in rcl, and then passing the necessary pointers to rcutils for it to use. This can be done at shared library construction to try to ensure as much logging as possible goes to the external one.

In the end, I think what I'm looking for is rcutils not having any direct or indirect dependency on any external logger and instead having the user of rcutils (rcl or rmw_X or whatever) specify the external logger.

I think we're converging on the same idea. In the latest update I've moved all the ext_lib dependencies out of rcutils and into rcl. I looked at how the rmw layer is selecting which implementation to use at runtime and decided it would be much faster in the short term to select a single implementation during the build process to link against. The current build process should let you select a different ext_lib implementation by adding it to the group, setting an environment variable, and rebuilding the rcl library. I know it's not ideal, but it let me move a bit faster to try to make the crystal release and I figured this was a feature improvement that could land later with a very easy migration path of just requiring the environment variable to be set at runtime instead of build time. Let me know if you disagree or think this needs to be prioritized.

I can move the unmanaged buffer code out of char_array and create a new data structure for it. This will create a lot of duplicate functions, but would leave char_array cleaner for buffer management.

I like this approach the most, because it feels like to me we're trying to combine the equivalent of std::vector and std::array_view (so I feel that despite the duplication of interfaces keep them separate is perhaps the right thing to do), but I don't want to make that a road block for this work. I think it's ok to leave as-is and create an issue to clean that up in the future (maybe community contribution).

The other reason I'm wary of expanding features of char_array since a lot of them seem to be about treating it like a string object. In which case it might be more appropriate to have a string struct which composes in a char array. Again, not for now, but something to think about.

Alright, we can open this as an issue to migrate this into its own data structure. You're right that it is starting to treat char_array like a a String object and I like the idea of looking to explicitly create a String struct that can use an underlying char_array.

[wjwwood]

The current build process should let you select a different ext_lib implementation by adding it to the group, setting an environment variable, and rebuilding the rcl library.

I think that's perfectly fine, the runtime control of it is purely extra in my opinion.

You're right that it is starting to treat char_array like a a String object and I like the idea of looking to explicitly create a String struct that can use an underlying char_array.

Also, each time we extend these C data structures I feel more and more like wanting to bring in a C library that offers these, like glib or something like that but smaller and leaner. So that might be something for us to consider in the future rather than continuing to build our own wheels :)

Again, for now, just plow ahead as-is.

[nburek]

Rebased on top of master.

[wjwwood]

Honestly, I'm beginning to question the need for most of this pull request. Once you revert the change that the output handlers still take the format string and the va args, and move the multiplexing of the output handler to rcl, the rest of the changes just seem to be refactoring the way the log message is formatted for the default output handler.

I started a pull request to touch up some style issues and undo the formatting occurring before the output handler is called, but once I started to get deeper into it I wasn't sure anymore how this was qualitatively different from the existing code (it may be qualitatively better, but the end result still seems to be just formatting the components into the log message for printing).

I think we should quickly discuss it before merging. Perhaps I've missed something significant in the changes that justifies the code delta.

Either way, I think we can merge most of this pull request, but I want to understand more why the changes to the formatting code were needed.

For a concrete example: there used to be a set of if-else statements which decided how to handle each format token (e.g. converting timestamp into a nano seconds or floating point seconds) and now it's a dispatch system using a structure of function pointers associated with token strings. That might be better, but I guess it seems like a lateral move to me.

[wjwwood]

So I remember now why this is like this. The reason was so that that the output handler being used could decide how to do the formatting, specifically if they wanted to use a fixed sized string for the destination and truncate if too long (avoiding memory allocations) or if they wanted to use dynamic memory and something like snprintf.

For passing to something like log4cxx you can just vsnprintf the format string and arg list into a log string right before passing it to log4cxx. That means redundant code (every output handler needs to do this), but it also means they have control over how the formatting happens.

Given this, I think we should roll back on this specific change. Sorry for being back and forth about it.

[nburek]

Either way, I think we can merge most of this pull request, but I want to understand more why the changes to the formatting code were needed.

The changes to the formatting code were originally done to make the formatter more reusable for other log output functions to format with. When we shifted from passing around the vargs there wasn't really a need for this to be as reusable anymore. We kept these changes in the original PR because we thought they provided a slightly nicer abstraction of buffer management to string formatting that could be reusable elsewhere in the code. If this part of the PR is contentious then I'd rather just remove it at this point.

For a concrete example: there used to be a set of if-else statements which decided how to handle each format token (e.g. converting timestamp into a nano seconds or floating point seconds) and now it's a dispatch system using a structure of function pointers associated with token strings. That might be better, but I guess it seems like a lateral move to me.

Yes, in this case it was probably a lateral move. It is arguably cleaner if you have a large number of tokens you want replaced or want the ability to register tokens outside this file. Since that doesn't seem to be the case it was a refactor that, in retrospect, wasn't needed.

So I remember now why this is like this. The reason was so that that the output handler being used could decide how to do the formatting, specifically if they wanted to use a fixed sized string for the destination and truncate if too long (avoiding memory allocations) or if they wanted to use dynamic memory and something like snprintf.

For passing to something like log4cxx you can just vsnprintf the format string and arg list into a log string right before passing it to log4cxx. That means redundant code (every output handler needs to do this), but it also means they have control over how the formatting happens.

Given this, I think we should roll back on this specific change. Sorry for being back and forth about it.

There are two different formatting operations being applied here. The first is the vargs list that comes from the user's log and the second is the log formatting that's applied on top of it. To me, if these are meant to be modeled as just output sinks on top of the logger system that's implemented in rcutils then it didn't make sense to make every output reformat the user's string, even if it was as simple as calling vsnprintf, because you don't want inconsistencies in the log across different outputs. The second formatting for the log could make sense to be done by the output handler. Other logger systems do provide ways of having different logger formats for different output handlers. However, it didn't seem like the current code had been structured to allow for different formats on different outputs and so it seemed easier to just do it in one place. Additionally, the token replacement that is done with the log formatting is not universal across logging systems and there is additional logic to token replacement beyond what printf does. This is the code I really didn't want to start duplicating in multiple locations.

I do see your point in allowing the user provided implementation to due more of the buffer management. Our disconnect may go back a little bit to the design of the logger interface being provided in rcutils. I was operating under the assumption that the output handlers should just be simple sinks for the logs so that the ROS system could have some control (such as enforcing the same formatting) over the various outputs. This is why I delegated more of the formatting work to the logger functions in rcutils. However, if the functions in rcutils are meant to just be a very simple facade over top of an entirely user provided logging system then, in my opinion, most of the logic currently in this file should be migrated out to its own implementation and this should be pared down to an actual facade that delegates all logging functionality (such as hierarchy management of severity levels) to the provided implementation.

Let me know your thoughts. I'm happy to course correct here for this review, but I'd like to make sure I understand what your vision is for this logging to make sure I'm aligned.

[wjwwood]

Ok, thanks for your feedback.

To be clear I'm ok with the "lateral" code changes, I just wanted to make sure I wasn't missing another reason for them.

---

To me, if these are meant to be modeled as just output sinks on top of the logger system that's implemented in rcutils then it didn't make sense to make every output reformat the user's string, even if it was as simple as calling vsnprintf, because you don't want inconsistencies in the log across different outputs.

I agree with you about having consistent formatting across outputs for the user's log message, however, I think that the variations on how this formatting happens will be only intrinsically different, and that the output will be the same in all cases, except for perhaps truncation which may be unavoidable. For example in all these cases the output would be the same (again excluding truncation) but may be different w.r.t. dynamic memory:

• vsnprintf to see how much is needed, then allocate space, then format with vsnprintf (definitely allocates)
• vsnprintf to a fixed sized output buffer, truncating if needed (may or may not allocate within vsnprintf)
• custom function which emulates vsnprintf but is guaranteed to not allocate memory, used with a fixed sized buffer (should not allocate memory)

That all being said, I think we can leave this as-is (formatting before passing to output handlers). I've been thinking about it more since last night and I think users that want to avoid memory allocation in these cases also want to avoid variadic arguments completely. So they'll probably do something like find-replace all use of variadic arguments and replace them with fixed operand formatting functions, AND then pass them to logging. In which case logging will not need vargs anyways.

The second formatting for the log could make sense to be done by the output handler. Other logger systems do provide ways of having different logger formats for different output handlers. However, it didn't seem like the current code had been structured to allow for different formats on different outputs and so it seemed easier to just do it in one place. Additionally, the token replacement that is done with the log formatting is not universal across logging systems and there is additional logic to token replacement beyond what printf does. This is the code I really didn't want to start duplicating in multiple locations.

I agree with you here that the "output format string" that we allow people to use (via the RCUTILS_CONSOLE_OUTPUT_FORMAT env var) should be respected by all the output handlers where possible. The reason I say this is that in ROS 1, roscpp's output format and rospy's output format were configured differently and it was super annoying.

However, there are cases where applying this formatting first doesn't make sense, like with rosout, which in my opinion should publish all the data related to the log (before formatting the log message according to RCUTILS_CONSOLE_OUTPUT_FORMAT) and then the tool which receives that message can apply formatting in various ways (think about a qt table view or something). For something like log4cxx, I'd love to see that output handler look at RCUTILS_CONSOLE_OUTPUT_FORMAT and come up with equivalent settings for log4cxx, pass those settings and all the logging details to log4cxx, but then let log4cxx actually do the formatting when and where appropriate. I'm not sure that's possible, in which case formatting the string according to RCUTILS_CONSOLE_OUTPUT_FORMAT before giving it to log4cxx (again just as an example) might be the right thing to do.

What I want to get away from is users having to specify something like the RCUTILS_CONSOLE_OUTPUT_FORMAT in multiple places (e.g. ROS 1's roscpp has log4cxx specific configuration arguments and rospy didn't) just to control formatting and logging severity levels. For other things like filtering or controlling multiple logging sinks with something like log4cxx, I think custom configurations are ok.

Put another way, I think it's important to use the same formatting logic and RCUTILS_CONSOLE_OUTPUT_FORMAT when the output sink can only take a single string (e.g. fprintf).

To that end I especially agree with:

This is the code I really didn't want to start duplicating in multiple locations.

So what I was imagining is something where these formatting functions were provided by rcutils and output handlers in rcl used them to do the formatting. And in the cases where doing the formatting first (like perhaps rosout) is not appropriate they simply do not call that function.

This is why I delegated more of the formatting work to the logger functions in rcutils. However, if the functions in rcutils are meant to just be a very simple facade over top of an entirely user provided logging system then, in my opinion, most of the logic currently in this file should be migrated out to its own implementation and this should be pared down to an actual facade that delegates all logging functionality (such as hierarchy management of severity levels) to the provided implementation.

I think that is closer to what I imagined, such that the logging code in rcutils was:

• a single output handler
• provided all the raw information for the logging to the output handler with minimal pre-processing
• provided a default output handler which adhered to the RCUTILS_CONSOLE_OUTPUT_FORMAT
• provide the functions which do the "final" formatting based on RCUTILS_CONSOLE_OUTPUT_FORMAT (and the tokens in it) so other output handlers can be identical to the console output

---

What I think makes sense is this:

• expose formatting functions as public API in rcutils
• have all the default output handlers in rcl call the formatting calls (or just format_log() from this pr) to ensure consistency
• document that output handlers should respect RCUTILS_CONSOLE_OUTPUT_FORMAT where it makes sense, and use the formatting functions in rcutils unless they have specific reason not to do so, in order to have consistency in the log messages

---

Does that sound ok?

I started a pr for this pr which addressed the vargs stuff (which I'll drop now) and some other style stuff, so I finish that up and propose it. But I think we still need to stop formatting the output according to RCUTILS_CONSOLE_OUTPUT_FORMAT before passing to the output handlers (unless I misread the code) and then do that formatting within the output handlers in rcl by calling a function (which is not yet public) from rcutils. So that works needs to be done still, do you have time to do that?

[nburek]

Thanks for the great explanations William. This all sounds good to me. I'll start work immediately to make the formatting functions public, add vargs back to the output handlers, and have each output handler in rcl call the formatting functions provided by rcutils.

[wjwwood]

@nburek I was planning on leaving the vargs out of the output handler signatures actually (leaving it as-is and avoiding some further changes for this pr). Sorry if my comment was confusing.

[wjwwood]

Specifically:

That all being said, I think we can leave this as-is (formatting before passing to output handlers). I've been thinking about it more since last night and I think users that want to avoid memory allocation in these cases also want to avoid variadic arguments completely. So they'll probably do something like find-replace all use of variadic arguments and replace them with fixed operand formatting functions, AND then pass them to logging. In which case logging will not need vargs anyways.

[wjwwood]

Just one item to address, otherwise lgtm.

[wjwwood]

I think we need an else case here where we at least either set the error state or use the SAFE_FWRITE macro or fprintf(stderr, ...) (as appears to be the style in this file) to let someone know that vsprintf failed.

[wjwwood]

Similarly, we should check status and notify someone somehow if status is no OK.

[wjwwood]

lgtm

[wjwwood]

CI (packages up to rcl and testing explicitly rcutils and rcl):

• Linux
• Linux-aarch64
• macOS
• Windows

[wjwwood]

New CI:

• Linux
• Linux-aarch64
• macOS
• Windows

[wjwwood]

One more CI 🤞:

• Linux
• Linux-aarch64
• macOS
• Windows

[wjwwood]

CI after unrelated idl issue was addressed on master:

• Linux
• Linux-aarch64
• macOS
• Windows