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_cache_refresh in manager.rs is flakey #824

Closed
MorrisLaw opened this issue Feb 22, 2024 · 3 comments
Closed

test_cache_refresh in manager.rs is flakey #824

MorrisLaw opened this issue Feb 22, 2024 · 3 comments
Assignees
@howardjohn
Labels
community/help wanted Indicates a PR/Issue that needs community help help wanted Indicates a PR/Issue that needs community help

Comments

@MorrisLaw
Copy link
Contributor

The test (test_cache_refresh) is not too reliable due to it's time dependent nature. When ran locally it may panic that the expected number of cert updates does not match the number of actual updates produced in the test.

Here is an example stack trace:

thread 'tokio-runtime-worker' panicked at src/identity/manager.rs:678:9:
assertion `left == right` failed
  left: 1
 right: 2
stack backtrace:
   0: rust_begin_unwind
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/panicking.rs:645:5
   1: core::panicking::panic_fmt
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/panicking.rs:72:14
   2: core::panicking::assert_failed_inner
   3: core::panicking::assert_failed
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/panicking.rs:279:5
   4: ztunnel::identity::manager::tests::verify_cert_updates::{{closure}}
             at ./src/identity/manager.rs:678:9
   5: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/core.rs:311:17
   6: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/loom/std/unsafe_cell.rs:14:9
   7: tokio::runtime::task::core::Core<T,S>::poll
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/core.rs:300:13
   8: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/harness.rs:476:19
   9: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/panic/unwind_safe.rs:272:9
  10: std::panicking::try::do_call
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/panicking.rs:552:40
  11: __rust_try
  12: std::panicking::try
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/panicking.rs:516:19
  13: std::panic::catch_unwind
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/panic.rs:142:14
  14: tokio::runtime::task::harness::poll_future
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/harness.rs:464:18
  15: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/harness.rs:198:27
  16: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/harness.rs:152:15
  17: tokio::runtime::task::raw::poll
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/raw.rs:276:5
  18: tokio::runtime::task::raw::RawTask::poll
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/raw.rs:200:18
  19: tokio::runtime::task::LocalNotified<S>::run
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/mod.rs:400:9
  20: tokio::runtime::scheduler::multi_thread::worker::Context::run_task::{{closure}}
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/scheduler/multi_thread/worker.rs:576:13
  21: tokio::runtime::coop::with_budget
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/coop.rs:107:5
  22: tokio::runtime::coop::budget
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/coop.rs:73:5
  23: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/scheduler/multi_thread/worker.rs:575:9
  24: tokio::runtime::scheduler::multi_thread::worker::Context::run
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/scheduler/multi_thread/worker.rs:538:24
  25: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}::{{closure}}
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/scheduler/multi_thread/worker.rs:491:21
  26: tokio::runtime::context::scoped::Scoped<T>::set
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/context/scoped.rs:40:9
  27: tokio::runtime::context::set_scheduler::{{closure}}
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/context.rs:176:26
  28: std::thread::local::LocalKey<T>::try_with
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/thread/local.rs:270:16
  29: std::thread::local::LocalKey<T>::with
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/thread/local.rs:246:9
  30: tokio::runtime::context::set_scheduler
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/context.rs:176:9
  31: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/scheduler/multi_thread/worker.rs:486:9
  32: tokio::runtime::context::runtime::enter_runtime
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/context/runtime.rs:65:16
  33: tokio::runtime::scheduler::multi_thread::worker::run
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/scheduler/multi_thread/worker.rs:478:5
  34: tokio::runtime::scheduler::multi_thread::worker::Launch::launch::{{closure}}
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/scheduler/multi_thread/worker.rs:447:45
  35: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/blocking/task.rs:42:21
  36: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/core.rs:311:17
  37: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/loom/std/unsafe_cell.rs:14:9
  38: tokio::runtime::task::core::Core<T,S>::poll
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/core.rs:300:13
  39: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/harness.rs:476:19
  40: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/panic/unwind_safe.rs:272:9
  41: std::panicking::try::do_call
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/panicking.rs:552:40
  42: __rust_try
  43: std::panicking::try
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/panicking.rs:516:19
  44: std::panic::catch_unwind
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/panic.rs:142:14
  45: tokio::runtime::task::harness::poll_future
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/harness.rs:464:18
  46: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/harness.rs:198:27
  47: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/harness.rs:152:15
  48: tokio::runtime::task::raw::poll
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/raw.rs:276:5
  49: tokio::runtime::task::raw::RawTask::poll
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/raw.rs:200:18
  50: tokio::runtime::task::UnownedTask<S>::run
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/task/mod.rs:437:9
  51: tokio::runtime::blocking::pool::Task::run
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/blocking/pool.rs:159:9
  52: tokio::runtime::blocking::pool::Inner::run
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/blocking/pool.rs:513:17
  53: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/blocking/pool.rs:471:13
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread 'identity::manager::tests::test_cache_refresh' panicked at src/identity/manager.rs:726:13:
assertion failed: result.is_ok()
stack backtrace:
   0: rust_begin_unwind
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/panicking.rs:645:5
   1: core::panicking::panic_fmt
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/panicking.rs:72:14
   2: core::panicking::panic
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/panicking.rs:127:5
   3: ztunnel::identity::manager::tests::test_cache_refresh::{{closure}}
             at ./src/identity/manager.rs:726:13
   4: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9
   5: tokio::runtime::park::CachedParkThread::block_on::{{closure}}
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/park.rs:283:63
   6: tokio::runtime::coop::with_budget
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/coop.rs:107:5
   7: tokio::runtime::coop::budget
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/coop.rs:73:5
   8: tokio::runtime::park::CachedParkThread::block_on
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/park.rs:283:31
   9: tokio::runtime::context::blocking::BlockingRegionGuard::block_on
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/context/blocking.rs:66:9
  10: tokio::runtime::scheduler::multi_thread::MultiThread::block_on::{{closure}}
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/scheduler/multi_thread/mod.rs:87:13
  11: tokio::runtime::context::runtime::enter_runtime
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/context/runtime.rs:65:16
  12: tokio::runtime::scheduler::multi_thread::MultiThread::block_on
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/scheduler/multi_thread/mod.rs:86:9
  13: tokio::runtime::runtime::Runtime::block_on
             at /home/jmorris/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.29.1/src/runtime/runtime.rs:313:45
  14: ztunnel::identity::manager::tests::test_cache_refresh
             at ./src/identity/manager.rs:725:9
  15: ztunnel::identity::manager::tests::test_cache_refresh::{{closure}}
             at ./src/identity/manager.rs:697:34
  16: core::ops::function::FnOnce::call_once
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/ops/function.rs:250:5
  17: core::ops::function::FnOnce::call_once
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
test identity::manager::tests::test_backoff_resets_on_successful_fetch_after_failure has been running for over 60 seconds
test identity::manager::tests::test_cache_refresh has been running for over 60 seconds
test identity::manager::tests::test_stress_caching has been running for over 60 seconds
test identity::manager::tests::test_cache_refresh ... FAILED
test identity::manager::tests::test_backoff_resets_on_successful_fetch_after_failure ... ok
@MorrisLaw MorrisLaw added community/help wanted Indicates a PR/Issue that needs community help help wanted Indicates a PR/Issue that needs community help labels Feb 22, 2024
@daixiang0
Copy link
Member

Test 10 times at local, can not reproduce:

root:[ztunnel]$ cargo test --package ztunnel --lib -- identity::manager::tests::test_cache_refresh --exact
    Finished test [unoptimized + debuginfo] target(s) in 0.13s
     Running unittests src/lib.rs (out/rust/debug/deps/ztunnel-5d4b934a2135e7c6)

running 1 test
test identity::manager::tests::test_cache_refresh ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 124 filtered out; finished in 0.20s

@MorrisLaw
Copy link
Contributor Author

Hmm. There's more context here in this slack thread.

I was running this on an Azure Ubuntu 20.04 VM. Myself and others have made some changes to that file recently, it's possible the flake could have been fixed? I'll have to check again to be sure.

@MorrisLaw MorrisLaw self-assigned this Apr 24, 2024
@howardjohn howardjohn assigned howardjohn and unassigned MorrisLaw May 11, 2024
@howardjohn
Copy link
Member

7b11e39

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@howardjohn howardjohn

Labels
community/help wanted Indicates a PR/Issue that needs community help help wanted Indicates a PR/Issue that needs community help
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@howardjohn @MorrisLaw @daixiang0