If you are new to Rust programming language, there is a chance you are experiencing a deep learning curve in understanding how the programming language works. On top of that, you start writing your first couple of unit tests and suddenly realize that the logs from using the print or println! macro are not displayed in the terminal.
To fix println! not showing logs when running succesful unit tests, pass the --show-ouput flag at the moment of executing the command to run tests cargo test. Hence, the new command to run tests and display logs generated from using the println macro is cargo test -- --show-output.
cargo test -- --show-output
Let’s look at the following example. We have a simple display_text function that only displays a log of a &str using println!, and returns a &"Text displayed".
fn main() {
display_text("Hello World!");
}
fn display_text(text: &str) -> &str {
println!("Displaying Text {0}", text);
&"Text displayed"
}
#[cfg(test)]
mod test {
use super::*;
#[test]
fn test_display_text() {
println!("Running test on display_text function");
assert_eq!(display_text("Hello!"), "Text displayed")
}
}Notice there is a test to test the display_text function that checks whether the returned &str is “Text displayed”.
Running the standard cargo test command will give us the following result.
$ cargo test
Finished test [unoptimized + debuginfo] target(s) in 0.23s
Running unittests (target\debug\deps\rust_playground-afbcb92314fac06b.exe)
running 1 test
test test::test_display_text ... ok
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.06sNotice the logs that should have been generated from println!("Displaying Text {0}", text); and println!("Running test on display_text function"); are not visible. Luckily, now that we know about the --show-output flag, we can get the outputs in the terminal similar to the following:
$ cargo test -- --show-output
Finished test [unoptimized + debuginfo] target(s) in 0.24s
Running unittests (target\debug\deps\rust_playground-afbcb92314fac06b.exe)
running 1 test
test test::test_display_text ... ok
successes:
---- test::test_display_text stdout ----
Running test on display_text function
Displaying Text Hello!
successes:
test::test_display_text
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.06sTable of Contents
Another way to discover the --show-output flag
If this is not your first time seeing the --show-output flag, there is a probability you discovered it by using the --helpcommand to find out about all the different options available when running tests.
Hence, if you run cargo test -- --help, the terminal will display all the options.
Options:
--include-ignored
Run ignored and not ignored tests
--ignored Run only ignored tests
--force-run-in-process
Forces tests to run in-process when panic=abort
--exclude-should-panic
Excludes tests marked as should_panic
--test Run tests and not benchmarks
--bench Run benchmarks instead of tests
--list List all tests and benchmarks
-h, --help Display this message
--logfile PATH Write logs to the specified file
--nocapture don't capture stdout/stderr of each task, allow
printing directly
--test-threads n_threads
Number of threads used for running tests in parallel
--skip FILTER Skip tests whose names contain FILTER (this flag can
be used multiple times)
-q, --quiet Display one character per test instead of one line.
Alias to --format=terse
--exact Exactly match filters rather than by substring
--color auto|always|never
Configure coloring of output:
auto = colorize if stdout is a tty and tests are run
on serially (default);
always = always colorize output;
never = never colorize output;
--format pretty|terse|json|junit
Configure formatting of output:
pretty = Print verbose output;
terse = Display one character per test;
json = Output a json document;
junit = Output a JUnit document
--show-output Show captured stdout of successful tests
-Z unstable-options Enable nightly-only flags:
unstable-options = Allow use of experimental features
--report-time [plain|colored]
Show execution time of each test. Available values:
plain = do not colorize the execution time (default);
colored = colorize output according to the `color`
parameter value;
Threshold values for colorized output can be
configured via
`RUST_TEST_TIME_UNIT`, `RUST_TEST_TIME_INTEGRATION`
and
`RUST_TEST_TIME_DOCTEST` environment variables.
Expected format of environment variable is
`VARIABLE=WARN_TIME,CRITICAL_TIME`.
Durations must be specified in milliseconds, e.g.
`500,2000` means that the warn time
is 0.5 seconds, and the critical time is 2 seconds.
Not available for --format=terse
--ensure-time Treat excess of the test execution time limit as
error.
Threshold values for this option can be configured via
`RUST_TEST_TIME_UNIT`, `RUST_TEST_TIME_INTEGRATION`
and
`RUST_TEST_TIME_DOCTEST` environment variables.
Expected format of environment variable is
`VARIABLE=WARN_TIME,CRITICAL_TIME`.
`CRITICAL_TIME` here means the limit that should not
be exceeded by test.
--shuffle Run tests in random order
--shuffle-seed SEED
Run tests in random order; seed the random number
generator with SEEDNotice option --show-output says Show captured stdout of successful tests. In other words, show logs in the terminal from executing succesful tests.
Why does Rust not show the output by default when executing successful unit tests?
While there isn’t an official statement from the Rust team, it is said among the community of Rust developers that Rust hides the logs generated when running unit tests to keep the final output clean to easily identify successful tests.
This can be new for programmers coming from a different background such as JavaScript where no matter whether you are running a test, logging using console.log displays the output in the terminal without the need of passing a flag like --show-output in Rust.
Failing tests display the logs from println! macro by default
If you haven’t noticed by now, we have been saying logs from println! macro doesn’t show by default when executing succesful tests. However, this is not the case when executing failing tests.
If we add a test we know will fail such as the following
#[cfg(test)]
mod test {
use super::*;
#[test]
fn gtest_display_text() {
println!("BAD");
assert_eq!(display_text("Hello!"), "FAILING!")
}
}and run cargo test you will see the log “BAD” is displayed in the terminal.
$ cargo test
Compiling rust_playground v0.1.0 (C:\Users\andry\Repos\blog-articles\rust_playground)
Finished test [unoptimized + debuginfo] target(s) in 0.99s
Running unittests (target\debug\deps\rust_playground-afbcb92314fac06b.exe)
running 1 test
test test::gtest_display_text ... FAILED
failures:
---- test::gtest_display_text stdout ----
BAD
Displaying Text Hello!
thread 'test::gtest_display_text' panicked at 'assertion failed: `(left == right)`
left: `"Text displayed"`,
right: `"FAILING!"`', src\main.rs:20:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
failures:
test::gtest_display_text
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.06s
error: test failed, to rerun pass '--bin rust_playground'This was confirmed by Mara Bos who is part of the Rust team at the moment of writing this article.
