Experimenting with spdlog

[mjcarroll]

No description provided.

[j-rivero]

Unsure if the comment is out of the scope of this work, please ignore it if it is.

The current implementation seems to support different "sinks" (destinations for the logging) in the sense that I can see the fileSink and consoleSink in the implementation of the ConsoleNew::Implementation. Even if the class naming and file naming is a bit confuse since we use "Console" all over the place.

I think that supported this variety of "sinks" is really a great approach so we can extend the logging capabilities in the future. Concretely I'm looking into experimenting with OpenTelemetry for the whole Gazebo and one of the options that this spdlog support can provide is the use of an "OpenTelemetry sink". The creation of it seems trivial if we can support multiple sinks somehow:

#include <opentelemetry/instrumentation/spdlog/sink.h>

auto otel_sink = std::make_shared<spdlog::sinks::opentelemetry_sink_mt>();
otel_sink->set_level(spdlog::level::info);
auto logger = spdlog::logger("OTelLogger", otel_sink);

[mjcarroll]

The current implementation seems to support different "sinks" (destinations for the logging) in the sense that I can see the fileSink and consoleSink in the implementation of the ConsoleNew::Implementation. Even if the class naming and file naming is a bit confuse since we use "Console" all over the place.

That is correct. I used ConsoleNew to keep the name and behavior consistent with the current Console behavior. The current Console also sinks to file and stdout/stderr console streams.

In this implementation, I wanted to make sure that we can surface the underlying spdlog mechanisms so you could (for instance) add an OpenTelemetry sink to Console.

[azeey]

Would it make sense to move this into gz-utils? We have an implementation of Console in sdformat which could be replaced with this. I was also working on gazebosim/gz-math#613 which needs to enforce an invariant. Since we don't use exceptions, this will probably resort to printing an error message, which we do in many places in gz-math. It would be nice if we had proper logging there as well.

[azeey]

@mjcarroll and I discussed putting a lightweight wrapper around spdlog in gz-utils which would allow us to use it in libraries such as gz-math or sdformat. We would still have the higher level API, aka common::Console here which will have more functionality. This would provide a way for downstream applications like gz-sim capture and redirect console output from gz-math or sdformat and display them however they want.

[codecov]

Codecov Report

Attention: Patch coverage is 84.12698% with 10 lines in your changes missing coverage. Please review.

Project coverage is 84.92%. Comparing base (316ea33) to head (0b479c3).
Report is 8 commits behind head on main.

Files	Patch %	Lines
src/Console.cc	84.12%	10 Missing ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##             main     #615      +/-   ##
==========================================
+ Coverage   80.54%   84.92%   +4.38%     
==========================================
  Files          80       78       -2     
  Lines       13588    10094    -3494     
==========================================
- Hits        10944     8572    -2372     
+ Misses       2644     1522    -1122     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[iche033]

update migration guide?

[iche033]

I tested this with gz-sim's main branch and I noticed a couple of issues.

1. This first one is minor - there are now empty lines between console log entries

[2024-08-26 21:48:33.501] [gz] [info] [SceneBroadcaster.cc:634] Serving scene information on [/world/shapes/scene/info]

[2024-08-26 21:48:33.502] [gz] [info] [SceneBroadcaster.cc:643] Serving graph information on [/world/shapes/scene/graph]

[2024-08-26 21:48:33.502] [gz] [info] [SceneBroadcaster.cc:654] Serving full state on [/world/shapes/state]

2. I get a crash if I try to close the GUI window:

terminate called after throwing an instance of 'std::system_error'
...
...
#13   Object "/lib/x86_64-linux-gnu/libspdlog.so.1.12", at 0x7fa4dfdb3400, in spdlog::details::registry::~registry()
#12   Object "/lib/x86_64-linux-gnu/libspdlog.so.1.12", at 0x7fa4dfde771b, in spdlog::details::periodic_worker::~periodic_worker()

[caguero]

update migration guide?

Updated in 27633b7

[azeey]

Is this a behavior change on the formatting of the logs? Should this be included in the migration guide?

[iche033]

Added gz-utils3-log / spdlog dependency to:

• homebrew: gz-common6: depend on spdlog osrf/homebrew-simulation#2747
• gz-common6-release: Add libutils3-log-dev and libspdlog-dev dependencies gazebo-release/gz-common6-release#5

windows has spdlog dependency already (gazebo-tooling/release-tools#1163)

[caguero]

I tested this with gz-sim's main branch and I noticed a couple of issues.

1. This first one is minor - there are now empty lines between console log entries

[2024-08-26 21:48:33.501] [gz] [info] [SceneBroadcaster.cc:634] Serving scene information on [/world/shapes/scene/info]

[2024-08-26 21:48:33.502] [gz] [info] [SceneBroadcaster.cc:643] Serving graph information on [/world/shapes/scene/graph]

[2024-08-26 21:48:33.502] [gz] [info] [SceneBroadcaster.cc:654] Serving full state on [/world/shapes/state]

2. I get a crash if I try to close the GUI window:

terminate called after throwing an instance of 'std::system_error'
...
...
#13   Object "/lib/x86_64-linux-gnu/libspdlog.so.1.12", at 0x7fa4dfdb3400, in spdlog::details::registry::~registry()
#12   Object "/lib/x86_64-linux-gnu/libspdlog.so.1.12", at 0x7fa4dfde771b, in spdlog::details::periodic_worker::~periodic_worker()

Could you try with this PR? gazebosim/gz-utils#139

I think we should use a period flush for efficiency but we might be doing something wrong and I suspect it's related with the use of static. This could be a workaround until we learn more about the issue.

[iche033]

Could you try with this PR? gazebosim/gz-utils#139

tested and confirmed it fixes the issues.

[caguero]

@Mergifyio backport gz-common6

[mergify]

backport gz-common6

✅ Backports have been created

• #628 Experimenting with spdlog (backport #615) has been created for branch gz-common6