search

martinvonz / jj

A Git-compatible VCS that is both simple and powerful
https://martinvonz.github.io/jj/
Apache License 2.0
8.18k stars 272 forks source link

Flaky tests in `test_working_copy_concurrent` when run with `nextest` #1536

Open ilyagr opened 1 year ago

ilyagr commented 1 year ago

When I run cargo insta test --test-runner nextest --workspace, I often get the following error. Rerunning usually fixes the problem.

 jujutsu-lib::test_working_copy_concurrent test_checkout_parallel::local_backend ---

running 1 test
test test_checkout_parallel::local_backend ... FAILED

failures:

failures:
    test_checkout_parallel::local_backend

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

--- STDERR:              jujutsu-lib::test_working_copy_concurrent test_checkout_parallel::local_backend ---
thread '<unnamed>' panicked at 'failed to create lock file /tmp/jj-test-67VQIk/repo/.jj/working_copy/working_copy.lock: File exists (os error 17)', lib/src/lock.rs:56:25
stack backtrace:
   0: rust_begin_unwind
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/std/src/panicking.rs:579:5
   1: core::panicking::panic_fmt
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/panicking.rs:64:14
   2: jujutsu_lib::lock::FileLock::lock
             at ./src/lock.rs:56:25
   3: jujutsu_lib::working_copy::WorkingCopy::start_mutation
             at ./src/working_copy.rs:1145:20
   4: jujutsu_lib::working_copy::WorkingCopy::check_out
             at ./src/working_copy.rs:1171:29
   5: test_working_copy_concurrent::test_checkout_parallel::{{closure}}
             at ./tests/test_working_copy_concurrent.rs:125:25
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread '<unnamed>' panicked at 'failed to create lock file /tmp/jj-test-67VQIk/repo/.jj/working_copy/working_copy.lock: File exists (os error 17)', lib/src/lock.rs:56:25
stack backtrace:
   0: rust_begin_unwind
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/std/src/panicking.rs:579:5
   1: core::panicking::panic_fmt
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/panicking.rs:64:14
   2: jujutsu_lib::lock::FileLock::lock
             at ./src/lock.rs:56:25
   3: jujutsu_lib::working_copy::WorkingCopy::start_mutation
             at ./src/working_copy.rs:1145:20
   4: jujutsu_lib::working_copy::WorkingCopy::check_out
             at ./src/working_copy.rs:1171:29
   5: test_working_copy_concurrent::test_checkout_parallel::{{closure}}
             at ./tests/test_working_copy_concurrent.rs:125:25
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread '<unnamed>' panicked at 'failed to create lock file /tmp/jj-test-67VQIk/repo/.jj/working_copy/working_copy.lock: File exists (os error 17)', lib/src/lock.rs:56:25
stack backtrace:
   0: rust_begin_unwind
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/std/src/panicking.rs:579:5
   1: core::panicking::panic_fmt
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/panicking.rs:64:14
   2: jujutsu_lib::lock::FileLock::lock
             at ./src/lock.rs:56:25
   3: jujutsu_lib::working_copy::WorkingCopy::start_mutation
             at ./src/working_copy.rs:1145:20
   4: jujutsu_lib::working_copy::WorkingCopy::check_out
             at ./src/working_copy.rs:1171:29
   5: test_working_copy_concurrent::test_checkout_parallel::{{closure}}
             at ./tests/test_working_copy_concurrent.rs:125:25
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread '<unnamed>' panicked at 'failed to create lock file /tmp/jj-test-67VQIk/repo/.jj/working_copy/working_copy.lock: File exists (os error 17)', lib/src/lock.rs:56:25
stack backtrace:
   0: rust_begin_unwind
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/std/src/panicking.rs:579:5
   1: core::panicking::panic_fmt
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/panicking.rs:64:14
   2: jujutsu_lib::lock::FileLock::lock
             at ./src/lock.rs:56:25
   3: jujutsu_lib::working_copy::WorkingCopy::start_mutation
             at ./src/working_copy.rs:1145:20
   4: jujutsu_lib::working_copy::WorkingCopy::check_out
             at ./src/working_copy.rs:1171:29
   5: test_working_copy_concurrent::test_checkout_parallel::{{closure}}
             at ./tests/test_working_copy_concurrent.rs:125:25
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread '<unnamed>' panicked at 'failed to create lock file /tmp/jj-test-67VQIk/repo/.jj/working_copy/working_copy.lock: File exists (os error 17)', lib/src/lock.rs:56:25
stack backtrace:
   0: rust_begin_unwind
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/std/src/panicking.rs:579:5
   1: core::panicking::panic_fmt
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/panicking.rs:64:14
   2: jujutsu_lib::lock::FileLock::lock
             at ./src/lock.rs:56:25
   3: jujutsu_lib::working_copy::WorkingCopy::start_mutation
             at ./src/working_copy.rs:1145:20
   4: jujutsu_lib::working_copy::WorkingCopy::check_out
             at ./src/working_copy.rs:1171:29
   5: test_working_copy_concurrent::test_checkout_parallel::{{closure}}
             at ./tests/test_working_copy_concurrent.rs:125:25
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread '<unnamed>' panicked at 'failed to create lock file /tmp/jj-test-67VQIk/repo/.jj/working_copy/working_copy.lock: File exists (os error 17)', lib/src/lock.rs:56:25
stack backtrace:
   0: rust_begin_unwind
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/std/src/panicking.rs:579:5
   1: core::panicking::panic_fmt
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/panicking.rs:64:14
   2: jujutsu_lib::lock::FileLock::lock
             at ./src/lock.rs:56:25
   3: jujutsu_lib::working_copy::WorkingCopy::start_mutation
             at ./src/working_copy.rs:1145:20
   4: jujutsu_lib::working_copy::WorkingCopy::check_out
             at ./src/working_copy.rs:1171:29
   5: test_working_copy_concurrent::test_checkout_parallel::{{closure}}
             at ./tests/test_working_copy_concurrent.rs:125:25
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread '<unnamed>' panicked at 'failed to create lock file /tmp/jj-test-67VQIk/repo/.jj/working_copy/working_copy.lock: File exists (os error 17)', lib/src/lock.rs:56:25
stack backtrace:
   0: rust_begin_unwind
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/std/src/panicking.rs:579:5
   1: core::panicking::panic_fmt
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/panicking.rs:64:14
   2: jujutsu_lib::lock::FileLock::lock
             at ./src/lock.rs:56:25
   3: jujutsu_lib::working_copy::WorkingCopy::start_mutation
             at ./src/working_copy.rs:1145:20
   4: jujutsu_lib::working_copy::WorkingCopy::check_out
             at ./src/working_copy.rs:1171:29
   5: test_working_copy_concurrent::test_checkout_parallel::{{closure}}
             at ./tests/test_working_copy_concurrent.rs:125:25
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread '<unnamed>' panicked at 'failed to create lock file /tmp/jj-test-67VQIk/repo/.jj/working_copy/working_copy.lock: File exists (os error 17)', lib/src/lock.rs:56:25
stack backtrace:
   0: rust_begin_unwind
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/std/src/panicking.rs:579:5
   1: core::panicking::panic_fmt
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/panicking.rs:64:14
   2: jujutsu_lib::lock::FileLock::lock
             at ./src/lock.rs:56:25
   3: jujutsu_lib::working_copy::WorkingCopy::start_mutation
             at ./src/working_copy.rs:1145:20
   4: test_working_copy_concurrent::test_checkout_parallel::{{closure}}
             at ./tests/test_working_copy_concurrent.rs:136:33
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread 'test_checkout_parallel::local_backend' panicked at 'called `Option::unwrap()` on a `None` value', lib/tests/test_working_copy_concurrent.rs:144:28
stack backtrace:
   0: rust_begin_unwind
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/std/src/panicking.rs:579:5
   1: core::panicking::panic_fmt
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/panicking.rs:64:14
   2: core::panicking::panic
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/panicking.rs:114:5
   3: core::option::Option<T>::unwrap
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/option.rs:942:21
   4: test_working_copy_concurrent::test_checkout_parallel
             at ./tests/test_working_copy_concurrent.rs:144:9
   5: test_working_copy_concurrent::test_checkout_parallel::local_backend
             at ./tests/test_working_copy_concurrent.rs:79:1
   6: test_working_copy_concurrent::test_checkout_parallel::local_backend::{{closure}}
             at ./tests/test_working_copy_concurrent.rs:79:1
   7: core::ops::function::FnOnce::call_once
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/ops/function.rs:250:5
   8: core::ops::function::FnOnce::call_once
             at /rustc/6664087f2d11a7bcb44fcb4dba552bf42d0df3f1/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

I'm not sure whether this would happen under regular cargo test, since that doesn't run tests in parralel.

yuja commented 1 year ago

Maybe the 10sec timeout is too short under heavy workload. https://github.com/martinvonz/jj/blob/main/lib/src/lock.rs#L52