utils
utils copied to clipboard
zeroize: `tests::zeroize_c_string` fails on i386
Hi,
while testing zeroize on Debian infrastructure one test fails (it does not fail on other architectures).
---- tests::zeroize_c_string stdout ----
thread 'tests::zeroize_c_string' panicked at 'assertion failed: `(left == right)`
left: `21`,
right: `0`', src/lib.rs:936:17
stack backtrace:
0: rust_begin_unwind
at /usr/src/rustc-1.58.1/library/std/src/panicking.rs:498:5
1: core::panicking::panic_fmt
at /usr/src/rustc-1.58.1/library/core/src/panicking.rs:107:14
2: core::panicking::assert_failed_inner
3: core::panicking::assert_failed
at /usr/src/rustc-1.58.1/library/core/src/panicking.rs:145:5
4: zeroize::tests::zeroize_c_string
at ./src/lib.rs:936:17
5: zeroize::tests::zeroize_c_string::{{closure}}
at ./src/lib.rs:922:5
6: core::ops::function::FnOnce::call_once
at /usr/src/rustc-1.58.1/library/core/src/ops/function.rs:227:5
7: core::ops::function::FnOnce::call_once
at /usr/src/rustc-1.58.1/library/core/src/ops/function.rs:227:5
Please find the full log at https://ci.debian.net/data/autopkgtest/testing/i386/r/rust-zeroize/22485575/log.gz
Any hints how to debug this?
It's possible this is a legitimate bug in the implementation. The functionality was recently added (#650) so it's relatively new. Is it sporadic or reproducible?
I would suggest adding some more assertions to the tests (e.g. is the original pointer changing?) to try to isolate the cause.
cc @robinhundt who authored #650
From what I see the failure is reproducible - I just triggered a re-test, so we will know soon. As those builds are only done on Debian package upload it's not easily possible to debug it directly on this infrastructure ... but I think I could try the build/tests locally in a i386 qemu chroot if neede.
Yes, it's reproducible, see https://ci.debian.net/packages/r/rust-zeroize/testing/i386/
That's good news. I'd suggest adding some more instrumentation (and possibly some dbg!
statements) around the tests and see if we can observe anything unusual happening during those tests failures.
Yes, I think adding assert_eq!(cstring.as_bytes().as_ptr(), orig_ptr);
after the call to cstring.zeroize();
would be a good idea. The backing Vec
of the CString
should not reallocate, but if that were the case, it might explain the failing test.
Another possibility is that the test case might contain UB and could be compiled to something unexpected for this target.
I also noticed that the tests are apparently run on a i386 CPU, but are compiled for the i686-unknown-linux-gnu
target. Is this intended?
I'll try - although, I'm not very fluent in Rust ... In Debian "i386" is the name of the x86 architecture, it now requires a i686 processor - so everything fine on this end.
Running the test in a i386 chroot gave me this:
$ cargo --version
cargo 1.56.0
$ RUST_BACKTRACE=full cargo test --all-features
[...]
---- zeroize_c_string stdout ----
thread 'zeroize_c_string' panicked at 'assertion failed: `(left == right)`
left: `21`,
right: `0`', zeroize/tests/zeroize.rs:185:13
stack backtrace:
0: 0x56625ab2 - std::backtrace_rs::backtrace::libunwind::trace::h320b03954b13b15a
at /usr/src/rustc-1.59.0/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5
1: 0x56625ab2 - std::backtrace_rs::backtrace::trace_unsynchronized::h404aa66a58afcce7
at /usr/src/rustc-1.59.0/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
2: 0x56625ab2 - std::sys_common::backtrace::_print_fmt::h1f0df45566fa763e
at /usr/src/rustc-1.59.0/library/std/src/sys_common/backtrace.rs:67:5
3: 0x56625ab2 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h49d2d68a197f5d73
at /usr/src/rustc-1.59.0/library/std/src/sys_common/backtrace.rs:46:22
4: 0x566598d0 - core::fmt::write::h63f14257cbd95381
at /usr/src/rustc-1.59.0/library/core/src/fmt/mod.rs:1168:17
5: 0x566442f5 - std::io::Write::write_fmt::h4c50e7f4adc5804d
at /usr/src/rustc-1.59.0/library/std/src/io/mod.rs:1660:15
6: 0x5661d9c4 - std::sys_common::backtrace::_print::h5da1337f2a7da169
at /usr/src/rustc-1.59.0/library/std/src/sys_common/backtrace.rs:49:5
7: 0x5661d9c4 - std::sys_common::backtrace::print::h2bb484354b6366ac
at /usr/src/rustc-1.59.0/library/std/src/sys_common/backtrace.rs:36:9
8: 0x5661d9c4 - std::panicking::default_hook::{{closure}}::h60e5a8b70fb4684b
at /usr/src/rustc-1.59.0/library/std/src/panicking.rs:211:50
9: 0x5661d5b8 - std::panicking::default_hook::hcb0fdf578cad4af3
at /usr/src/rustc-1.59.0/library/std/src/panicking.rs:225:9
10: 0x5661df89 - std::panicking::rust_panic_with_hook::h173ed85a59f13a7c
at /usr/src/rustc-1.59.0/library/std/src/panicking.rs:606:17
11: 0x5662631f - std::panicking::begin_panic_handler::{{closure}}::h14739303386c4688
at /usr/src/rustc-1.59.0/library/std/src/panicking.rs:502:13
12: 0x56625bf4 - std::sys_common::backtrace::__rust_end_short_backtrace::hb6737ae7810b94dc
at /usr/src/rustc-1.59.0/library/std/src/sys_common/backtrace.rs:139:18
13: 0x5661daae - rust_begin_unwind
at /usr/src/rustc-1.59.0/library/std/src/panicking.rs:498:5
14: 0x565bf180 - core::panicking::panic_fmt::h91489b75f712f7b5
at /usr/src/rustc-1.59.0/library/core/src/panicking.rs:116:14
15: 0x56654e5b - core::panicking::assert_failed_inner::h704e9e2e15fcef63
16: 0x565cd47e - core::panicking::assert_failed::hd2ec6f0b6772109c
at /usr/src/rustc-1.59.0/library/core/src/panicking.rs:154:5
17: 0x565c3e80 - zeroize::zeroize_c_string::h8dc7aeaf9dbd0fc1
at /utils/zeroize/tests/zeroize.rs:185:13
18: 0x565c3b2d - zeroize::zeroize_c_string::{{closure}}::h46dde2f2e42da98e
at /utils/zeroize/tests/zeroize.rs:171:1
19: 0x565cbbd1 - core::ops::function::FnOnce::call_once::hb28f778e64bc144e
at /usr/src/rustc-1.59.0/library/core/src/ops/function.rs:227:5
20: 0x565d9852 - core::ops::function::FnOnce::call_once::h0572bae84892651f
at /usr/src/rustc-1.59.0/library/core/src/ops/function.rs:227:5
21: 0x565d9852 - test::__rust_begin_short_backtrace::hd837b0aa16a9c015
at /usr/src/rustc-1.59.0/library/test/src/lib.rs:574:5
22: 0x565d99bc - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h2e1dce8498d803b9
at /usr/src/rustc-1.59.0/library/alloc/src/boxed.rs:1854:9
23: 0x565d99bc - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::hdf395b25b3e5c7c5
at /usr/src/rustc-1.59.0/library/core/src/panic/unwind_safe.rs:271:9
24: 0x565d99bc - std::panicking::try::do_call::h16369fe0180352cd
at /usr/src/rustc-1.59.0/library/std/src/panicking.rs:406:40
25: 0x565d99bc - std::panicking::try::h25f3cabb7fe2415f
at /usr/src/rustc-1.59.0/library/std/src/panicking.rs:370:19
26: 0x565d99bc - std::panic::catch_unwind::hdb361248efc98a79
at /usr/src/rustc-1.59.0/library/std/src/panic.rs:133:14
27: 0x565d99bc - test::run_test_in_process::hdd8fd07504e529c0
at /usr/src/rustc-1.59.0/library/test/src/lib.rs:597:18
28: 0x565fd645 - test::run_test::run_test_inner::{{closure}}::ha9ae95d07ec41dcc
at /usr/src/rustc-1.59.0/library/test/src/lib.rs:491:39
29: 0x565fd645 - test::run_test::run_test_inner::{{closure}}::h489e29cbdff688d7
at /usr/src/rustc-1.59.0/library/test/src/lib.rs:518:37
30: 0x565fd645 - std::sys_common::backtrace::__rust_begin_short_backtrace::h7a7291046fe7c276
at /usr/src/rustc-1.59.0/library/std/src/sys_common/backtrace.rs:123:18
31: 0x565fabb8 - std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}}::h8e62180684017b8d
at /usr/src/rustc-1.59.0/library/std/src/thread/mod.rs:477:17
32: 0x565fabb8 - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h020046288dede4ff
at /usr/src/rustc-1.59.0/library/core/src/panic/unwind_safe.rs:271:9
33: 0x565fabb8 - std::panicking::try::do_call::h4a6d763b94410ce3
at /usr/src/rustc-1.59.0/library/std/src/panicking.rs:406:40
34: 0x565fabb8 - std::panicking::try::h7354ccdf46ae868d
at /usr/src/rustc-1.59.0/library/std/src/panicking.rs:370:19
35: 0x565fabb8 - std::panic::catch_unwind::h28c94783f93fbaa6
at /usr/src/rustc-1.59.0/library/std/src/panic.rs:133:14
36: 0x565fabb8 - std::thread::Builder::spawn_unchecked::{{closure}}::h51797d227a32d022
at /usr/src/rustc-1.59.0/library/std/src/thread/mod.rs:476:30
37: 0x565fabb8 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h7a30731d70d141de
at /usr/src/rustc-1.59.0/library/core/src/ops/function.rs:227:5
38: 0x5661560b - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h764764ad3dc9b175
at /usr/src/rustc-1.59.0/library/alloc/src/boxed.rs:1854:9
39: 0x5661560b - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h5b9c09009d2e3828
at /usr/src/rustc-1.59.0/library/alloc/src/boxed.rs:1854:9
40: 0x5661560b - std::sys::unix::thread::Thread::new::thread_start::heb638986cd3951cc
at /usr/src/rustc-1.59.0/library/std/src/sys/unix/thread.rs:108:17
41: 0xf7f47e6c - start_thread
42: 0xf7d43606 - clone
43: 0x0 - <unknown>
Adding assert_eq!(cstring.as_bytes().as_ptr(), orig_ptr);
doesn't change anything, it fails some lines further down https://github.com/RustCrypto/utils/blob/master/zeroize/tests/zeroize.rs#L185
FWIW I noticed we didn't have zeroize
CI for 32-bit targets, although after adding it, it passed on an Ubuntu image:
https://github.com/RustCrypto/utils/pull/775
@innir if you have a QEMU recipe for reproducing it, can you post it and I can try to run it locally?
Hm, most obvious difference is, I'm testing with --all-features
and with rustc
1.59.0 ...
You can reproduce my chroot by this:
sudo mmdebstrap --arch=i386 --include=dh-cargo,git sid chroot-i386
sudo systemd-nspawn -D chroot-i386 git clone https://github.com/RustCrypto/utils.git
sudo systemd-nspawn --chdir /utils/zeroize -E RUST_BACKTRACE=full -D chroot-i386 cargo test --all-features
@tarcieri Did you had any chance to reproduce the test failure?
Not as yet, unfortunately
Perhaps for now we can mark the test with #[ignore]
.
I've released zeroize
v1.5.6 which adds #[ignore]
to the flaky test.
However, I'm going to leave this issue open to track the test failure and whatever potential issues it may or may not be revealing
Mid to end of July, I'll have time to look at this at this issue as well, if it's not resolved until then.