Implement a backend logger using spdlog.

[clalancette]

Along with ros2/rcutils#166 and ros2/rcl#466, this PR is one way we could implement per-process logging in ROS 2. It uses a header-only C++ library called spdlog instead of log4cxx (which has a bunch of problems). I'm not at all tied to using this library, but it is relatively straightforward and has most of the features we want. The open questions with this PR (in rough order of priority):

1. Is spdlog good enough for our purposes? It supports all of the features of log4cxx that we were using, with the exception of external configuration. It just doesn't have a way to be configured from a file. We could define something, we could ignore the feature, or we could find another C++ logging library that has that feature.
2. When running a simple executable with this in place (ros2 run demo_nodes_cpp talker), you get 2 things in ~/.ros/log; a directory of <date>-<hostname>-<pid>, and a log file of <processname>-<pid>-<ms-since-epoch>. This PR creates the latter; I'm not sure where the former is coming from. We should figure out our strategy here and only make one of them show up.
3. Assuming we want to use spdlog, how do we want to vendor it? Here I've copied it into the repository with a LICENSE file (and made the license of the package match), but we could also ExternalProject it or do spdlog_vendor package separately.
4. Needs to be tested with Windows, macOS, etc. I'll hold off on this until the points above are addressed.

@ros2/team @nburek FYI.

[jacobperron]

Regarding question 3, can we use package managers for installation:

• apt (Linux)
• brew (macOS)
• nuget (Windows) ?

Although, I guess it's possible to run into issues due to different versions.

[artivis]

From spdlog's readme, the supported platforms are,

• Linux, FreeBSD, OpenBSD, Solaris, AIX
• Windows (msvc 2013+, cygwin)
• macOS (clang 3.5+)
• Android

while the package managers are,

• Homebrew: brew install spdlog
• FreeBSD: cd /usr/ports/devel/spdlog/ && make install clean
• Fedora: yum install spdlog
• Gentoo: emerge dev-libs/spdlog
• Arch Linux: yaourt -S spdlog-git
• vcpkg: vcpkg install spdlog

I did encounter versioning issues a while back with spdlog, hopefully this was smoothed.

[fujitatomoya]

I'd like to hear what everyone thinks as following questions,

• sustainability and maintenance.
  need to re-build rcl_logging_spdlog every single time if any fix available on spdlog?
• log directory, should be configurable for each process? (or system?)
  with specific and particular situation for debugging, we some time to ramfs.
• from spdlog implementation, always use mutex_lock to exclude logger access.
  i believe that nobody like to use the CPU consumption for system but user space.
  there could be buffer to enhance using user space instruction to exclude the access for logger with multi-thread. (example, 1st tries to lock with CAS instruction to exclude the access)

[nburek]

My opinions for your question, @clalancette

1. Yes, I think that spdlog is good enough for our initial purposes. I did some looking around before selecting Log4cxx initially and hadn't discovered any other logging libraries I think are better to continue with than spdlog.
   I also think it's fine to ignore the configuration file input for now. I don't think we need to solve every use case for logging right off the bat, but it would be great just to have something working that dumps logs to file with some sane default settings. That's a big missing feature right now with the dashing release since the log4cxx issues prevented us from getting that enabled by default. Let's let the community drive what additional features they want from logging and then we can explore if we're better off adding a simple config file parser on top of spdlog or if we need to search for a different logger.
2. I think this second folder in the logs is coming from the ros2/launch system. See: https://github.com/ros2/launch/blob/f1dc16de491864fc2c2a881040003a5f4b1bf8b2/launch/launch/logging/__init__.py#L367-L385. Agreed we should standardize.
3. Having a copy in the repo was fine for testing that it works, but I don't think it makes sense for that to be the long term solution. For log4cxx we tried used apt, brew, and Chocolatey. The apt and brew repos were already available, but creating the chocolatey package was a real pain and I wouldn't recommend it as a solution for Windows. I personally don't have a strong preference as to how it's vended separately though, so I would defer to others.

[clalancette]

* sustainability and maintenance.
  need to re-build rcl_logging_spdlog every single time if any fix available on [spdlog](https://github.com/gabime/spdlog)?

Yeah, that will be a problem with vendoring (either here in this package, or in a vendor package). So if we can (and as pointed out by others), it would be better to use packages and offload that work elsewhere.

* log directory, should be configurable for each process? (or system?)
  with specific and particular situation for debugging, we some time to ramfs.

Yeah, that's a good point. That is one reason to support the external configuration file, but on the the other hand, we can just add a new environment variable for that. I'll put it on the list to do.

* from [spdlog](https://github.com/gabime/spdlog) implementation, always use mutex_lock to exclude logger access.
  i believe that nobody like to use the CPU consumption for system but user space.
  there could be buffer to enhance using user space instruction to exclude the access for logger with multi-thread. (example, 1st tries to lock with CAS instruction to exclude the access)

I'm not going to worry too much about this unless/until someone comes up with a realistic scenario where this is a problem. If it does turn out to be a problem, then we can either enhance spdlog upstream, or switch to yet another logging implementation.

Thanks for the feedback!

[clalancette]

1. Yes, I think that spdlog is good enough for our initial purposes. I did some looking around before selecting Log4cxx initially and hadn't discovered any other logging libraries I think are better to continue with than spdlog.
   I also think it's fine to ignore the configuration file input for now. I don't think we need to solve every use case for logging right off the bat, but it would be great just to have something working that dumps logs to file with some sane default settings. That's a big missing feature right now with the dashing release since the log4cxx issues prevented us from getting that enabled by default. Let's let the community drive what additional features they want from logging and then we can explore if we're better off adding a simple config file parser on top of spdlog or if we need to search for a different logger.

OK, that was my feeling as well. I just wanted to make sure there wasn't some critical use case I was missing.

2. I think this second folder in the logs is coming from the ros2/launch system. See: https://github.com/ros2/launch/blob/f1dc16de491864fc2c2a881040003a5f4b1bf8b2/launch/launch/logging/__init__.py#L367-L385. Agreed we should standardize.

What confused me was that I wasn't using the launch system. That directory is showing up even when I just do ros2 run demo_nodes_cpp talker with this spdlog implementation enabled. Maybe somehow ros2 run re-uses some of that code? Not sure.

3. Having a copy in the repo was fine for testing that it works, but I don't think it makes sense for that to be the long term solution. For log4cxx we tried used apt, brew, and Chocolatey. The apt and brew repos were already available, but creating the chocolatey package was a real pain and I wouldn't recommend it as a solution for Windows. I personally don't have a strong preference as to how it's vended separately though, so I would defer to others.

OK, I think it is clear that we want to use separate packages. It seems to already be packaged for Ubuntu, and available via Brew for macOS, so that's a good start. I'll leave it to @nuclearsandwich and @mjcarroll to give any feedback about chocolatey packaging (or whatever) for Windows.

[fujitatomoya]

@clalancette

What confused me was that I wasn't using the launch system. That directory is showing up even when I just do ros2 run demo_nodes_cpp talker with this spdlog implementation enabled. Maybe somehow ros2 run re-uses some of that code? Not sure.

this is done by luanch.logging, ros2cli imports logging,

https://github.com/ros2/launch/blob/40c9d879ae01b7c689438461338458b8173e535a/launch/launch/logging/__init__.py#L402-L404

[nuclearsandwich]

3\. Having a copy in the repo was fine for testing that it works, but I don't think it makes sense for that to be the long term solution. For log4cxx we tried used apt, brew, and Chocolatey. The apt and brew repos were already available, but creating the chocolatey package was a real pain and I wouldn't recommend it as a solution for Windows. I personally don't have a strong preference as to how it's vended separately though, so I would defer to others.

log4cxx definitely set a new worst case bar for Chocolatey packaging.
spdlog has a few advantages that log4cxx didn't.

1. It's a header-only library which makes packaging much easier.
2. Unlike log4cxx a spdlog package already exists for vcpkg. Our CI workflow isn't compatible with vcpkg directly but there's some work in progress that may make extracting chocolatey packages from vpkg possible. [feature] add vcpkg export --x-chocolatey support microsoft/vcpkg#6891 Testing with spdlog may provide some good practical feedback for that effort.

[nuclearsandwich]

@clalancette it wasn't immediately clear which version of spdlog is vendored here. Ubuntu bionic packages 0.16 but the current version in Homebrew is 1.3.1.

[clalancette]

This is still on my list to come back and look at for Eloquent, but I haven't had time for it yet. Probably September.

[clalancette]

The current status on this is the following:

1. I think we've come to broad agreement that spdlog is an OK implementation for now. It is missing the ability to externally configure via a file, but that is not a major limitation and we can add it in the future (or switch to a different backend).
2. The next step is to figure out how we are going to vendor or package spdlog on the various platforms. I'll point out that spdlog is header-only, which may or may not make things easier. Here's what I know about what's available on the platforms that Eloquent is going to support:
   • Ubuntu 18.04 - libspdlog-dev 0.16
   • Debian Buster - libspdlog-dev 1.3.1
   • macOS/brew - spdlog 1.3.1
   • Windows/choco - Not available
3. Once the vendoring is figured out, we then need to address review comments on Implement rcutils_mkdir. rcutils#166 , fix this PR up to use the newly-vendored code, and get these 3 PRs reviewed and merged:
   • Implement rcutils_mkdir. rcutils#166
   • Implement a backend logger using spdlog. #17
   • Switch the default logging implementation to spdlog. rcl#466

@tfoote FYI

[clalancette]

Looking at the above list of platforms, I think it is broadly clear that we want to use spdlog 1.3.1, as that will get us compatibility on Buster and macOS/brew out-of-the-box. For Ubuntu Bionic and Windows, then, I think we should probably vendor it like we do in https://github.com/ros2/console_bridge_vendor/blob/master/CMakeLists.txt . Essentially, if we find spdlog 1.3.1 on the system, use that, otherwise vendor it ourselves. I'm going to start working on that.

[clalancette]

CI is definitely going to fail here because it needs the whole set of things in ros2/ros2#789 in order to succeed.

[clalancette]

Thanks for the initial review! All review comments have been addressed in b32968f. Please take another look when you have a chance.

[jacobperron]

Ultimately, it looks like we might want to define a common logging API so that the backend can be easily changed. But I'm okay with this PR as-is, if we want to leave that as a follow-up task.

It would be nice to add linter tests.

Some more minor comments below.

[clalancette]

Ultimately, it looks like we might want to define a common logging API so that the backend can be easily changed. But I'm okay with this PR as-is, if we want to leave that as a follow-up task.

So there actually is one that they all conform to: https://github.com/ros2/rcl/blob/d655147310e3e63aff1555ad40fca1bb9cb7783e/rcl/include/rcl/logging_external_interface.h . It's a little hard to find it, though, because of the way this whole thing was done. I honestly don't remember all of the details at the moment, but it definitely could be improved so that they use more common stuff.

[clalancette]

All review comments are addressed in e268e69. I've also added the linters and fixed things up there.

[jacobperron]

LGTM

[nuclearsandwich]

The Epr job won't work until spdlog_vendor is released into eloquent. I think it would be nice if we got the PR job passing before merging this.

[clalancette]

@ros-pull-request-builder retest this please

[clalancette]

@ros-pull-request-builder retest this please

[clalancette]

Woohoo, PR testing succeeded. Merging now.

[pwm1234]

1. Is spdlog good enough for our purposes? It supports all of the features of log4cxx that we were using, with the exception of external configuration. It just doesn't have a way to be configured from a file. We could define something, we could ignore the feature, or we could find another C++ logging library that has that feature.

@clalancette For reference https://github.com/guangie88/spdlog_setup is a reasonable place to start when it comes to configuring spdlog from a file. I have used it on a few small projects and have been pleased.

[maxlein]

Is there somewhere a hint or manual on how to switch to spdlog?
I asked this in ros answers few months ago but didn‘t get an answer.

[nburek]

@maxlein
I believe that as of the Eloquent release spdlog is now the default logger, someone correct me if I'm wrong. If you're on a previous version, you will need to build rcl_logging_spdlog into your workspace (if it isn't already available) and then you will need to rebuild rcl while linking in rcl_logging_spdlog as the logger you want. You can do this by either copying the changes from here to set it as the default logger or by setting the environment variable RCL_LOGGING_IMPLEMENTATION=rcl_logging_spdlog during the build so that the make files pick it up (see here)

[clalancette]

That's correct; in Eloquent and later, spdlog is now the default.

[maxlein]

Thanks, I am on eloquent.
So to check, I will look at the env var.