Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

test failed: wicketd test_update_races #4590

Closed
davepacheco opened this issue Nov 30, 2023 · 2 comments · Fixed by #4641
Closed

test failed: wicketd test_update_races #4590

davepacheco opened this issue Nov 30, 2023 · 2 comments · Fixed by #4641
Assignees
@sunshowers
Labels
Test Flake Tests that work. Wait, no. Actually yes. Hang on. Something is broken.

Comments

@davepacheco
Copy link
Collaborator

CI run:
https://github.com/oxidecomputer/omicron/pull/4588/checks?check_run_id=19198066410

Specific failure:
https://buildomat.eng.oxide.computer/wg/0/details/01HGH32FQYKZJNX9J62HNABKPA/31C5jyox8tyHUIuDDevKkXlDZCyNw143z4nOq8wLl3xtjKzT/01HGH32V3P0HH6B56S46AJAT63#S4455

	--- STDERR:              wicketd::mod integration_tests::updates::test_update_races ---
	log file: /var/tmp/omicron_tmp/mod-ae2eb84a30e4213e-test_artifact_upload_while_updating.14133.0.log
	note: configured to log to "/var/tmp/omicron_tmp/mod-ae2eb84a30e4213e-test_artifact_upload_while_updating.14133.0.log"
	hint: Generated a random key:
	hint:
	hint:   ed25519:826a8f799d4cc767158c990a60f721215bfd71f8f94fa88ba1960037bd6e5554
	hint:
	hint: To modify this repository, you will need this key. Use the -k/--key
	hint: command line flag or the TUFACEOUS_KEY environment variable:
	hint:
	hint:   export TUFACEOUS_KEY=ed25519:826a8f799d4cc767158c990a60f721215bfd71f8f94fa88ba1960037bd6e5554
	hint:
	hint: To prevent this default behavior, use --no-generate-key.
	thread 'integration_tests::updates::test_update_races' panicked at wicketd/tests/integration_tests/updates.rs:482:41:
	at least one event
	stack backtrace:
	   0: rust_begin_unwind
	             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/std/src/panicking.rs:597:5
	   1: core::panicking::panic_fmt
	             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/panicking.rs:72:14
	   2: core::panicking::panic_display
	             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/panicking.rs:168:5
	   3: core::panicking::panic_str
	             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/panicking.rs:152:5
	   4: core::option::expect_failed
	             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/option.rs:1988:5
	   5: core::option::Option<T>::expect
	             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/option.rs:898:21
	   6: {async_block#0}
	             at ./tests/integration_tests/updates.rs:482:9
	   7: poll<&mut dyn core::future::future::Future<Output=()>>
	             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/future/future.rs:125:9
	   8: {closure#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
	             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/park.rs:282:63
	   9: with_budget<core::task::poll::Poll<()>, tokio::runtime::park::{impl#4}::block_on::{closure_env#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
	             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/coop.rs:107:5
	  10: budget<core::task::poll::Poll<()>, tokio::runtime::park::{impl#4}::block_on::{closure_env#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
	             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/coop.rs:73:5
	  11: block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
	             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/park.rs:282:31
	  12: tokio::runtime::context::blocking::BlockingRegionGuard::block_on
	             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/context/blocking.rs:66:9
	  13: tokio::runtime::scheduler::multi_thread::MultiThread::block_on::{{closure}}
	             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/scheduler/multi_thread/mod.rs:87:13
	  14: tokio::runtime::context::runtime::enter_runtime
	             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/context/runtime.rs:65:16
	  15: tokio::runtime::scheduler::multi_thread::MultiThread::block_on
	             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/scheduler/multi_thread/mod.rs:86:9
	  16: tokio::runtime::runtime::Runtime::block_on
	             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/runtime.rs:350:45
	  17: test_update_races
	             at ./tests/integration_tests/updates.rs:508:5
	  18: mod::integration_tests::updates::test_update_races::{{closure}}
	             at ./tests/integration_tests/updates.rs:401:30
	  19: core::ops::function::FnOnce::call_once
	             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/ops/function.rs:250:5
	  20: core::ops::function::FnOnce::call_once
	             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/ops/function.rs:250:5
	note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

I saw this on PR #4588 but I'd be surprised if that were related.
@davepacheco davepacheco added the Test Flake Tests that work. Wait, no. Actually yes. Hang on. Something is broken. label Nov 30, 2023
@davepacheco
Copy link
Collaborator Author

@sunshowers could you take a look at this one?

@sunshowers sunshowers self-assigned this Dec 1, 2023
@jgallagher
Copy link
Contributor

Hit this on https://github.com/oxidecomputer/omicron/pull/4631/checks?check_run_id=19382171637, which has a single line change that is definitely unrelated to wicket. The error message is different, though; from https://buildomat.eng.oxide.computer/wg/0/details/01HH0667GSHN427B68G5DM8TVM/zr5145908NiVzI4lFKYsQ9BYQbVz239vio9yYcXLa23GRNkX/01HH0671ZWE4TA608VS47PQCHP:

--- STDERR:              wicketd::mod integration_tests::updates::test_update_races ---
log file: /var/tmp/omicron_tmp/mod-2499ac8b8ccc2c38-test_artifact_upload_while_updating.14197.0.log
note: configured to log to "/var/tmp/omicron_tmp/mod-2499ac8b8ccc2c38-test_artifact_upload_while_updating.14197.0.log"
hint: Generated a random key:
hint:
hint:   ed25519:9fd97a67e84aed533d0ae66f8cb83ec7481d411fd0cdec2237cd6977e1e096be
hint:
hint: To modify this repository, you will need this key. Use the -k/--key
hint: command line flag or the TUFACEOUS_KEY environment variable:
hint:
hint:   export TUFACEOUS_KEY=ed25519:9fd97a67e84aed533d0ae66f8cb83ec7481d411fd0cdec2237cd6977e1e096be
hint:
hint: To prevent this default behavior, use --no-generate-key.
thread 'integration_tests::updates::test_update_races' panicked at wicketd/tests/integration_tests/updates.rs:483:5:
last event is execution completed: StepEvent {
    spec: "WicketdEngineSpec",
    execution_id: ExecutionId(
        6400de89-e360-4f36-87ed-446d2f470cb0,
    ),
    event_index: 0,
    total_elapsed: 444.774µs,
    kind: ExecutionStarted {
        steps: [
            StepInfo {
                id: RunningInstallinator,
                component: Host,
                description: "Fake step that waits for receiver to resolve",
                index: 0,
                component_index: 0,
                total_component_steps: 1,
            },
        ],
        components: [
            StepComponentSummary {
                component: Host,
                total_component_steps: 1,
            },
        ],
        first_step: StepInfoWithMetadata {
            info: StepInfo {
                id: RunningInstallinator,
                component: Host,
                description: "Fake step that waits for receiver to resolve",
                index: 0,
                component_index: 0,
                total_component_steps: 1,
            },
            metadata: None,
        },
    },
}
stack backtrace:
   0: rust_begin_unwind
             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/std/src/panicking.rs:597:5
   1: core::panicking::panic_fmt
             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/panicking.rs:72:14
   2: {async_block#0}
             at ./tests/integration_tests/updates.rs:483:5
   3: poll<&mut dyn core::future::future::Future<Output=()>>
             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/future/future.rs:125:9
   4: {closure#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/park.rs:282:63
   5: with_budget<core::task::poll::Poll<()>, tokio::runtime::park::{impl#4}::block_on::{closure_env#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/coop.rs:107:5
   6: budget<core::task::poll::Poll<()>, tokio::runtime::park::{impl#4}::block_on::{closure_env#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/coop.rs:73:5
   7: block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/park.rs:282:31
   8: tokio::runtime::context::blocking::BlockingRegionGuard::block_on
             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/context/blocking.rs:66:9
   9: tokio::runtime::scheduler::multi_thread::MultiThread::block_on::{{closure}}
             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/scheduler/multi_thread/mod.rs:87:13
  10: tokio::runtime::context::runtime::enter_runtime
             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/context/runtime.rs:65:16
  11: tokio::runtime::scheduler::multi_thread::MultiThread::block_on
             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/scheduler/multi_thread/mod.rs:86:9
  12: tokio::runtime::runtime::Runtime::block_on
             at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.34.0/src/runtime/runtime.rs:350:45
  13: test_update_races
             at ./tests/integration_tests/updates.rs:508:5
  14: mod::integration_tests::updates::test_update_races::{{closure}}
             at ./tests/integration_tests/updates.rs:401:30
  15: core::ops::function::FnOnce::call_once
             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/ops/function.rs:250:5
  16: core::ops::function::FnOnce::call_once
             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/ops/function.rs:250:5

@sunshowers sunshowers mentioned this issue Dec 7, 2023
Merged
sunshowers added a commit that referenced this issue Dec 7, 2023
@sunshowers
[wicketd] be more explicit about ordering in test_update_races (#4641)
77ad358 
The switch to a multithreaded executor for this test in #4477 appears to have
exposed a race within this test (quite ironic given the name!) Fix the race by
being explicit about the ordering of events.

Fixes #4590.
@davepacheco davepacheco mentioned this issue Dec 11, 2023
Closed
@davepacheco davepacheco mentioned this issue Jan 18, 2024
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@sunshowers sunshowers

Labels
Test Flake Tests that work. Wait, no. Actually yes. Hang on. Something is broken.
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

[wicketd] be more explicit about ordering in test_update_races oxidecomputer/omicron
3 participants
@sunshowers @davepacheco @jgallagher