test failed in CI: `task::tests::tq_proxy`

[bnaecker]

This test failed on a CI run on #9389:

https://github.com/oxidecomputer/omicron/pull/9389/checks?check_run_id=55874719917

Log showing the specific test failure:

https://buildomat.eng.oxide.computer/wg/0/details/01KAF2KF2DFCHPA4BRCG61DX4E/ts4gyuSeVYFFUa8hwGAJ2g9toM9He4l9WyRbJJZOfDPhrdoe/01KAF2M73GZGW61YZXRP3469K9#S9612

Excerpt from the log showing the failure:

      FAIL [   3.917s] (2414/2421) trust-quorum task::tests::tq_proxy
stdout ───

  running 1 test
  Writing keys and certs to /var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-root-a.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-signer-a1.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-platformid-1.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-deviceid-1.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-sprockets-auth-1.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-alias-1.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-platformid-2.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-deviceid-2.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-sprockets-auth-2.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-alias-2.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-platformid-3.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-deviceid-3.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-sprockets-auth-3.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-alias-3.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-platformid-4.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-deviceid-4.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-sprockets-auth-4.key.pem"
  Writing key pair to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-alias-4.key.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-root-a.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-signer-a1.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-platformid-1.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-deviceid-1.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-sprockets-auth-1.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-alias-1.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-platformid-2.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-deviceid-2.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-sprockets-auth-2.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-alias-2.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-platformid-3.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-deviceid-3.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-sprockets-auth-3.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-alias-3.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-platformid-4.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-deviceid-4.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-sprockets-auth-4.cert.pem"
  Writing certificate to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-alias-4.cert.pem"
  Writing pki path to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-sprockets-auth-1.certlist.pem"
  Writing pki path to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-alias-1.certlist.pem"
  Writing pki path to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-sprockets-auth-2.certlist.pem"
  Writing pki path to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-alias-2.certlist.pem"
  Writing pki path to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-sprockets-auth-3.certlist.pem"
  Writing pki path to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-alias-3.certlist.pem"
  Writing pki path to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-sprockets-auth-4.certlist.pem"
  Writing pki path to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.1/test-alias-4.certlist.pem"
  test task::tests::tq_proxy ... FAILED

  failures:

  failures:
      task::tests::tq_proxy

  test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 10 filtered out; finished in 3.90s
  
stderr ───
  log file: /var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.0.log
  note: configured to log to "/var/tmp/omicron_tmp/trust_quorum-827d57b93529a4cc-tq_proxy.335332.0.log"

  thread 'task::tests::tq_proxy' panicked at trust-quorum/src/task.rs:2272:14:
  successful status request: Disconnected
  stack backtrace:
     0: __rustc::rust_begin_unwind
               at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/std/src/panicking.rs:697:5
     1: core::panicking::panic_fmt
               at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/panicking.rs:75:14
     2: core::result::unwrap_failed
               at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/result.rs:1761:5
     3: expect<trust_quorum::task::NodeStatus, trust_quorum::proxy::ProxyError<trust_quorum::proxy::NoInnerError>>
               at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/result.rs:1119:23
     4: {async_block#0}
               at ./src/task.rs:2272:14
     5: poll<&mut dyn core::future::future::Future<Output=()>>
               at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/future/future.rs:124:9
     6: poll<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
               at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/future/future.rs:124:9
     7: {closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:742:70
     8: with_budget<core::task::poll::Poll<()>, tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure#0}::{closure#0}::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/task/coop/mod.rs:167:5
     9: budget<core::task::poll::Poll<()>, tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure#0}::{closure#0}::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/task/coop/mod.rs:133:5
    10: {closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:742:25
    11: enter<core::task::poll::Poll<()>, tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure#0}::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:432:19
    12: {closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:741:44
    13: {closure#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:829:68
    14: set<tokio::runtime::scheduler::Context, tokio::runtime::scheduler::current_thread::{impl#8}::enter::{closure_env#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>, (alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>)>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/context/scoped.rs:40:9
    15: {closure#0}<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>), tokio::runtime::scheduler::current_thread::{impl#8}::enter::{closure_env#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/context.rs:176:38
    16: try_with<tokio::runtime::context::Context, tokio::runtime::context::set_scheduler::{closure_env#0}<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>), tokio::runtime::scheduler::current_thread::{impl#8}::enter::{closure_env#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>>, (alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>)>
               at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/std/src/thread/local.rs:315:12
    17: with<tokio::runtime::context::Context, tokio::runtime::context::set_scheduler::{closure_env#0}<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>), tokio::runtime::scheduler::current_thread::{impl#8}::enter::{closure_env#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>>, (alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>)>
               at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/std/src/thread/local.rs:279:20
    18: set_scheduler<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>), tokio::runtime::scheduler::current_thread::{impl#8}::enter::{closure_env#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/context.rs:176:17
    19: enter<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:829:27
    20: block_on<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:729:24
    21: {closure#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:200:33
    22: enter_runtime<tokio::runtime::scheduler::current_thread::{impl#0}::block_on::{closure_env#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>, ()>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/context/runtime.rs:65:16
    23: block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:188:9
    24: block_on_inner<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/runtime.rs:356:52
    25: block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
               at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/runtime.rs:330:18
    26: tq_proxy
               at ./src/task.rs:2275:35
    27: {closure#0}
               at ./src/task.rs:2120:24
    28: call_once<trust_quorum::task::tests::tq_proxy::{closure_env#0}, ()>
               at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/ops/function.rs:250:5
    29: core::ops::function::FnOnce::call_once
               at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/ops/function.rs:250:5
  note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

[andrewjstone]

This is a bug in the test. The test assumes that after loading a rack secret that it can successfully talk to all nodes. However, the threshold for recomputing the rack secret is 3. In the failing test node 4 receives 3 shares from node 2, node 3, and itself. Then what happens is we try to proxy a request from node 1 to node 4, but the two have not yet reconnected, and so the request fails. I'll fix this by waiting for the connection before sending the final status request.