feat: use Rust standard logging.

[Arnaud-de-Grandmaison-ARM]

This commit removes all the "println" that were in the repository to use Rust's standard "log" crate instead (which is maitained by the Rust core team).

All the library / infrastructure parts of the keybroker-demo repository only use the "log::error", "log::warn", "log::info", "log::debug" functions from the logging facade.

The actual executables (keybroker-server, keybroker-app) instantiate and configure an implementation of a logger. The stderrlog implementation is used here as it is simple minimal logger, but https://docs.rs/log/latest/log/ lists many more available logging implementations.

The keybroker-server and keyborker-app do use the same command line options with respect to logging control (verbose / quiet). The verbose switch can be specified multiple times to increase verbosity.

[thomas-fossati]

Looks good.

Just a question. Being a (relative) neophyte in the Rust world, I am ignorant of how the verbosity number maps to the log level. Is this a straight:

Log level	verbosity threshold
Emergency	0
Alert	1
Critical	2
Error	3
Warning	4
Notice	5
Info	6
Debug	7

so that to get the log::info messages I'd need to pass -vvvvvv, or something else?

If the latter, could you please explain the expectations for the CLI caller?

[Arnaud-de-Grandmaison-ARM]

The logging is done thru one of the five macros: error!, warn!, info!, debug! and trace! . The level of filtering is done when instantiating the logger implementation (in the executable, not in the library). The mapping we have in our executables is:

Log level	Verbosity threshold	keybroker-*
Error	0	Enabled by default, unless invoked with -q / --quiet
Warning	1	Enabled by default, unless invoked with -q / --quiet
Info	2	Enabled with -v or --verbose
Debug	3	Enabled with -vv or -v -v or --verbose --verbose
Trace	4	Enabled with -vvv or -v -v -v or ...

If you experiment with it, you'll notice that some of our dependencies are using the log crate as well because we get some of their output in debug or trace mode (e.g. the actix web server):

$ ./target/debug/keybroker-server -v -v -v
INFO starting 11 workers
INFO Actix runtime found; starting in Actix runtime
INFO starting service: "actix-web-service-127.0.0.1:8088", workers: 11, listening on: 127.0.0.1:8088
TRACE starting server worker 0
TRACE registering event source with poller: token=Token(1), interests=READABLE
TRACE starting server worker 1
TRACE service "actix-web-service-127.0.0.1:8088" is available

The one point that may be debatable is that I've enabled the warnings by default. I believe it is a sound default given the purpose of keybroker-demo code base (education). For production code, warnings would probably have to be filtered, but for education and people experimenting, I feel more at ease with providing them with details when something is not quite right (a warning).

[thomas-fossati]

The logging is done thru one of the five macros: error!, warn!, info!, debug! and trace! . The level of filtering is done when instantiating the logger implementation (in the executable, not in the library). The mapping we have in our executables is:
[...]

Thanks for the detailed description. Much appreciated!

If you experiment with it, you'll notice that some of our dependencies are using the log crate as well because we get some of their output in debug or trace mode (e.g. the actix web server):
[...]

Cool - this is a consequence of the first piece of your explanation IIUC.

The one point that may be debatable is that I've enabled the warnings by default. I believe it is a sound default given the purpose of keybroker-demo code base (education). For production code, warnings would probably have to be filtered, but for education and people experimenting, I feel more at ease with providing them with details when something is not quite right (a warning).

👍

[thomas-fossati]

Log level	Verbosity threshold	keybroker-*
Error	0	Enabled by default, unless invoked with -q / --quiet
Warning	1	Enabled by default, unless invoked with -q / --quiet
Info	2	Enabled with -v or --verbose
Debug	3	Enabled with -vv or -v -v or --verbose --verbose
Trace	4	Enabled with -vvv or -v -v -v or ...

Could you add this table to a logging.md file alongside the high-level explanation you provided above? This looks like handy information.

[paulhowardarm]

Could you add this table to a logging.md file alongside the high-level explanation you provided above? This looks like handy information.

Not sure we need a whole separate markdown file for that? It might be better to move towards enhancing the README, which is currently a bit threadbare. Perhaps we need a follow-up PR to add building/running guides to the README, and then we can include the verbosity table as a sub-heading of that?

[Arnaud-de-Grandmaison-ARM]

Aggreed, I was not thrilled by a separate logging.md file. I propose to add sketch sections (building, running and logging) with lightweight content as part of this patch, and some subsequent PR / patch can fill them with more details.

[thomas-fossati]

Aggreed, I was not thrilled by a separate logging.md file. I propose to add sketch sections (building, running and logging) with lightweight content as part of this patch, and some subsequent PR / patch can fill them with more details.

I am ok with all proposals as long as the information captured in #16 (comment) is made permanently visible in the codebase :-)

[thomas-fossati]

LGTM, thanks!

[paulhowardarm]

Looks great, thank you.