Text file busy flake in tests

[gakonst]

For some reason, tests fail sometimes with the error below:

---- multi_runner::tests::sputnik::test_sputnik_abstract_contract stdout ----
compiling...
thread 'multi_runner::tests::sputnik::test_sputnik_abstract_contract' panicked at 'called `Result::unwrap()` on an `Err` value: Text file busy (os error 26)

Other times it fails with this one:

---- multi_runner::tests::sputnik::test_sputnik_abstract_contract stdout ----
compiling...
thread 'multi_runner::tests::sputnik::test_sputnik_abstract_contract' panicked at 'called `Result::unwrap()` on an `Err` value: "/home/runner/.svm/0.8.1/solc-0.8.1": Text file busy (os error 26)

I suspect this might be related to the Solc downloader trying to download a binary multiple times, and write it over an existing file? Not sure.

[onbjerg]

Going by backtrace:

---- multi_runner::tests::sputnik::test_sputnik_abstract_contract stdout ----
compiling...
thread 'multi_runner::tests::sputnik::test_sputnik_abstract_contract' panicked at 'called `Result::unwrap()` on an `Err` value: Text file busy (os error 26)

Location:
    /rustc/59eed8a2aac0230a8b53e89d4e99d55912ba6b35/library/core/src/result.rs:1915:27', forge/src/multi_runner.rs:223:82
stack backtrace:
   0: rust_begin_unwind
             at /rustc/59eed8a2aac0230a8b53e89d4e99d55912ba6b35/library/std/src/panicking.rs:517:5
   1: core::panicking::panic_fmt
             at /rustc/59eed8a2aac0230a8b53e89d4e99d55912ba6b35/library/core/src/panicking.rs:101:14
   2: core::result::unwrap_failed
             at /rustc/59eed8a2aac0230a8b53e89d4e99d55912ba6b35/library/core/src/result.rs:1617:5
   3: core::result::Result<T,E>::unwrap
             at /rustc/59eed8a2aac0230a8b53e89d4e99d55912ba6b35/library/core/src/result.rs:1299:23
   4: forge::multi_runner::tests::runner
             at ./src/multi_runner.rs:223:9
   5: forge::multi_runner::tests::test_abstract_contract
             at ./src/multi_runner.rs:251:26
   6: forge::multi_runner::tests::sputnik::test_sputnik_abstract_contract
             at ./src/multi_runner.rs:301:13
   7: forge::multi_runner::tests::sputnik::test_sputnik_abstract_contract::{{closure}}
             at ./src/multi_runner.rs:300:9
   8: core::ops::function::FnOnce::call_once
             at /rustc/59eed8a2aac0230a8b53e89d4e99d55912ba6b35/library/core/src/ops/function.rs:227:5
   9: core::ops::function::FnOnce::call_once
             at /rustc/59eed8a2aac0230a8b53e89d4e99d55912ba6b35/library/core/src/ops/function.rs:227:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.


failures:
    multi_runner::tests::sputnik::test_sputnik_abstract_contract

We end up at MultiContractRunnerBuilder::build that can only return an Err in one place, which is when it calls project.compile()?. Since we're running with --all-features we end up in Project::svm_compile for the next Result.

My best bet is that either it is that we are building the same contracts in two tests, so the cache/artifacts are being written at the same time, or it is SVM as you suspected.

I don't see a super elegant solution, maybe using serial_test or running with -- --test-threads=1 (slow!)

[gakonst]

My best bet is that either it is that we are building the same contracts in two tests, so the cache/artifacts are being written at the same time, or it is SVM as you suspected.

@mattsse this seems to align with how we've been thinking about the caching issue?

I think there should be a "right" way to solve it, serial tests would be a big no-no, so let's try to brainstorm it a bit?

[mattsse]

so text file busy happens if a program tries to modify a file that's currently being executed or otherwise used in write mode.

this could be a race condition within our svm abstraction.
is there a way to reproduce this?
RUST_LOG=ethers=trace should also be helpful to locate the root cause

[onbjerg]

To reproduce: run cargo test --all --all-features -- --test-threads=high number where high number is the amount of threads you are able to use before your computer flies off into space. For good measure also delete or move $HOME/.svm before running. Run until the test fails. 🤷

I used a thread count of 32 and ran it 2 or 3 times before I encountered the failing test

[mattsse]

that makes a bit more sense now,
this happens only during tests, right?

[mattsse]

my guess is, two tests run in parallel, both need solc x.y.z which is missing, so they both try to install it...

[gakonst]

Yeah that's typically what happened in the past, which I thought we had solved with a mutex in the installation step, maybe the mutex got lost during our ethers-solc refactors?

[mattsse]

lock in test is still there but perhaps this is an integration test issue where multiple bins are executed

maybe we can try using a lockfile instead, https://crates.io/crates/fslock ?

[mattsse]

Oh I think I've found it,

I changed version detection in the new graph implementation

[onbjerg]

I don't think an in-process mutex solves it, think we do need a lockfile. AFAIK tests are built as a special executable that Cargo just runs in parallel or something :/

[gakonst]

I think adding a lockfile under ~/.svm and the artifacts dir could be a fine solution if we don't have a better one, as long as it gets cleaned up instantly and we document it nicely (it's never cool when the user needs to manually remove index/lockfiles)

[onbjerg]

Ok, looked at it to be sure, it does not run the executable multiple times side by side. Perhaps it's just because we call other install methods than Solc::ensure_installed so the lock should actually be in Solc::install and Solc::blocking_install

gakonst/ethers-rs#808

[gakonst]

From latest CI:

The println makes me believe the issue is during the svm installation step here, which proceeds to call svm::install.

I think the offending code is either the std::io::copy or the std::fs::File::create above it

@MATTSE mentioned that if gakonst/ethers-rs#802 doesn't address this, we should consider using a lockfile, given that our existing mutexes in ethers-solc seem to not be getting hit

[roynalnaruto]

@gakonst @mattsse added a PR above that will block the installation until lock file is released (up to a timeout period of 10 seconds).

[gakonst]

Let's see if this finally fixes it..