ReadmeDoctests test flaky in fresh repo

Open chkno opened this issue 2 years ago • 0 comments

The ReadmeDoctests tests introduced in #37 sometimes fail non-deterministically.

For example, I ran cargo test 100 times and it failed 12 times. ... But then I ran it a thousand more times and never saw it fail again. But then I made a fresh clone of the this repo, ran cargo test 100 times, and saw it fail 22 times!

So it somehow seems to be related to running tests from a fresh repo?

The first failure's error message says something about AlreadyExists and all later error messages are about CorruptLog:

First run of cargo test after fresh clone:

...
running 51 tests
...
test result: ok. 51 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.11s

   Doc-tests commitlog

running 2 tests
test src/lib.rs - (line 18) ... ok
test src/lib.rs - ReadmeDoctests (line 1244) ... FAILED

failures:

---- src/lib.rs - ReadmeDoctests (line 1244) stdout ----
Test executable failed (exit status: 101).

stderr:
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Os { code: 17, kind: AlreadyExists, message: "File exists" }', src/lib.rs:9:40
stack backtrace:
   0:     0x55c50288126c - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::hf2ea00d5f3b53d9f
   1:     0x55c5028aaefe - core::fmt::write::ha076a7e65c6b1874
   2:     0x55c50288e551 - std::io::Write::write_fmt::h9630bb3b0fe886f5
   3:     0x55c502895325 - std::panicking::default_hook::{{closure}}::h64163197f96398c1
   4:     0x55c502894f82 - std::panicking::default_hook::h92625161492e6b48
   5:     0x55c502895841 - std::panicking::rust_panic_with_hook::hfdd7d6bb6788c6c2
   6:     0x55c5028815a7 - std::panicking::begin_panic_handler::{{closure}}::he81a60a7ef84ad4a
   7:     0x55c502881384 - std::sys_common::backtrace::__rust_end_short_backtrace::h62801bf9780239e6
   8:     0x55c5028954f2 - rust_begin_unwind
   9:     0x55c502813783 - core::panicking::panic_fmt::hfd221b9f37504b4a
  10:     0x55c502813813 - core::result::unwrap_failed::h7a3045feac200afb
  11:     0x55c502814c5a - core::result::Result<T,E>::unwrap::hb5c78b479aba5702
  12:     0x55c50281747c - rust_out::main::h7cf9d0438004d406
  13:     0x55c502814283 - core::ops::function::FnOnce::call_once::h3166193039ac9aa5
  14:     0x55c502813df9 - std::sys_common::backtrace::__rust_begin_short_backtrace::h4035ab9eaf427f7b
  15:     0x55c502813e69 - std::rt::lang_start::{{closure}}::h61c7438f2ca2ee26
  16:     0x55c502888295 - std::rt::lang_start_internal::h09bcc9fffd987f14
  17:     0x55c502813e51 - std::rt::lang_start::hc4bcc3e322e6b48a
  18:     0x55c5028177f3 - main
  19:     0x7f3c8cd9c24e - __libc_start_call_main
  20:     0x7f3c8cd9c309 - __libc_start_main_alias_1
  21:     0x55c5028138c5 - _start
  22:                0x0 - <unknown>



failures:
    src/lib.rs - ReadmeDoctests (line 1244)

test result: FAILED. 1 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.66s

error: test failed, to rerun pass '--doc'

Subsequent runs:

$ cargo test
   Compiling commitlog v0.2.0 (/home/chkno/devel/commitlog)
    Finished test [unoptimized + debuginfo] target(s) in 5.09s
     Running unittests src/lib.rs (/home/chkno/devel/commitlog/target/debug/deps/commitlog-20e23766e29d907f)

running 51 tests
...

test result: ok. 51 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.10s

   Doc-tests commitlog

running 2 tests
test src/lib.rs - (line 18) ... FAILED
test src/lib.rs - ReadmeDoctests (line 1244) ... FAILED

failures:

---- src/lib.rs - (line 18) stdout ----
Test executable failed (exit status: 101).

stderr:
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: CorruptLog', src/lib.rs:16:54
stack backtrace:
   0:     0x55c37ebef26c - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::hf2ea00d5f3b53d9f
   1:     0x55c37ec18efe - core::fmt::write::ha076a7e65c6b1874
   2:     0x55c37ebfc551 - std::io::Write::write_fmt::h9630bb3b0fe886f5
   3:     0x55c37ec03325 - std::panicking::default_hook::{{closure}}::h64163197f96398c1
   4:     0x55c37ec02f82 - std::panicking::default_hook::h92625161492e6b48
   5:     0x55c37ec03841 - std::panicking::rust_panic_with_hook::hfdd7d6bb6788c6c2
   6:     0x55c37ebef5a7 - std::panicking::begin_panic_handler::{{closure}}::he81a60a7ef84ad4a
   7:     0x55c37ebef384 - std::sys_common::backtrace::__rust_end_short_backtrace::h62801bf9780239e6
   8:     0x55c37ec034f2 - rust_begin_unwind
   9:     0x55c37eb81783 - core::panicking::panic_fmt::hfd221b9f37504b4a
  10:     0x55c37eb81813 - core::result::unwrap_failed::h7a3045feac200afb
  11:     0x55c37eb82ba6 - core::result::Result<T,E>::unwrap::hb37e00b8d64d32aa
  12:     0x55c37eb85562 - rust_out::main::h7cf9d0438004d406
  13:     0x55c37eb82283 - core::ops::function::FnOnce::call_once::h3166193039ac9aa5
  14:     0x55c37eb81df9 - std::sys_common::backtrace::__rust_begin_short_backtrace::h4035ab9eaf427f7b
  15:     0x55c37eb81e69 - std::rt::lang_start::{{closure}}::h61c7438f2ca2ee26
  16:     0x55c37ebf6295 - std::rt::lang_start_internal::h09bcc9fffd987f14
  17:     0x55c37eb81e51 - std::rt::lang_start::hc4bcc3e322e6b48a
  18:     0x55c37eb857f3 - main
  19:     0x7f1b6139324e - __libc_start_call_main
  20:     0x7f1b61393309 - __libc_start_main_alias_1
  21:     0x55c37eb818c5 - _start
  22:                0x0 - <unknown>


---- src/lib.rs - ReadmeDoctests (line 1244) stdout ----
Test executable failed (exit status: 101).

stderr:
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: CorruptLog', src/lib.rs:16:54
stack backtrace:
   0:     0x5614542e726c - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::hf2ea00d5f3b53d9f
   1:     0x561454310efe - core::fmt::write::ha076a7e65c6b1874
   2:     0x5614542f4551 - std::io::Write::write_fmt::h9630bb3b0fe886f5
   3:     0x5614542fb325 - std::panicking::default_hook::{{closure}}::h64163197f96398c1
   4:     0x5614542faf82 - std::panicking::default_hook::h92625161492e6b48
   5:     0x5614542fb841 - std::panicking::rust_panic_with_hook::hfdd7d6bb6788c6c2
   6:     0x5614542e75a7 - std::panicking::begin_panic_handler::{{closure}}::he81a60a7ef84ad4a
   7:     0x5614542e7384 - std::sys_common::backtrace::__rust_end_short_backtrace::h62801bf9780239e6
   8:     0x5614542fb4f2 - rust_begin_unwind
   9:     0x561454279783 - core::panicking::panic_fmt::hfd221b9f37504b4a
  10:     0x561454279813 - core::result::unwrap_failed::h7a3045feac200afb
  11:     0x56145427aba6 - core::result::Result<T,E>::unwrap::hb37e00b8d64d32aa
  12:     0x56145427d562 - rust_out::main::h7cf9d0438004d406
  13:     0x56145427a283 - core::ops::function::FnOnce::call_once::h3166193039ac9aa5
  14:     0x561454279df9 - std::sys_common::backtrace::__rust_begin_short_backtrace::h4035ab9eaf427f7b
  15:     0x561454279e69 - std::rt::lang_start::{{closure}}::h61c7438f2ca2ee26
  16:     0x5614542ee295 - std::rt::lang_start_internal::h09bcc9fffd987f14
  17:     0x561454279e51 - std::rt::lang_start::hc4bcc3e322e6b48a
  18:     0x56145427d7f3 - main
  19:     0x7f8388d3024e - __libc_start_call_main
  20:     0x7f8388d30309 - __libc_start_main_alias_1
  21:     0x5614542798c5 - _start
  22:                0x0 - <unknown>



failures:
    src/lib.rs - (line 18)
    src/lib.rs - ReadmeDoctests (line 1244)

test result: FAILED. 0 passed; 2 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.79s

error: test failed, to rerun pass '--doc'

Mar 10 '23 00:03 chkno