Pre-RFC: Enable logging in tests


#1

Summary

Enable automatic use of the log crate in tests.

Motivation

Currently, the only way to have err!(), warn!(), info!(), debug!() and trace!() messages print during tests is to start a logger at the start of every test. This is annoying.

Instead, cargo test should automatically start a logger when testing any crate which depends on the log crate. The binary produced by cargo test should collect these log messages, save them to a file, and pretty-print them when a test fails. It should also have command-line options for adjusting the log level.

Detailed design

TBA.

Drawbacks

It makes the log crate special, by giving it special support directly in cargo. However log is already special (by being the de-facto logging facade used throughout the rust ecosystem) and if some alternative logging facade ever becomes popular there’s no reason cargo couldn’t have built-in support for it as well.


#2

Personally I’d prefer to start with a generic setup hook to avoid giving log any real special support. Then once it’s possible to manually hook any logging framework up we could consider making log special by automatically injecting a setup hook for it.

It does introduce more questions than just doing the special case though, how do you define the setup hooks, do we support per-crate and per-module (and all submodules) setup hooks for in-src tests, is there a way to specify a setup hook for all test files in the tests directory or are they all completely independent, what about doc-tests?


I’m not sure why a file would be needed here. It seems like just setting up a log handler that prints to stdout and using the existing stdout redirection would be enough. (Although, I seem to recall that there are issues with that redirection only actually affecting print! instead of all uses of stdout, but I think fixing that is preferable to introducing an alternative way to redirect test output).

The command line options also seem a bit extraneous, using env_logger for the handler lets you adjust the log levels via environment variables and having the same way to do so in tests and with the final binary seems good for introducing new developers to a crate that uses log extensively.


#3

I suppose this is more general solution:


#4

One feature I like about the Catch testing framework for C++ is its logging. Log messages are buffered locally and only actually sent to stdout or a file if the test fails.

In Rust this could be triggered by a panic. Thus a panic handler would be ideal.


#5

@repax

Your link is broken.

cargo test already works in such way, you need cargo test -- --nocapture to get output of “green” test.

Or you mean that it should works not only for stdout/stderr buffering, but also for logging? But you can redirect logs to stdout/stderr during tests and reuse already existing functionality?


#6

Sorry. Fixed the link.

The logging messages are ignored if the test succeeds (so as to not pollute stdout/logfiles). The idea is that the test can log interesting debug properties that are only of interest if the test fails.


#7

The logging messages are ignored if the test succeeds (so as to not pollute stdout/logfiles). The idea is that the test can log interesting debug properties that are only of interest if the test fails.

It would be possible to do this sort of thing aswell, if the logger implementation was provided by cargo rather than just using env_logger. It’s more flexible than just forwarding everything to stdout.


#8

Yeah, and I think that the motivation for your pre-RFC touches on a very useful idea, worth discussing. I’m unsure what crate if any should be endorsed. So, we could try to enumerate the minimum set of features required to see what logging framework best fits the needs.