# Pre-RFC: Enable logging in tests

**URL:** <https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792>\
**Category:** Uncategorized\
**Created:** [August 22, 2017, 5:09am UTC](https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792 "2017-08-22T05:09:53Z")\
**Posts on this page:** 11\
**Page:** 1

<div class="post-metadata">

**Author:** ![canndrew](https://sea2.discourse-cdn.com/flex002/user_avatar/internals.rust-lang.org/canndrew/32/1676_2.png) [@canndrew](https://internals.rust-lang.org/u/canndrew)\
**Post date:** [August 22, 2017, 5:09am UTC](https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792/1 "2017-08-22T05:09:53Z")

</div>

## 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.

---

<div class="post-metadata">

**Author:** ![Nemo157](https://sea2.discourse-cdn.com/flex002/user_avatar/internals.rust-lang.org/nemo157/32/11585_2.png) [@Nemo157](https://internals.rust-lang.org/u/Nemo157)\
**Post date:** [August 22, 2017, 8:38am UTC](https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792/2 "2017-08-22T08:38:22Z")

</div>

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?

* * *

> [@canndrew](#):
>
> 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.

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.

---

<div class="post-metadata">

**Author:** ![Dushistov](https://sea2.discourse-cdn.com/flex002/user_avatar/internals.rust-lang.org/dushistov/32/4046_2.png) [@Dushistov](https://internals.rust-lang.org/u/Dushistov)\
**Post date:** [August 22, 2017, 9:05am UTC](https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792/3 "2017-08-22T09:05:26Z")

</div>

I suppose this is more general solution:

> <https://github.com/rust-lang/rust/issues/35762>
>
> The details can be found logging while running cargo test.
> The problem is in usage of rust log library,
> to get it work...

---

<div class="post-metadata">

**Author:** ![repax](https://sea2.discourse-cdn.com/flex002/user_avatar/internals.rust-lang.org/repax/32/1342_2.png) [@repax](https://internals.rust-lang.org/u/repax)\
**Post date:** [August 22, 2017, 10:00am UTC](https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792/4 "2017-08-22T10:00:16Z")

</div>

One feature I like about the [Catch testing framework](https://github.com/philsquared/Catch/blob/master/docs/logging.md) 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.

---

<div class="post-metadata">

**Author:** ![Dushistov](https://sea2.discourse-cdn.com/flex002/user_avatar/internals.rust-lang.org/dushistov/32/4046_2.png) [@Dushistov](https://internals.rust-lang.org/u/Dushistov)\
**Post date:** [August 22, 2017, 11:14am UTC](https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792/5 "2017-08-22T11:14:07Z")

</div>

@repax

> [@repax](#):
>
> One feature I like about the Catch testing framework for C++

Your link is broken.

> [@repax](#):
>
> Log messages are buffered locally and only actually sent to stdout or a file if the test fails.

`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?

---

<div class="post-metadata">

**Author:** ![repax](https://sea2.discourse-cdn.com/flex002/user_avatar/internals.rust-lang.org/repax/32/1342_2.png) [@repax](https://internals.rust-lang.org/u/repax)\
**Post date:** [August 22, 2017, 11:18am UTC](https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792/6 "2017-08-22T11:18:42Z")

</div>

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.

---

<div class="post-metadata">

**Author:** ![canndrew](https://sea2.discourse-cdn.com/flex002/user_avatar/internals.rust-lang.org/canndrew/32/1676_2.png) [@canndrew](https://internals.rust-lang.org/u/canndrew)\
**Post date:** [August 22, 2017, 2:03pm UTC](https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792/7 "2017-08-22T14:03:45Z")

</div>

> 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.

---

<div class="post-metadata">

**Author:** ![repax](https://sea2.discourse-cdn.com/flex002/user_avatar/internals.rust-lang.org/repax/32/1342_2.png) [@repax](https://internals.rust-lang.org/u/repax)\
**Post date:** [August 22, 2017, 3:07pm UTC](https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792/8 "2017-08-22T15:07:48Z")

</div>

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.

---

<div class="post-metadata">

**Author:** ![elichai2](https://sea2.discourse-cdn.com/flex002/user_avatar/internals.rust-lang.org/elichai2/32/5205_2.png) [@elichai2](https://internals.rust-lang.org/u/elichai2)\
**Post date:** [February 6, 2019, 10:47am UTC](https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792/9 "2019-02-06T10:47:21Z")

</div>

Hey, was there any progress on this? I too think that the log facade should be integrated in `cargo test` Right now I need to start a simplelogger before each test individually

---

<div class="post-metadata">

**Author:** ![repax](https://sea2.discourse-cdn.com/flex002/user_avatar/internals.rust-lang.org/repax/32/1342_2.png) [@repax](https://internals.rust-lang.org/u/repax)\
**Post date:** [February 6, 2019, 1:57pm UTC](https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792/10 "2019-02-06T13:57:50Z")

</div>

Perhaps the use of the `dbg!` macro could provide sufficient information to understand why a paricular test fails.

---

<div class="post-metadata">

**Author:** ![system](https://sea2.discourse-cdn.com/flex002/user_avatar/internals.rust-lang.org/system/32/14092_2.png) [@system](https://internals.rust-lang.org/u/system)\
**Post date:** [May 7, 2019, 2:08pm UTC](https://internals.rust-lang.org/t/pre-rfc-enable-logging-in-tests/5792/11 "2019-05-07T14:08:55Z")

</div>

Closed on May 7, 2019, 2:08pm UTC

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.
