Failing tests in v0.13.8

[NiklausHofer]

Running cargo test in v0.13.8 results in two tests failing. This is on x86-64 Linux with Rust 1.98.1.

test test::tests::test_version_discovery_404_fails ... FAILED

Running with RUST_BACKTRACE=full, here is what I get:

test test::tests::test_version_discovery_404_fails ... FAILED
test openstack_async::tests::test_auto_renew_stops_when_client_dropped ... ok
test openstack_async::tests::test_auto_renew_success ... ok

failures:

---- test::tests::test_version_discovery_404_fails stdout ----

thread 'test::tests::test_version_discovery_404_fails' (2830885) panicked at openstack_sdk/src/test.rs:567:9:
Version discovery 404 should fail
stack backtrace:
   0:     0x55f350e65591 - <<std[6c98fd8553dbae28]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[c0acaeba6ab4c2e0]::fmt::Display>::fmt
   1:     0x55f350e8273a - core[c0acaeba6ab4c2e0]::fmt::write
   2:     0x55f350e6ce3c - <alloc[12e961f32105355]::vec::Vec<u8> as std[6c98fd8553dbae28]::io::Write>::write_fmt
   3:     0x55f350e3ced6 - std[6c98fd8553dbae28]::panicking::default_hook::{closure#0}
   4:     0x55f350e5abf9 - std[6c98fd8553dbae28]::panicking::default_hook
   5:     0x55f34fdf1510 - test[69f9176bb4e5faed]::test_main_inner::<test[69f9176bb4e5faed]::test_main_static::{closure#0}>::{closure#0}
   6:     0x55f350e5af22 - std[6c98fd8553dbae28]::panicking::panic_with_hook
   7:     0x55f350e3cfb4 - std[6c98fd8553dbae28]::panicking::panic_handler::{closure#0}
   8:     0x55f350e31629 - std[6c98fd8553dbae28]::sys::backtrace::__rust_end_short_backtrace::<std[6c98fd8553dbae28]::panicking::panic_handler::{closure#0}, !>
   9:     0x55f350e3e19d - __rustc[100742bb89c490cb]::rust_begin_unwind
  10:     0x55f350e82fec - core[c0acaeba6ab4c2e0]::panicking::panic_fmt
  11:     0x55f34dd18ee3 - openstack_sdk[213fbd54d4f80503]::test::tests::test_version_discovery_404_fails::{closure#0}
  12:     0x55f34ddd7ea4 - <core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>> as core[c0acaeba6ab4c2e0]::future::future::Future>::poll
  13:     0x55f34ddf4c26 - <tokio[385202785094474a]::runtime::park::CachedParkThread>::block_on::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>::{closure#0}
  14:     0x55f34ddf1675 - <tokio[385202785094474a]::runtime::park::CachedParkThread>::block_on::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>
  15:     0x55f34de0a9c5 - <tokio[385202785094474a]::runtime::context::blocking::BlockingRegionGuard>::block_on::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>
  16:     0x55f34dd26954 - <tokio[385202785094474a]::runtime::scheduler::multi_thread::MultiThread>::block_on::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>::{closure#0}
  17:     0x55f34ddea88d - tokio[385202785094474a]::runtime::context::runtime::enter_runtime::<<tokio[385202785094474a]::runtime::scheduler::multi_thread::MultiThread>::block_on<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>::{closure#0}, ()>
  18:     0x55f34dd265ed - <tokio[385202785094474a]::runtime::scheduler::multi_thread::MultiThread>::block_on::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>
  19:     0x55f34dd98d3a - <tokio[385202785094474a]::runtime::runtime::Runtime>::block_on_inner::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>
  20:     0x55f34dd9962b - <tokio[385202785094474a]::runtime::runtime::Runtime>::block_on::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>
  21:     0x55f34ddd65c6 - openstack_sdk[213fbd54d4f80503]::test::tests::test_version_discovery_404_fails
  22:     0x55f34dd14973 - openstack_sdk[213fbd54d4f80503]::test::tests::test_version_discovery_404_fails::{closure#0}
  23:     0x55f34dd96996 - <openstack_sdk[213fbd54d4f80503]::test::tests::test_version_discovery_404_fails::{closure#0} as core[c0acaeba6ab4c2e0]::ops::function::FnOnce<()>>::call_once
  24:     0x55f34fde484b - test[69f9176bb4e5faed]::__rust_begin_short_backtrace::<core[c0acaeba6ab4c2e0]::result::Result<(), alloc[12e961f32105355]::string::String>, fn() -> core[c0acaeba6ab4c2e0]::result::Result<(), alloc[12e961f32105355]::string::String>>
  25:     0x55f34fdf1e95 - test[69f9176bb4e5faed]::run_test::{closure#0}
  26:     0x55f34fdeb844 - std[6c98fd8553dbae28]::sys::backtrace::__rust_begin_short_backtrace::<test[69f9176bb4e5faed]::run_test::{closure#1}, ()>
  27:     0x55f34fdf4fe2 - <std[6c98fd8553dbae28]::thread::lifecycle::spawn_unchecked<test[69f9176bb4e5faed]::run_test::{closure#1}, ()>::{closure#1} as core[c0acaeba6ab4c2e0]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
  28:     0x55f350e63faf - <std[6c98fd8553dbae28]::sys::thread::unix::Thread>::new::thread_start
  29:     0x7fe7b7e06f45 - <unknown>
  30:     0x7fe7b7e74d9c - <unknown>
  31:                0x0 - <unknown>


failures:
    test::tests::test_version_discovery_404_fails

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

I am also seeing failures in another test, but those only happen about 30% of the time:

test test::tests::test_scoped_login_does_not_trigger_redundant_reauth ... FAILED

Again, here's the full backtrace:

test test::tests::test_scoped_login_does_not_trigger_redundant_reauth ... FAILED

failures:

---- test::tests::test_scoped_login_does_not_trigger_redundant_reauth stdout ----

thread 'test::tests::test_scoped_login_does_not_trigger_redundant_reauth' (2873778) panicked at openstack_sdk/src/test.rs:447:9:
assertion `left == right` failed: scoped login must obtain the token in a single request; a second hit means an unnecessary rescope reauth was triggered
  left: 0
 right: 1
stack backtrace:
   0:     0x560b29d06591 - <<std[6c98fd8553dbae28]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[c0acaeba6ab4c2e0]::fmt::Display>::fmt
   1:     0x560b29d2373a - core[c0acaeba6ab4c2e0]::fmt::write
   2:     0x560b29d0de3c - <alloc[12e961f32105355]::vec::Vec<u8> as std[6c98fd8553dbae28]::io::Write>::write_fmt
   3:     0x560b29cdded6 - std[6c98fd8553dbae28]::panicking::default_hook::{closure#0}
   4:     0x560b29cfbbf9 - std[6c98fd8553dbae28]::panicking::default_hook
   5:     0x560b28c92510 - test[69f9176bb4e5faed]::test_main_inner::<test[69f9176bb4e5faed]::test_main_static::{closure#0}>::{closure#0}
   6:     0x560b29cfbf22 - std[6c98fd8553dbae28]::panicking::panic_with_hook
   7:     0x560b29cddf82 - std[6c98fd8553dbae28]::panicking::panic_handler::{closure#0}
   8:     0x560b29cd2629 - std[6c98fd8553dbae28]::sys::backtrace::__rust_end_short_backtrace::<std[6c98fd8553dbae28]::panicking::panic_handler::{closure#0}, !>
   9:     0x560b29cdf19d - __rustc[100742bb89c490cb]::rust_begin_unwind
  10:     0x560b29d23fec - core[c0acaeba6ab4c2e0]::panicking::panic_fmt
  11:     0x560b29d23ed3 - core[c0acaeba6ab4c2e0]::panicking::assert_failed_inner
  12:     0x560b29d1c8cd - core[c0acaeba6ab4c2e0]::panicking::assert_failed::<usize, usize>
  13:     0x560b26bbc748 - openstack_sdk[213fbd54d4f80503]::test::tests::test_scoped_login_does_not_trigger_redundant_reauth::{closure#0}
  14:     0x560b26c78ea4 - <core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>> as core[c0acaeba6ab4c2e0]::future::future::Future>::poll
  15:     0x560b26c95c26 - <tokio[385202785094474a]::runtime::park::CachedParkThread>::block_on::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>::{closure#0}
  16:     0x560b26c92675 - <tokio[385202785094474a]::runtime::park::CachedParkThread>::block_on::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>
  17:     0x560b26cab9c5 - <tokio[385202785094474a]::runtime::context::blocking::BlockingRegionGuard>::block_on::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>
  18:     0x560b26bc7954 - <tokio[385202785094474a]::runtime::scheduler::multi_thread::MultiThread>::block_on::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>::{closure#0}
  19:     0x560b26c8b88d - tokio[385202785094474a]::runtime::context::runtime::enter_runtime::<<tokio[385202785094474a]::runtime::scheduler::multi_thread::MultiThread>::block_on<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>::{closure#0}, ()>
  20:     0x560b26bc75ed - <tokio[385202785094474a]::runtime::scheduler::multi_thread::MultiThread>::block_on::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>
  21:     0x560b26c39d3a - <tokio[385202785094474a]::runtime::runtime::Runtime>::block_on_inner::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>
  22:     0x560b26c3a62b - <tokio[385202785094474a]::runtime::runtime::Runtime>::block_on::<core[c0acaeba6ab4c2e0]::pin::Pin<&mut dyn core[c0acaeba6ab4c2e0]::future::future::Future<Output = ()>>>
  23:     0x560b26c78209 - openstack_sdk[213fbd54d4f80503]::test::tests::test_scoped_login_does_not_trigger_redundant_reauth
  24:     0x560b26bb5a93 - openstack_sdk[213fbd54d4f80503]::test::tests::test_scoped_login_does_not_trigger_redundant_reauth::{closure#0}
  25:     0x560b26c37b16 - <openstack_sdk[213fbd54d4f80503]::test::tests::test_scoped_login_does_not_trigger_redundant_reauth::{closure#0} as core[c0acaeba6ab4c2e0]::ops::function::FnOnce<()>>::call_once
  26:     0x560b28c8584b - test[69f9176bb4e5faed]::__rust_begin_short_backtrace::<core[c0acaeba6ab4c2e0]::result::Result<(), alloc[12e961f32105355]::string::String>, fn() -> core[c0acaeba6ab4c2e0]::result::Result<(), alloc[12e961f32105355]::string::String>>
  27:     0x560b28c92e95 - test[69f9176bb4e5faed]::run_test::{closure#0}
  28:     0x560b28c8c844 - std[6c98fd8553dbae28]::sys::backtrace::__rust_begin_short_backtrace::<test[69f9176bb4e5faed]::run_test::{closure#1}, ()>
  29:     0x560b28c95fe2 - <std[6c98fd8553dbae28]::thread::lifecycle::spawn_unchecked<test[69f9176bb4e5faed]::run_test::{closure#1}, ()>::{closure#1} as core[c0acaeba6ab4c2e0]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
  30:     0x560b29d04faf - <std[6c98fd8553dbae28]::sys::thread::unix::Thread>::new::thread_start
  31:     0x7f9447e4ff45 - <unknown>
  32:     0x7f9447ebdd9c - <unknown>
  33:                0x0 - <unknown>


failures:
    test::tests::test_scoped_login_does_not_trigger_redundant_reauth

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

error: test failed, to rerun pass `-p openstack_sdk --lib`

When running tests in v0.13.7, I am not getting any of this...

[gtema]

can't reproduce it, but will definitely look deeper. Those are one of the new things done in 0.13.8 (more the sdk)

[NiklausHofer]

Thanks for looking into it. I've rerun the tests across two separate systems with a number of different Rust versions (1.91.0, 1.94.1, 1.97.1).

I've found that neither of the tests fails consistently. On some runs, I even get both to succeed. Even without recompilation, if I just run the cargo test command in quick succession, the behavior changes some times.

[gtema]

Ah ok, that actually clarifies a lot, in CI and locally I always use nextest (cargo nextest run ...). It properly isolates the tests into subprocesses so that they stop interfering like they do under regular test runner.

[gtema]

@NiklausHofer, if you have a chance, can you pls try to run tests on #1985 I was never able to reproduce reported issues even with 'cargo test', but the PR addresses the most possible cause

[NiklausHofer]

@NiklausHofer, if you have a chance, can you pls try to run tests on #1985 I was never able to reproduce reported issues even with 'cargo test', but the PR addresses the most possible cause

That seems to have done it. I am no longer getting failing tests. Tested across both systems and numerous runs. Thank you :)

[gtema]

Thanks for confirming. Anyway 'cargo nextest' should be preferred and is slightly faster