diff --git a/example/setup_test.go b/example/setup_test.go index 09403075..5907e3a3 100644 --- a/example/setup_test.go +++ b/example/setup_test.go @@ -18,12 +18,35 @@ func BenchmarkLargeSetup(b *testing.B) { func BenchmarkLargeSetupInLoop(b *testing.B) { var result uint64 + + // The `testing` package starts the timer automatically at the beginning of the benchmark. If we try to + // stop the timer before the expensiveOperation, and then start it again afterwards we'll run into an issue + // where the difference from the function start to the first b.StopTimer() call is included in the timing. + // ``` + // for i := 0; i < b.N; i++ { + // b.StopTimer() + // expensiveOperation() + // b.StartTimer() + // b.Log("Running iteration", i, b.Elapsed()) + // + // result = actualWork() + // b.Log("Running iteration", i, b.Elapsed()) + // } + // ``` + // This will print two timings: + // setup_test.go:26: Running iteration 0 782ns + // setup_test.go:29: Running iteration 0 7.560911ms + // + // However, the first timing (782ns) is misleading because it's not related to the benchmark. To avoid this, we have to + // stop the timer in the beginning of the benchmark function. + b.StopTimer() + b.ResetTimer() for i := 0; i < b.N; i++ { - b.StopTimer() expensiveOperation() - b.StartTimer() + b.StartTimer() result = actualWork() + b.StopTimer() } runtime.KeepAlive(result) } diff --git a/go-runner/src/main.rs b/go-runner/src/main.rs index af958f2f..88afd2c4 100644 --- a/go-runner/src/main.rs +++ b/go-runner/src/main.rs @@ -4,7 +4,8 @@ use std::path::Path; fn main() -> anyhow::Result<()> { env_logger::builder() .parse_env(env_logger::Env::new().filter_or("CODSPEED_LOG", "info")) - .filter_module("handlebars", log::LevelFilter::Off) + .filter_module("handlebars", log::LevelFilter::Warn) + .filter_module("dircpy", log::LevelFilter::Warn) .format_timestamp(None) .init();