[INFO] cloning repository https://github.com/exclave/exclave
[INFO] running `Command { std: "git" "-c" "credential.helper=" "-c" "credential.helper=/workspace/cargo-home/bin/git-credential-null" "clone" "--bare" "https://github.com/exclave/exclave" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fexclave%2Fexclave", kill_on_drop: false }`
[INFO] [stderr] Cloning into bare repository '/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fexclave%2Fexclave'...
[INFO] running `Command { std: "git" "rev-parse" "HEAD", kill_on_drop: false }`
[INFO] [stdout] 9220d267dc11d1f9df9425253d1b832420b3afc7
[INFO] testing exclave/exclave against try#28eff87d300677d3acc4d7129d31c74bf885cf6d for pr-94775
[INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fexclave%2Fexclave" "/workspace/builds/worker-20/source", kill_on_drop: false }`
[INFO] [stderr] Cloning into '/workspace/builds/worker-20/source'...
[INFO] [stderr] done.
[INFO] validating manifest of git repo https://github.com/exclave/exclave on toolchain 28eff87d300677d3acc4d7129d31c74bf885cf6d
[INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+28eff87d300677d3acc4d7129d31c74bf885cf6d" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] removed /workspace/builds/worker-20/source/.cargo/config
[INFO] started tweaking git repo https://github.com/exclave/exclave
[INFO] finished tweaking git repo https://github.com/exclave/exclave
[INFO] tweaked toml for git repo https://github.com/exclave/exclave written to /workspace/builds/worker-20/source/Cargo.toml
[INFO] crate git repo https://github.com/exclave/exclave already has a lockfile, it will not be regenerated
[INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+28eff87d300677d3acc4d7129d31c74bf885cf6d" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-20/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-20/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:1ede1414886370302e694df474b9877c02906499f04c196936ce0973d30c5eaa" "/opt/rustwide/cargo-home/bin/cargo" "+28eff87d300677d3acc4d7129d31c74bf885cf6d" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] bfa2233d22154b08e7f8b4a96f87aad9e74c3d0308e40c8965d280d2ba79157c
[INFO] running `Command { std: "docker" "start" "-a" "bfa2233d22154b08e7f8b4a96f87aad9e74c3d0308e40c8965d280d2ba79157c", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "bfa2233d22154b08e7f8b4a96f87aad9e74c3d0308e40c8965d280d2ba79157c", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "bfa2233d22154b08e7f8b4a96f87aad9e74c3d0308e40c8965d280d2ba79157c", kill_on_drop: false }`
[INFO] [stdout] bfa2233d22154b08e7f8b4a96f87aad9e74c3d0308e40c8965d280d2ba79157c
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-20/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-20/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:1ede1414886370302e694df474b9877c02906499f04c196936ce0973d30c5eaa" "/opt/rustwide/cargo-home/bin/cargo" "+28eff87d300677d3acc4d7129d31c74bf885cf6d" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 64d633afb2f1bd77ac13e5be3a2b50bac0a78479a32de88f6f79ae0773cdc831
[INFO] running `Command { std: "docker" "start" "-a" "64d633afb2f1bd77ac13e5be3a2b50bac0a78479a32de88f6f79ae0773cdc831", kill_on_drop: false }`
[INFO] [stderr]    Compiling libc v0.2.43
[INFO] [stderr]    Compiling cfg-if v0.1.6
[INFO] [stderr]    Compiling void v1.0.2
[INFO] [stderr]    Compiling semver-parser v0.7.0
[INFO] [stderr]    Compiling rand_core v0.3.0
[INFO] [stderr]    Compiling winapi-build v0.1.1
[INFO] [stderr]    Compiling scopeguard v0.3.3
[INFO] [stderr]    Compiling proc-macro2 v0.4.20
[INFO] [stderr]    Compiling slab v0.4.1
[INFO] [stderr]    Compiling futures v0.1.25
[INFO] [stderr]    Compiling bitflags v1.0.4
[INFO] [stderr]    Compiling ucd-util v0.1.1
[INFO] [stderr]    Compiling lazycell v1.2.0
[INFO] [stderr]    Compiling byteorder v1.2.7
[INFO] [stderr]    Compiling crossbeam-utils v0.5.0
[INFO] [stderr]    Compiling utf8-ranges v1.0.1
[INFO] [stderr]    Compiling serde v1.0.80
[INFO] [stderr]    Compiling nix v0.11.0
[INFO] [stderr]    Compiling regex v1.0.5
[INFO] [stderr]    Compiling fixedbitset v0.1.9
[INFO] [stderr]    Compiling ryu v0.2.6
[INFO] [stderr]    Compiling winapi v0.2.8
[INFO] [stderr]    Compiling ordermap v0.3.5
[INFO] [stderr]    Compiling same-file v1.0.3
[INFO] [stderr]    Compiling bitflags v0.9.1
[INFO] [stderr]    Compiling either v1.5.0
[INFO] [stderr]    Compiling regex v0.2.11
[INFO] [stderr]    Compiling quick-error v1.2.2
[INFO] [stderr]    Compiling nom v2.2.1
[INFO] [stderr]    Compiling vec_map v0.8.1
[INFO] [stderr]    Compiling itoa v0.4.3
[INFO] [stderr]    Compiling exclave v0.2.6 (/opt/rustwide/workdir)
[INFO] [stderr]    Compiling lazy_static v1.1.0
[INFO] [stderr]    Compiling memchr v2.1.0
[INFO] [stderr]    Compiling log v0.4.6
[INFO] [stderr]    Compiling owning_ref v0.3.3
[INFO] [stderr]    Compiling textwrap v0.10.0
[INFO] [stderr]    Compiling unreachable v1.0.0
[INFO] [stderr]    Compiling regex-syntax v0.6.2
[INFO] [stderr]    Compiling regex-syntax v0.5.6
[INFO] [stderr]    Compiling smallvec v0.6.5
[INFO] [stderr]    Compiling humantime v1.1.1
[INFO] [stderr]    Compiling user32-sys v0.2.0
[INFO] [stderr]    Compiling kernel32-sys v0.2.2
[INFO] [stderr]    Compiling rand_core v0.2.2
[INFO] [stderr]    Compiling itertools v0.5.10
[INFO] [stderr]    Compiling walkdir v2.2.5
[INFO] [stderr]    Compiling lock_api v0.1.4
[INFO] [stderr]    Compiling semver v0.9.0
[INFO] [stderr]    Compiling iovec v0.1.2
[INFO] [stderr]    Compiling rand v0.5.5
[INFO] [stderr]    Compiling net2 v0.2.33
[INFO] [stderr]    Compiling num_cpus v1.8.0
[INFO] [stderr]    Compiling atty v0.2.11
[INFO] [stderr]    Compiling inotify-sys v0.1.3
[INFO] [stderr]    Compiling termios v0.3.1
[INFO] [stderr]    Compiling filetime v0.2.1
[INFO] [stderr]    Compiling nix v0.9.0
[INFO] [stderr]    Compiling clicolors-control v0.2.0
[INFO] [stderr]    Compiling rustc_version v0.2.3
[INFO] [stderr]    Compiling petgraph v0.4.13
[INFO] [stderr]    Compiling bytes v0.4.10
[INFO] [stderr]    Compiling thread_local v0.3.6
[INFO] [stderr]    Compiling clap v2.32.0
[INFO] [stderr]    Compiling systemd-parser v0.1.3
[INFO] [stderr]    Compiling mio v0.6.16
[INFO] [stderr]    Compiling quote v0.6.9
[INFO] [stderr]    Compiling aho-corasick v0.6.8
[INFO] [stderr]    Compiling parking_lot_core v0.3.1
[INFO] [stderr]    Compiling syn v0.15.15
[INFO] [stderr]    Compiling tokio-io v0.1.10
[INFO] [stderr]    Compiling tokio-executor v0.1.5
[INFO] [stderr]    Compiling mio-extras v2.0.5
[INFO] [stderr]    Compiling daggy v0.6.0
[INFO] [stderr]    Compiling runny v1.2.5
[INFO] [stderr]    Compiling ctrlc v3.1.1
[INFO] [stderr]    Compiling serde_json v1.0.32
[INFO] [stderr]    Compiling serde_derive v1.0.80
[INFO] [stderr]    Compiling dependy v0.4.1
[INFO] [stderr]    Compiling parking_lot v0.6.4
[INFO] [stderr]    Compiling tokio-reactor v0.1.6
[INFO] [stderr]    Compiling console v0.6.2
[INFO] [stderr]    Compiling inotify v0.6.1
[INFO] [stderr]    Compiling notify v4.0.6
[INFO] [stdout] warning: unused return value of `std::convert::From::from` that must be used
[INFO] [stdout]    --> src/units/scenario.rs:182:29
[INFO] [stdout]     |
[INFO] [stdout] 182 | ...                   PathBuf::from(wd);
[INFO] [stdout]     |                       ^^^^^^^^^^^^^^^^^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `#[warn(unused_must_use)]` on by default
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: 1 warning emitted
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 58.14s
[INFO] running `Command { std: "docker" "inspect" "64d633afb2f1bd77ac13e5be3a2b50bac0a78479a32de88f6f79ae0773cdc831", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "64d633afb2f1bd77ac13e5be3a2b50bac0a78479a32de88f6f79ae0773cdc831", kill_on_drop: false }`
[INFO] [stdout] 64d633afb2f1bd77ac13e5be3a2b50bac0a78479a32de88f6f79ae0773cdc831
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-20/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-20/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:1ede1414886370302e694df474b9877c02906499f04c196936ce0973d30c5eaa" "/opt/rustwide/cargo-home/bin/cargo" "+28eff87d300677d3acc4d7129d31c74bf885cf6d" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 7c0d10192ced6745193b0c0f920a50de60875715c22b3c3b00bb2805a1c2ca89
[INFO] running `Command { std: "docker" "start" "-a" "7c0d10192ced6745193b0c0f920a50de60875715c22b3c3b00bb2805a1c2ca89", kill_on_drop: false }`
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr]    Compiling exclave v0.2.6 (/opt/rustwide/workdir)
[INFO] [stdout] warning: unused return value of `std::convert::From::from` that must be used
[INFO] [stdout]    --> src/units/scenario.rs:182:29
[INFO] [stdout]     |
[INFO] [stdout] 182 | ...                   PathBuf::from(wd);
[INFO] [stdout]     |                       ^^^^^^^^^^^^^^^^^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `#[warn(unused_must_use)]` on by default
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: 1 warning emitted
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 29.73s
[INFO] [stderr]   Executable unittests src/main.rs (/opt/rustwide/target/debug/deps/exclave-5519d52f6cd64932)
[INFO] running `Command { std: "docker" "inspect" "7c0d10192ced6745193b0c0f920a50de60875715c22b3c3b00bb2805a1c2ca89", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "7c0d10192ced6745193b0c0f920a50de60875715c22b3c3b00bb2805a1c2ca89", kill_on_drop: false }`
[INFO] [stdout] 7c0d10192ced6745193b0c0f920a50de60875715c22b3c3b00bb2805a1c2ca89
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-20/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-20/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:1ede1414886370302e694df474b9877c02906499f04c196936ce0973d30c5eaa" "/opt/rustwide/cargo-home/bin/cargo" "+28eff87d300677d3acc4d7129d31c74bf885cf6d" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] 34a18c2cbe00f449427bd14057274e09fe59de09a6162c493b91f0d3d1cf6d38
[INFO] running `Command { std: "docker" "start" "-a" "34a18c2cbe00f449427bd14057274e09fe59de09a6162c493b91f0d3d1cf6d38", kill_on_drop: false }`
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr] warning: unused return value of `std::convert::From::from` that must be used
[INFO] [stderr]    --> src/units/scenario.rs:182:29
[INFO] [stderr]     |
[INFO] [stderr] 182 | ...                   PathBuf::from(wd);
[INFO] [stderr]     |                       ^^^^^^^^^^^^^^^^^^
[INFO] [stderr]     |
[INFO] [stderr]     = note: `#[warn(unused_must_use)]` on by default
[INFO] [stderr] 
[INFO] [stderr] warning: `exclave` (bin "exclave" test) generated 1 warning
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 1.45s
[INFO] [stderr]      Running unittests src/main.rs (/opt/rustwide/target/debug/deps/exclave-5519d52f6cd64932)
[INFO] [stdout] 
[INFO] [stdout] running 6 tests
[INFO] [stdout] test test::load_dependency ... ok
[INFO] [stdout] test test::basic_scenario ... ok
[INFO] [stdout] test test::test_requires ... FAILED
[INFO] [stdout] test test::scenario_execstop ... ok
[INFO] [stdout] test test::scenario_execstopsuccess ... ok
[INFO] [stdout] test test::scenario_execstopfailure ... ok
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- test::test_requires stdout ----
[INFO] [stdout] Message: Status(UnitStatusEvent { name: UnitName { id: "dependent", kind: Test }, status: Loaded })
[INFO] [stdout] Message: Status(UnitStatusEvent { name: UnitName { id: "master", kind: Test }, status: Loaded })
[INFO] [stdout] Message: Status(UnitStatusEvent { name: UnitName { id: "scenario", kind: Scenario }, status: Loaded })
[INFO] [stdout] Message: RescanRequest
[INFO] [stdout] Message: RescanStart
[INFO] [stdout] Message: Status(UnitStatusEvent { name: UnitName { id: "dependent", kind: Test }, status: Selected })
[INFO] [stdout] Message: Status(UnitStatusEvent { name: UnitName { id: "master", kind: Test }, status: Selected })
[INFO] [stdout] Message: Status(UnitStatusEvent { name: UnitName { id: "scenario", kind: Scenario }, status: Selected })
[INFO] [stdout] Message: RescanFinish
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "scenario", kind: Scenario }, contents: StartScenario(Some(UnitName { id: "scenario", kind: Scenario })) })
[INFO] [stdout] Message: Log(LogEntry { unit: UnitName { id: "scenario", kind: Scenario }, log_type: Info, log_message: "scenario starting", unix_time: 1647140102, unix_time_nsecs: 318340773 })
[INFO] [stdout] Message: Status(UnitStatusEvent { name: UnitName { id: "scenario", kind: Scenario }, status: Active })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "scenario", kind: Scenario }, contents: AdvanceScenario(0) })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "scenario", kind: Scenario }, contents: StartTest(UnitName { id: "dependent", kind: Test }) })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "dependent", kind: Test }, contents: TestStarted })
[INFO] [stdout] Message: Status(UnitStatusEvent { name: UnitName { id: "dependent", kind: Test }, status: Active })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "dependent", kind: Test }, contents: Log("begin-dependent") })
[INFO] [stdout] Message: Log(LogEntry { unit: UnitName { id: "dependent", kind: Test }, log_type: Info, log_message: "begin-dependent", unix_time: 1647140102, unix_time_nsecs: 342801331 })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "dependent", kind: Test }, contents: Log("end-dependent") })
[INFO] [stdout] Message: Log(LogEntry { unit: UnitName { id: "dependent", kind: Test }, log_type: Info, log_message: "end-dependent", unix_time: 1647140102, unix_time_nsecs: 342872761 })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "dependent", kind: Test }, contents: TestFinished(0, "end-dependent") })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "dependent", kind: Test }, contents: AdvanceScenario(0) })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "scenario", kind: Scenario }, contents: StopTest(UnitName { id: "dependent", kind: Test }) })
[INFO] [stdout] Message: Status(UnitStatusEvent { name: UnitName { id: "dependent", kind: Test }, status: DeactivatedSuccessfully("controller requested test stop") })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "scenario", kind: Scenario }, contents: StartTest(UnitName { id: "master", kind: Test }) })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "master", kind: Test }, contents: TestStarted })
[INFO] [stdout] Message: Status(UnitStatusEvent { name: UnitName { id: "master", kind: Test }, status: Active })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "master", kind: Test }, contents: TestFinished(0, "") })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "master", kind: Test }, contents: AdvanceScenario(0) })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "scenario", kind: Scenario }, contents: StopTest(UnitName { id: "master", kind: Test }) })
[INFO] [stdout] Message: Status(UnitStatusEvent { name: UnitName { id: "master", kind: Test }, status: DeactivatedSuccessfully("controller requested test stop") })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "scenario", kind: Scenario }, contents: StopTest(UnitName { id: "dependent", kind: Test }) })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "scenario", kind: Scenario }, contents: StopTest(UnitName { id: "master", kind: Test }) })
[INFO] [stdout] Message: ManagerRequest(ManagerControlMessage { sender: UnitName { id: "scenario", kind: Scenario }, contents: StopTest(UnitName { id: "scenario", kind: Scenario }) })
[INFO] [stdout] Message: Log(LogEntry { unit: UnitName { id: "scenario", kind: Scenario }, log_type: Info, log_message: "scenario ended", unix_time: 1647140102, unix_time_nsecs: 363099339 })
[INFO] [stdout] Message: Status(UnitStatusEvent { name: UnitName { id: "scenario", kind: Scenario }, status: DeactivatedSuccessfully("controller requested test stop") })
[INFO] [stdout] thread 'test::test_requires' panicked at 'unit scenario.scenario deactivated before strings were found (success: controller requested test stop)', src/test.rs:505:25
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x55c8f98f23fc - std::backtrace_rs::backtrace::libunwind::trace::h24899a79947a3581
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5
[INFO] [stdout]    1:     0x55c8f98f23fc - std::backtrace_rs::backtrace::trace_unsynchronized::he41003c4da095493
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
[INFO] [stdout]    2:     0x55c8f98f23fc - std::sys_common::backtrace::_print_fmt::hd99333b051dd1a34
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/sys_common/backtrace.rs:66:5
[INFO] [stdout]    3:     0x55c8f98f23fc - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::hc787bdbb27333705
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/sys_common/backtrace.rs:45:22
[INFO] [stdout]    4:     0x55c8f9915b6c - core::fmt::write::hcbf4c637ea0ffa73
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/core/src/fmt/mod.rs:1190:17
[INFO] [stdout]    5:     0x55c8f98edcf1 - std::io::Write::write_fmt::hc0cb15f223a4d98b
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/io/mod.rs:1655:15
[INFO] [stdout]    6:     0x55c8f98f4155 - std::sys_common::backtrace::_print::h3317bb700e9723d3
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/sys_common/backtrace.rs:48:5
[INFO] [stdout]    7:     0x55c8f98f4155 - std::sys_common::backtrace::print::ha6331dabcf0e0777
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/sys_common/backtrace.rs:35:9
[INFO] [stdout]    8:     0x55c8f98f4155 - std::panicking::default_hook::{{closure}}::h8c69f6668a2c7303
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/panicking.rs:295:22
[INFO] [stdout]    9:     0x55c8f98f3e33 - std::panicking::default_hook::h9114a6ae7f2bfe11
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/panicking.rs:311:9
[INFO] [stdout]   10:     0x55c8f98f46a3 - std::panicking::rust_panic_with_hook::he7eb6b6fb517d694
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/panicking.rs:698:17
[INFO] [stdout]   11:     0x55c8f98f4587 - std::panicking::begin_panic_handler::{{closure}}::h811983c88af2c672
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/panicking.rs:588:13
[INFO] [stdout]   12:     0x55c8f98f28b4 - std::sys_common::backtrace::__rust_end_short_backtrace::h4afde4df00b8fb5c
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/sys_common/backtrace.rs:138:18
[INFO] [stdout]   13:     0x55c8f98f42b9 - rust_begin_unwind
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/panicking.rs:584:5
[INFO] [stdout]   14:     0x55c8f95e08b3 - core::panicking::panic_fmt::h9bba74b2d82f87b0
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/core/src/panicking.rs:143:14
[INFO] [stdout]   15:     0x55c8f96165d0 - exclave::test::test_requires::hdeffaf6f933454c7
[INFO] [stdout]                                at /opt/rustwide/workdir/src/test.rs:505:25
[INFO] [stdout]   16:     0x55c8f9615d7a - exclave::test::test_requires::{{closure}}::hf76405566dd477d7
[INFO] [stdout]                                at /opt/rustwide/workdir/src/test.rs:448:1
[INFO] [stdout]   17:     0x55c8f9603cde - core::ops::function::FnOnce::call_once::hf1f409aabaa67bc5
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/core/src/ops/function.rs:227:5
[INFO] [stdout]   18:     0x55c8f9713763 - core::ops::function::FnOnce::call_once::h7c82417d43deacd4
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/core/src/ops/function.rs:227:5
[INFO] [stdout]   19:     0x55c8f9713763 - test::__rust_begin_short_backtrace::h4db1f83eaaa59dd5
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/test/src/lib.rs:575:5
[INFO] [stdout]   20:     0x55c8f9712496 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h63d171b312d4fa47
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/alloc/src/boxed.rs:1854:9
[INFO] [stdout]   21:     0x55c8f9712496 - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h00197ed0537faf7a
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/core/src/panic/unwind_safe.rs:271:9
[INFO] [stdout]   22:     0x55c8f9712496 - std::panicking::try::do_call::h86332069d38d2744
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/panicking.rs:492:40
[INFO] [stdout]   23:     0x55c8f9712496 - std::panicking::try::h1f6ae9e296714b32
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/panicking.rs:456:19
[INFO] [stdout]   24:     0x55c8f9712496 - std::panic::catch_unwind::ha8e34042702c40f8
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/panic.rs:137:14
[INFO] [stdout]   25:     0x55c8f9712496 - test::run_test_in_process::hd493285879569b21
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/test/src/lib.rs:598:18
[INFO] [stdout]   26:     0x55c8f9712496 - test::run_test::run_test_inner::{{closure}}::hf19abbbb55852552
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/test/src/lib.rs:492:39
[INFO] [stdout]   27:     0x55c8f96dee3e - test::run_test::run_test_inner::{{closure}}::h7e3c2c343e147543
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/test/src/lib.rs:519:37
[INFO] [stdout]   28:     0x55c8f96dee3e - std::sys_common::backtrace::__rust_begin_short_backtrace::h4c402e6f80a12404
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/sys_common/backtrace.rs:122:18
[INFO] [stdout]   29:     0x55c8f96e4258 - std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}::h1d78d90ebcef4dc4
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/thread/mod.rs:498:17
[INFO] [stdout]   30:     0x55c8f96e4258 - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::hf6925ff7eaaf6137
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/core/src/panic/unwind_safe.rs:271:9
[INFO] [stdout]   31:     0x55c8f96e4258 - std::panicking::try::do_call::hc5e80b04a1842b4a
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/panicking.rs:492:40
[INFO] [stdout]   32:     0x55c8f96e4258 - std::panicking::try::h9d62e0cac0ea03e6
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/panicking.rs:456:19
[INFO] [stdout]   33:     0x55c8f96e4258 - std::panic::catch_unwind::heb8ac09f2b83c104
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/panic.rs:137:14
[INFO] [stdout]   34:     0x55c8f96e4258 - std::thread::Builder::spawn_unchecked_::{{closure}}::h9f6e6e505ad142aa
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/thread/mod.rs:497:30
[INFO] [stdout]   35:     0x55c8f96e4258 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h3c78246b8eee677a
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/core/src/ops/function.rs:227:5
[INFO] [stdout]   36:     0x55c8f98f9153 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::hca2e57b0f33df4ea
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/alloc/src/boxed.rs:1854:9
[INFO] [stdout]   37:     0x55c8f98f9153 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h3c7322d65af8c247
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/alloc/src/boxed.rs:1854:9
[INFO] [stdout]   38:     0x55c8f98f9153 - std::sys::unix::thread::Thread::new::thread_start::h8691f5e7943f3a56
[INFO] [stdout]                                at /rustc/28eff87d300677d3acc4d7129d31c74bf885cf6d/library/std/src/sys/unix/thread.rs:108:17
[INFO] [stdout]   39:     0x7fda1f066609 - start_thread
[INFO] [stdout]   40:     0x7fda1f1ca163 - clone
[INFO] [stdout]   41:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     test::test_requires
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 5 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.16s
[INFO] [stdout] 
[INFO] [stderr] error: test failed, to rerun pass '--bin exclave'
[INFO] running `Command { std: "docker" "inspect" "34a18c2cbe00f449427bd14057274e09fe59de09a6162c493b91f0d3d1cf6d38", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "34a18c2cbe00f449427bd14057274e09fe59de09a6162c493b91f0d3d1cf6d38", kill_on_drop: false }`
[INFO] [stdout] 34a18c2cbe00f449427bd14057274e09fe59de09a6162c493b91f0d3d1cf6d38