#[logfn]Expand description
Provide an proc_macro #[logfn] which log the function call begin and return,
with argument list and return value.
§Examples
use captains_log::{recipe, logfn};
use log::*;
let builder = recipe::raw_file_logger("/tmp", "log_test", log::Level::Debug).test();
builder.build().expect("setup_log");
// default log level to be info
#[logfn]
fn foo() {
info!("foo");
bar(1, "bar arg");
}
// you can change log level to warn
#[logfn(warn)]
fn bar(a: i32, s: &str) {
info!("bar");
}
foo();/tmp/log_test.log will have this content:
[2025-06-21 01:00:17.116049][INFO][test_logfn.rs:13] <<< foo () enter <<<
[2025-06-21 01:00:17.116206][INFO][test_logfn.rs:15] foo
[2025-06-21 01:00:17.116223][WARN][test_logfn.rs:19] <<< bar (a = 1, s = "bar arg") enter <<<
[2025-06-21 01:00:17.116236][INFO][test_logfn.rs:21] bar
[2025-06-21 01:00:17.116246][WARN][test_logfn.rs:19] >>> bar return () >>>
[2025-06-21 01:00:17.116256][INFO][test_logfn.rs:13] >>> foo return () >>>§Best practice with test suit
Nice to have #[logfn] used with retest.
-
When you have large test suit, you want to know which logs belong to which test case.
-
Sometimes your test crashes, you want to find the resposible test case.
use rstest::*;
use log::*;
use captains_log::*;
// A show case that setup() fixture will be called twice, before each test.
// In order make logs available.
#[logfn]
#[fixture]
fn setup() {
let builder = recipe::raw_file_logger("/tmp", "log_rstest", log::Level::Debug).test();
builder.build().expect("setup_log");
}
#[logfn]
#[rstest(file_size, case(0), case(1))]
fn test_rstest_foo(setup: (), file_size: usize) {
info!("do something111");
}
#[logfn]
#[rstest]
fn test_rstest_bar(setup: ()) {
info!("do something222");
}
After running the test with:
cargo test -- --test-threads=1
/tmp/log_rstest.log will have this content:
[2025-06-21 00:39:37.091326][INFO][test_rstest.rs:11] >>> setup return () >>>
[2025-06-21 00:39:37.091462][INFO][test_rstest.rs:27] <<< test_rstest_bar (setup = ()) enter <<<
[2025-06-21 00:39:37.091493][INFO][test_rstest.rs:30] do something222
[2025-06-21 00:39:37.091515][INFO][test_rstest.rs:27] >>> test_rstest_bar return () >>>
[2025-06-21 00:39:37.091719][INFO][test_rstest.rs:11] <<< setup () enter <<<
[2025-06-21 00:39:37.091826][INFO][test_rstest.rs:11] >>> setup return () >>>
[2025-06-21 00:39:37.091844][INFO][test_rstest.rs:21] <<< test_rstest_foo (setup = (), file_size = 0) enter <<<
[2025-06-21 00:39:37.091857][INFO][test_rstest.rs:24] do something111
[2025-06-21 00:39:37.091868][INFO][test_rstest.rs:21] >>> test_rstest_foo return () >>>
[2025-06-21 00:39:37.092063][INFO][test_rstest.rs:11] <<< setup () enter <<<
[2025-06-21 00:39:37.092136][INFO][test_rstest.rs:11] >>> setup return () >>>
[2025-06-21 00:39:37.092151][INFO][test_rstest.rs:21] <<< test_rstest_foo (setup = (), file_size = 1) enter <<<
[2025-06-21 00:39:37.092163][INFO][test_rstest.rs:24] do something111
[2025-06-21 00:39:37.092173][INFO][test_rstest.rs:21] >>> test_rstest_foo return () >>>