[INFO] fetching crate alioth 0.12.0...
[INFO] testing alioth-0.12.0 against 1.99.0-beta.1+cargoflags=--release for beta-release-1.99-2
[INFO] extracting crate alioth 0.12.0 into /workspace/builds/worker-2-tc2/source
[INFO] started tweaking crates.io crate alioth 0.12.0
[INFO] finished tweaking crates.io crate alioth 0.12.0
[INFO] tweaked toml for crates.io crate alioth 0.12.0 written to /workspace/builds/worker-2-tc2/source/Cargo.toml
[INFO] validating manifest of crates.io crate alioth 0.12.0 on toolchain 1.99.0-beta.1
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.99.0-beta.1" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate alioth 0.12.0 already has a lockfile, it will not be regenerated
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.99.0-beta.1" "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-2-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-2-tc2/target:/opt/rustwide/target:rw,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" "-m" "1610612736" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:8683fc1fc2eb5c9ac98e0d076ab094b2ffac7f99da555d2b6a2e27f346de2ec7" "sleep" "infinity", kill_on_drop: false }`
[INFO] [stdout] 0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8
[INFO] running `Command { std: "docker" "start" "0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-w" "/opt/rustwide/workdir" "--user" "0:0" "0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.1" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.1" "build" "--frozen" "--message-format=json" "--release", kill_on_drop: false }`
[INFO] [stderr]    Compiling proc-macro2 v1.0.106
[INFO] [stderr]    Compiling unicode-ident v1.0.22
[INFO] [stderr]    Compiling quote v1.0.44
[INFO] [stderr]    Compiling libc v0.2.182
[INFO] [stderr]    Compiling serde_core v1.0.228
[INFO] [stderr]    Compiling parking_lot_core v0.9.12
[INFO] [stderr]    Compiling cfg-if v1.0.4
[INFO] [stderr]    Compiling serde v1.0.228
[INFO] [stderr]    Compiling io-uring v0.7.11
[INFO] [stderr]    Compiling smallvec v1.15.1
[INFO] [stderr]    Compiling heck v0.5.0
[INFO] [stderr]    Compiling zerocopy v0.8.40
[INFO] [stderr]    Compiling iana-time-zone v0.1.64
[INFO] [stderr]    Compiling bitflags v2.11.0
[INFO] [stderr]    Compiling lock_api v0.4.14
[INFO] [stderr]    Compiling log v0.4.29
[INFO] [stderr]    Compiling chrono v0.4.44
[INFO] [stderr]    Compiling syn v2.0.117
[INFO] [stderr]    Compiling mio v1.1.1
[INFO] [stderr]    Compiling parking_lot v0.12.5
[INFO] [stderr]    Compiling serde_derive v1.0.228
[INFO] [stderr]    Compiling serde-aco-derive v0.12.0
[INFO] [stderr]    Compiling snafu-derive v0.8.9
[INFO] [stderr]    Compiling zerocopy-derive v0.8.40
[INFO] [stderr]    Compiling bitfield-macros v0.19.4
[INFO] [stderr]    Compiling alioth-macros v0.12.0
[INFO] [stderr]    Compiling bitfield v0.19.4
[INFO] [stderr]    Compiling snafu v0.8.9
[INFO] [stderr]    Compiling serde-aco v0.12.0
[INFO] [stderr]    Compiling alioth v0.12.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 42.54s
[INFO] running `Command { std: "docker" "inspect" "0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.1" "test" "--frozen" "--no-run" "--message-format=json" "--release", kill_on_drop: false }`
[INFO] [stderr]    Compiling syn v2.0.117
[INFO] [stderr]    Compiling winnow v0.7.14
[INFO] [stderr]    Compiling hashbrown v0.16.1
[INFO] [stderr]    Compiling equivalent v1.0.2
[INFO] [stderr]    Compiling memchr v2.7.6
[INFO] [stderr]    Compiling semver v1.0.27
[INFO] [stderr]    Compiling regex-syntax v0.8.8
[INFO] [stderr]    Compiling toml_datetime v0.7.5+spec-1.1.0
[INFO] [stderr]    Compiling bitflags v2.11.0
[INFO] [stderr]    Compiling getrandom v0.3.4
[INFO] [stderr]    Compiling thiserror v2.0.17
[INFO] [stderr]    Compiling log v0.4.29
[INFO] [stderr]    Compiling rustix v1.1.3
[INFO] [stderr]    Compiling relative-path v1.9.3
[INFO] [stderr]    Compiling dtor-proc-macro v0.0.6
[INFO] [stderr]    Compiling pin-utils v0.1.0
[INFO] [stderr]    Compiling glob v0.3.3
[INFO] [stderr]    Compiling pin-project-lite v0.2.16
[INFO] [stderr]    Compiling futures-core v0.3.31
[INFO] [stderr]    Compiling cfg-if v1.0.4
[INFO] [stderr]    Compiling futures-task v0.3.31
[INFO] [stderr]    Compiling slab v0.4.11
[INFO] [stderr]    Compiling rustc_version v0.4.1
[INFO] [stderr]    Compiling linux-raw-sys v0.11.0
[INFO] [stderr]    Compiling dtor v0.1.1
[INFO] [stderr]    Compiling mio v1.1.1
[INFO] [stderr]    Compiling io-uring v0.7.11
[INFO] [stderr]    Compiling futures-timer v3.0.3
[INFO] [stderr]    Compiling ctor-proc-macro v0.0.7
[INFO] [stderr]    Compiling once_cell v1.21.3
[INFO] [stderr]    Compiling fastrand v2.3.0
[INFO] [stderr]    Compiling nu-ansi-term v0.50.3
[INFO] [stderr]    Compiling rstest_macros v0.26.1
[INFO] [stderr]    Compiling ctor v0.6.3
[INFO] [stderr]    Compiling assert_matches v1.5.0
[INFO] [stderr]    Compiling aho-corasick v1.1.4
[INFO] [stderr]    Compiling indexmap v2.12.1
[INFO] [stderr]    Compiling regex-automata v0.4.13
[INFO] [stderr]    Compiling toml_parser v1.0.6+spec-1.1.0
[INFO] [stderr]    Compiling toml_edit v0.23.10+spec-1.0.0
[INFO] [stderr]    Compiling tempfile v3.25.0
[INFO] [stderr]    Compiling proc-macro-crate v3.4.0
[INFO] [stderr]    Compiling serde_derive v1.0.228
[INFO] [stderr]    Compiling thiserror-impl v2.0.17
[INFO] [stderr]    Compiling serde-aco-derive v0.12.0
[INFO] [stderr]    Compiling snafu-derive v0.8.9
[INFO] [stderr]    Compiling futures-macro v0.3.31
[INFO] [stderr]    Compiling bitfield-macros v0.19.4
[INFO] [stderr]    Compiling zerocopy-derive v0.8.40
[INFO] [stderr]    Compiling alioth-macros v0.12.0
[INFO] [stderr]    Compiling regex v1.12.2
[INFO] [stderr]    Compiling futures-util v0.3.31
[INFO] [stderr]    Compiling bitfield v0.19.4
[INFO] [stderr]    Compiling zerocopy v0.8.40
[INFO] [stderr]    Compiling snafu v0.8.9
[INFO] [stderr]    Compiling serde v1.0.228
[INFO] [stderr]    Compiling flexi_logger v0.31.8
[INFO] [stderr]    Compiling serde-aco v0.12.0
[INFO] [stderr]    Compiling rstest v0.26.1
[INFO] [stderr]    Compiling alioth v0.12.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 1m 23s
[INFO] running `Command { std: "docker" "inspect" "0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.1" "test" "--frozen" "--release", kill_on_drop: false }`
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 0.13s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/release/deps/alioth-66a7b0a5b8b7b37d)
[INFO] [stdout] 
[INFO] [stdout] running 228 tests
[INFO] [stdout] test blk::qcow2::tests::test_cmpr_desc_offset_size::case_2 ... ok
[INFO] [stdout] test blk::qcow2::tests::test_l1entry_l2_offset::case_1 ... ok
[INFO] [stdout] test blk::qcow2::tests::test_cmpr_desc_offset_size::case_1 ... ok
[INFO] [stdout] test board::tests::test_cpu_topology_encode_decode::case_1 ... ok
[INFO] [stdout] test board::tests::test_cpu_topology_encode_decode::case_3 ... ok
[INFO] [stdout] test board::tests::test_cpu_topology_encode_decode::case_4 ... ok
[INFO] [stdout] test blk::qcow2::tests::test_std_desc_cluster_offset::case_1 ... ok
[INFO] [stdout] test board::tests::test_cpu_topology_encode_decode::case_2 ... ok
[INFO] [stdout] test board::tests::test_cpu_topology_encode_decode::case_6 ... ok
[INFO] [stdout] test board::tests::test_cpu_topology_encode_decode::case_7 ... ok
[INFO] [stdout] test board::tests::test_cpu_topology_encode_decode::case_8 ... ok
[INFO] [stdout] test board::tests::test_cpu_topology_encode_decode::case_5 ... ok
[INFO] [stdout] test board::tests::test_cpu_topology_encode_decode::case_9 ... ok
[INFO] [stdout] test board::tests::test_cpu_topology_fixup ... ok
[INFO] [stdout] test board::x86_64::tests::test_encode_x2apic::case_2 ... ok
[INFO] [stdout] test board::x86_64::tests::test_encode_x2apic::case_1 ... ok
[INFO] [stdout] test board::x86_64::tests::test_encode_x2apic::case_3 ... ok
[INFO] [stdout] test board::x86_64::tests::test_encode_x2apic::case_6 ... ok
[INFO] [stdout] test board::x86_64::tests::test_encode_x2apic::case_7 ... ok
[INFO] [stdout] test board::x86_64::tests::test_encode_x2apic::case_8 ... ok
[INFO] [stdout] test board::x86_64::tests::test_encode_x2apic::case_9 ... ok
[INFO] [stdout] test board::x86_64::tests::test_encode_x2apic::case_5 ... ok
[INFO] [stdout] test board::x86_64::tests::test_encode_x2apic::case_4 ... ok
[INFO] [stdout] test device::clock::tests::test_system_clock ... ok
[INFO] [stdout] test device::cmos::tests::test_cmos ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_access::case_02 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_access::case_03 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_access::case_04 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_access::case_06 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_access::case_07 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_access::case_09 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_access::case_10 ... ok
[INFO] [stdout] test device::cmos::tests::test_cmos_upgrade_in_progress ... ok
[INFO] [stdout] test device::fw_cfg::acpi::tests::test_size ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_read::case_2 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_read::case_1 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_file_access ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_read::case_3 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_size::case_3 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_file_size ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_size::case_4 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_size::case_5 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_size::case_6 ... ok
[INFO] [stdout] test device::net::tests::test_mac_addr_visitor ... ok
[INFO] [stdout] test firmware::dt::dtb::tests::test_prop_val_write_as_blob::case_01 ... ok
[INFO] [stdout] test firmware::acpi::bindings::tests::test_size ... ok
[INFO] [stdout] test firmware::dt::dtb::tests::test_prop_val_write_as_blob::case_03 ... ok
[INFO] [stdout] test firmware::dt::dtb::tests::test_prop_val_write_as_blob::case_04 ... ok
[INFO] [stdout] test firmware::dt::dtb::tests::test_prop_val_write_as_blob::case_05 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_access::case_05 ... ok
[INFO] [stdout] test device::ioapic::tests::test_ioapic_read_write ... ok
[INFO] [stdout] test firmware::dt::dtb::tests::test_prop_val_write_as_blob::case_06 ... ok
[INFO] [stdout] test device::ioapic::tests::test_ioapic_service_pin ... ok
[INFO] [stdout] test firmware::dt::dtb::tests::test_prop_val_write_as_blob::case_07 ... ok
[INFO] [stdout] test firmware::acpi::reg::tests::test_pm_timer ... FAILED
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_access::case_01 ... ok
[INFO] [stdout] test hv::kvm::vcpu::x86_64::tests::test_kvm_run ... ignored
[INFO] [stdout] test hv::kvm::vcpu::x86_64::tests::test_vcpu_regs ... ignored
[INFO] [stdout] test hv::kvm::vm::tests::test_mem_map ... ignored
[INFO] [stderr] ERROR [alioth::device::fw_cfg] fw_cfg: reading File { fd: 3, path: "/tmp/.tmpACfdKI/test_file (deleted)", read: true, write: false }: Error { kind: UnexpectedEof, message: "failed to fill whole buffer" }
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_file_read ... ok
[INFO] [stdout] test firmware::dt::dtb::tests::test_prop_val_write_as_blob::case_08 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_read::case_4 ... ok
[INFO] [stdout] test firmware::dt::dtb::tests::test_prop_val_write_as_blob::case_02 ... ok
[INFO] [stdout] test hv::kvm::vm::x86_64::test::test_determine_vm_type::case_3 ... ok
[INFO] [stdout] test hv::kvm::vm::x86_64::test::test_determine_vm_type::case_4 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_read::case_5 ... ok
[INFO] [stdout] test hv::kvm::vm::x86_64::test::test_translate_msi_addr::case_1 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_read::case_6 ... ok
[INFO] [stdout] test hv::kvm::vm::x86_64::test::test_translate_msi_addr::case_3 ... ok
[INFO] [stdout] test hv::kvm::vm::x86_64::test::test_translate_msi_addr::case_4 ... ok
[INFO] [stdout] test hv::kvm::vm::x86_64::test::test_translate_msi_addr::case_5 ... ok
[INFO] [stdout] test hv::kvm::x86_64::tests::test_convert_cpuid_entry::case_1 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_size::case_1 ... ok
[INFO] [stdout] test firmware::dt::dtb::tests::test_prop_val_write_as_blob::case_09 ... ok
[INFO] [stdout] test hv::kvm::x86_64::tests::test_get_supported_cpuid ... ignored
[INFO] [stdout] test hv::kvm::x86_64::tests::test_convert_cpuid_entry::case_2 ... ok
[INFO] [stdout] test firmware::dt::dtb::tests::test_prop_val_write_as_blob::case_10 ... ok
[INFO] [stdout] test loader::elf::tests::test_size ... ok
[INFO] [stdout] test mem::addressable::tests::test_addressable ... ok
[INFO] [stdout] test loader::xen::start_info::tests::test_size ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_04 ... ok
[INFO] [stdout] test hv::kvm::vm::x86_64::test::test_determine_vm_type::case_1 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_05 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_03 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_06 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_08 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_07 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_12 ... ok
[INFO] [stdout] test firmware::dt::dtb::tests::test_string_block ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_14 ... ok
[INFO] [stdout] test hv::kvm::vm::x86_64::test::test_determine_vm_type::case_2 ... ok
[INFO] [stdout] test firmware::dt::tests::test_val_size ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_09 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_15 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_16 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_size::case_2 ... ok
[INFO] [stdout] test firmware::ovmf::x86_64::tdx::tests::test_create_hob ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_10 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_11 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_17 ... ok
[INFO] [stdout] test device::fw_cfg::tests::test_fw_cfg_content_access::case_08 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_02 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_03 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_08 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_01 ... ok
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c3f80000, 1000) = 0, done
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_09 ... ok
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c3f7f000, 1000) = 0, done
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_11 ... ok
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: updating bar 0: 0x0000000c -> 0xec00000c, mask=0xfffff000
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_12 ... ok
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: bar 0: write 0xec000000, update: 0x0000000c -> 0xec00000c
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_10 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_13 ... ok
[INFO] [stdout] test pci::bus::tests::test_host_bridge ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_02 ... ok
[INFO] [stdout] test mem::mapped::tests::test_ram_bus_read ... ok
[INFO] [stderr] ERROR [alioth::pci::cap] MsiCapMmio: write 0xaabbccdd to invalid offset 0xc.
[INFO] [stdout] test pci::bus::tests::test_pci_io_bus ... ok
[INFO] [stdout] test pci::bus::tests::test_pci_io_bus_unaligned_address_access ... ok
[INFO] [stdout] test mem::addressable::tests::test_new_slot ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_05 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_13 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_06 ... ok
[INFO] [stdout] test hv::kvm::vm::x86_64::test::test_translate_msi_addr::case_2 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_read::case_01 ... ok
[INFO] [stdout] test pci::bus::tests::test_pci_bus ... ok
[INFO] [stdout] test pci::bus::tests::test_pci_io_bus_disabled_address ... ok
[INFO] [stdout] test pci::cap::tests::test_msi_cap_mmio_64_pvm ... ok
[INFO] [stderr] ERROR [alioth::pci::cap] unaligned access to msix table: size = 2, offset = 0x0
[INFO] [stderr] ERROR [alioth::pci::cap] unaligned access to msix table: size = 2, offset = 0x0
[INFO] [stderr] ERROR [alioth::pci::cap] unaligned access to msix table: size = 4, offset = 0xe
[INFO] [stderr] ERROR [alioth::pci::cap] unaligned access to msix table: size = 4, offset = 0x12
[INFO] [stderr] ERROR [alioth::pci::cap] MSI-X table size: 2, accessing index 2
[INFO] [stderr] ERROR [alioth::pci::cap] MSI-X table size: 2, accessing index 2
[INFO] [stderr] INFO [alioth::pci::config] 00:01.0: updating bar 5: 0x0000e001 -> 0x0000c001, mask=0xfffffffc
[INFO] [stderr] INFO [alioth::pci::config] 00:01.0: bar 5: write 0x0000c000, update: 0x0000e001 -> 0x0000c001
[INFO] [stderr] INFO [alioth::pci::config] 00:01.0: updating bar 5: 0x0000e001 -> 0x0000f001, mask=0xfffffffc
[INFO] [stderr] INFO [alioth::pci::config] 00:01.0: updating bar 0: 0xe0000000 -> 0xfffff000, mask=0xfffff000
[INFO] [stderr] INFO [alioth::pci::config] 00:01.0: bar 0: write 0xffffffff, update: 0xe0000000 -> 0xfffff000
[INFO] [stderr] INFO [alioth::pci::config] 00:01.0: updating bar 0: 0xe0000000 -> 0xd0000000, mask=0xfffff000
[INFO] [stderr] INFO [alioth::pci::config] 00:01.0: updating bar 3: 0x00000001 -> 0x00000002, mask=0xffffffff
[INFO] [stderr] INFO [alioth::pci::config] 00:01.0: updating bar 2: 0x00000004 -> 0x80000004, mask=0xc0000000
[INFO] [stdout] test pci::cap::tests::test_msi_msg_ctrl_cap_size::case_1 ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_07 ... ok
[INFO] [stdout] test pci::cap::tests::test_msi_cap_mmio_32 ... ok
[INFO] [stdout] test pci::cap::tests::test_msi_cap_mmio_32_pvm ... ok
[INFO] [stdout] test mem::emulated::tests::test_mmio_bus_write::case_04 ... ok
[INFO] [stdout] test pci::cap::tests::test_msi_msg_ctrl_cap_size::case_2 ... ok
[INFO] [stdout] test pci::cap::tests::test_msi_msg_ctrl_cap_size::case_3 ... ok
[INFO] [stdout] test pci::cap::tests::test_msi_msg_ctrl_cap_size::case_4 ... ok
[INFO] [stdout] test pci::cap::tests::test_msix_cap_mmio ... ok
[INFO] [stdout] test pci::cap::tests::test_msix_msg_ctrl::case_1 ... ok
[INFO] [stdout] test pci::cap::tests::test_msix_msg_ctrl::case_2 ... ok
[INFO] [stdout] test pci::cap::tests::test_msix_table_mmio ... ok
[INFO] [stdout] test pci::cap::tests::test_null_cap::case_2 ... ok
[INFO] [stdout] test pci::cap::tests::test_null_cap::case_3 ... ok
[INFO] [stdout] test pci::cap::tests::test_null_cap::case_4 ... ok
[INFO] [stdout] test pci::cap::tests::test_null_cap::case_1 ... ok
[INFO] [stdout] test pci::cap::tests::test_null_cap::case_5 ... ok
[INFO] [stdout] test pci::cap::tests::test_null_cap::case_6 ... ok
[INFO] [stdout] test pci::cap::tests::test_null_cap::case_7 ... ok
[INFO] [stdout] test pci::cap::tests::test_null_cap::case_8 ... ok
[INFO] [stdout] test pci::cap::tests::test_null_cap::case_9 ... ok
[INFO] [stdout] test pci::cap::tests::test_pci_cap_list_default ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_bar_callbacks ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_change_command::case_1 ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_config ... ok
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: bar 0: set to 0xe0000000, update: 0xe0000000 -> 0xe0000000
[INFO] [stdout] test pci::config::tests::test_emulated_header_change_command::case_2 ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_change_command::case_3 ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_change_command::case_4 ... ok
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: bar 2: set to 0x00000000, update: 0x00000004 -> 0x00000004
[INFO] [stdout] test pci::config::tests::test_emulated_header_masks ... ok
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: bar 3: set to 0x00000001, update: 0x00000001 -> 0x00000001
[INFO] [stdout] test pci::cap::tests::test_pci_cap_list ... ok
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: updating bar 0: 0xe0000000 -> 0xe0010000, mask=0xfffff000
[INFO] [stdout] test pci::config::tests::test_emulated_header_write_bar::case_1 ... ok
[INFO] [stderr] INFO [alioth::pci::pvpanic] pvpanic: PANICKED
[INFO] [stdout] test pci::config::tests::test_emulated_header_write_bar::case_2 ... ok
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: bar 0: set to 0xe0010000, update: 0xe0000000 -> 0xe0010000
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: updating bar 3: 0x00000001 -> 0x00000002, mask=0xffffffff
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: bar 2: set to 0x00000000, update: 0x00000004 -> 0x00000004
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: bar 3: set to 0x00000002, update: 0x00000001 -> 0x00000002
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: bar 5: set to 0x0000e000, update: 0x0000e001 -> 0x0000e001
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: updating bar 5: 0x0000e001 -> 0x0000e101, mask=0xfffffffc
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: bar 5: set to 0x0000e100, update: 0x0000e001 -> 0x0000e101
[INFO] [stdout] test pci::config::tests::test_emulated_header_write_bar::case_3 ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_write_bar::case_4 ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_write_bar::case_5 ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_write_bar::case_7 ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_write_bar::case_6 ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_write_bar::case_8 ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_write_status::case_1 ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_write_status::case_2 ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_write_status::case_3 ... ok
[INFO] [stdout] test pci::config::tests::test_emulated_header_write_status::case_4 ... ok
[INFO] [stdout] test pci::host_bridge::tests::test_host_bridge ... ok
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_read_config::case_01 ... ok
[INFO] [stdout] test pci::config::tests::test_mem_bar_layout_change ... ok
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_bar ... ok
[INFO] [stdout] test pci::config::tests::test_io_bar_layout_change ... ok
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_read_config::case_02 ... ok
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_read_config::case_04 ... ok
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_read_config::case_03 ... ok
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_read_config::case_05 ... ok
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_read_config::case_07 ... ok
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_read_config::case_06 ... ok
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_read_config::case_08 ... ok
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_read_config::case_12 ... ok
[INFO] [stdout] test pci::segment::tests::test_pci_segment_mmio ... ok
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_read_config::case_11 ... ok
[INFO] [stdout] test pci::segment::tests::test_pci_segment_reserve::case_1 ... ok
[INFO] [stdout] test pci::segment::tests::test_pci_segment_reserve::case_2 ... ok
[INFO] [stdout] test pci::segment::tests::test_pci_segment_reserve::case_3 ... ok
[INFO] [stdout] test pci::segment::tests::test_pci_segment_next_bdf_wrapping ... ok
[INFO] [stdout] test pci::segment::tests::test_pci_segment_reserve::case_4 ... ok
[INFO] [stdout] test sync::notifier::tests::test_notifier ... ok
[INFO] [stdout] test sys::linux::ioctl::tests::test_codes ... ok
[INFO] [stdout] test utils::endian::tests::test_little_endian ... ok
[INFO] [stdout] test utils::endian::tests::test_big_endian ... ok
[INFO] [stdout] test utils::tests::test_align_up ... ok
[INFO] [stdout] test virtio::dev::entropy::tests::entry_config_test ... ok
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: updating bar 0: 0x0000000c -> 0xee00000c, mask=0xfffff000
[INFO] [stderr] INFO [alioth::pci::config] 00:00.0: bar 0: write 0xee000000, update: 0x0000000c -> 0xee00000c
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1200000, 200000) = 0, done
[INFO] [stderr] ERROR [alioth::virtio::dev::vsock] alioth::virtio::dev::vsock::VsockConfig: write 0x0000000000000000 to readonly offset 0x0.
[INFO] [stdout] test virtio::queue::packed::tests::enabled_queue ... ok
[INFO] [stdout] test virtio::dev::vsock::uds_vsock::tests::vsock_config_test ... ok
[INFO] [stdout] test virtio::queue::packed::tests::index_wrapping_sub::case_1 ... ok
[INFO] [stdout] test virtio::queue::packed::tests::index_wrapping_add::case_4 ... ok
[INFO] [stdout] test virtio::queue::packed::tests::index_wrapping_sub::case_2 ... ok
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_read_config::case_09 ... ok
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c0e00000, 200000) = 0, done
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c0a00000, 200000) = 0, done
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c0a00000, 200000) = 0, done
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c0800000, 200000) = 0, done
[INFO] [stdout] test pci::pvpanic::tests::test_pvpanic_read_config::case_10 ... ok
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c0a00000, 200000) = 0, done
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1000000, 200000) = 0, done
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c0200000, 200000) = 0, done
[INFO] [stdout] test virtio::queue::packed::tests::index_wrapping_sub::case_4 ... ok
[INFO] [stderr] ERROR [alioth::virtio::dev::vsock::uds_vsock] vsock: queue RX: no enough writable buffers for VsockOp::RST
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c0e00000, 200000) = 0, done
[INFO] [stdout] test virtio::queue::packed::tests::index_wrapping_sub::case_3 ... ok
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c0c00000, 200000) = 0, done
[INFO] [stderr] ERROR [alioth::virtio::dev::vsock::uds_vsock] vsock: failed to respond to shutdown: Invalid virtq buffer
[INFO] [stderr] 0: Invalid virtq buffer, at src/virtio/dev/vsock/uds_vsock.rs:223:41
[INFO] [stderr] 
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1000000, 200000) = 0, done
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1200000, 200000) = 0, done
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1200000, 200000) = 0, done
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1200000, 200000) = 0, done
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_01 ... ok
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1200000, 200000) = 0, done
[INFO] [stdout] test virtio::queue::packed::tests::index_wrapping_add::case_3 ... ok
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1400000, 200000) = 0, done
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_03 ... ok
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_04 ... ok
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_06 ... ok
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_05 ... ok
[INFO] [stdout] test virtio::queue::packed::tests::index_wrapping_add::case_1 ... ok
[INFO] [stdout] test virtio::queue::packed::tests::index_wrapping_add::case_2 ... ok
[INFO] [stdout] test virtio::queue::packed::tests::disabled_queue ... ok
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_07 ... ok
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_02 ... ok
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1200000, 200000) = 0, done
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1200000, 200000) = 0, done
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1400000, 200000) = 0, done
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1400000, 200000) = 0, done
[INFO] [stdout] test virtio::queue::packed::tests::enable_notification ... ok
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_08 ... ok
[INFO] [stdout] test virtio::dev::vsock::uds_vsock::tests::vsock_conn_test ... ok
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_09 ... ok
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_10 ... ok
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_11 ... ok
[INFO] [stdout] test virtio::dev::entropy::tests::entropy_test ... ok
[INFO] [stdout] test virtio::queue::split::tests::disabled_queue ... ok
[INFO] [stdout] test virtio::queue::split::tests::event_idx_enabled ... ok
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1200000, 200000) = 0, done
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_13 ... ok
[INFO] [stdout] test virtio::queue::tests::test_copy_from_reader ... ok
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1400000, 200000) = 0, done
[INFO] [stdout] test virtio::queue::tests::test_handle_deferred ... ok
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1200000, 200000) = 0, done
[INFO] [stdout] test virtio::queue::tests::test_copy_to_writer ... ok
[INFO] [stdout] test virtio::queue::split::tests::enabled_queue ... ok
[INFO] [stderr] INFO [alioth::mem::mapped] munmap(0x79a1c1400000, 200000) = 0, done
[INFO] [stdout] test virtio::queue::tests::test_written_bytes ... ok
[INFO] [stdout] test virtio::queue::packed::tests::is_interrupt_enabled::case_12 ... ok
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- firmware::acpi::reg::tests::test_pm_timer stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'firmware::acpi::reg::tests::test_pm_timer' (2146) panicked at src/firmware/acpi/reg_test.rs:23:5:
[INFO] [stdout] assertion failed: v2 > v1
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5ce9eff5e641 - <<std[104cf6e2632825ea]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[7c831bd917ebf35f]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5ce9eff76b8a - core[7c831bd917ebf35f]::fmt::write
[INFO] [stdout]    2:     0x5ce9eff647fc - <alloc[2fdc3f7464fcf288]::vec::Vec<u8> as core[7c831bd917ebf35f]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5ce9eff36fd6 - std[104cf6e2632825ea]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5ce9eff54e29 - std[104cf6e2632825ea]::panicking::default_hook
[INFO] [stdout]    5:     0x5ce9efed9190 - test[73009c9f9aebf890]::test_main_inner::<test[73009c9f9aebf890]::test_main_static::{closure#0}>::{closure#0}
[INFO] [stdout]    6:     0x5ce9eff54fe2 - std[104cf6e2632825ea]::panicking::panic_with_hook
[INFO] [stdout]    7:     0x5ce9eff370b4 - std[104cf6e2632825ea]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    8:     0x5ce9eff2f259 - std[104cf6e2632825ea]::sys::backtrace::__rust_end_short_backtrace::<std[104cf6e2632825ea]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    9:     0x5ce9eff37e5d - __rustc[b0d56fa5b193ad05]::rust_begin_unwind
[INFO] [stdout]   10:     0x5ce9eff7736c - core[7c831bd917ebf35f]::panicking::panic_fmt
[INFO] [stdout]   11:     0x5ce9eff77332 - core[7c831bd917ebf35f]::panicking::panic
[INFO] [stdout]   12:     0x5ce9efd7919b - alioth[3a84b572fa13e118]::firmware::acpi::reg::tests::test_pm_timer
[INFO] [stdout]   13:     0x5ce9efd96a49 - <alioth[3a84b572fa13e118]::firmware::acpi::reg::tests::test_pm_timer::{closure#0} as core[7c831bd917ebf35f]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   14:     0x5ce9efecc47b - test[73009c9f9aebf890]::__rust_begin_short_backtrace::<core[7c831bd917ebf35f]::result::Result<(), alloc[2fdc3f7464fcf288]::string::String>, fn() -> core[7c831bd917ebf35f]::result::Result<(), alloc[2fdc3f7464fcf288]::string::String>>
[INFO] [stdout]   15:     0x5ce9efed9ae5 - test[73009c9f9aebf890]::run_test::{closure#0}
[INFO] [stdout]   16:     0x5ce9efed2ea4 - std[104cf6e2632825ea]::sys::backtrace::__rust_begin_short_backtrace::<test[73009c9f9aebf890]::run_test::{closure#1}, ()>
[INFO] [stdout]   17:     0x5ce9efedcc42 - <std[104cf6e2632825ea]::thread::lifecycle::spawn_unchecked<test[73009c9f9aebf890]::run_test::{closure#1}, ()>::{closure#1} as core[7c831bd917ebf35f]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   18:     0x5ce9eff5d629 - <std[104cf6e2632825ea]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   19:     0x79a1c3db107a - <unknown>
[INFO] [stdout]   20:     0x79a1c3e44534 - clone
[INFO] [stdout]   21:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     firmware::acpi::reg::tests::test_pm_timer
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 223 passed; 1 failed; 4 ignored; 0 measured; 0 filtered out; finished in 0.05s
[INFO] [stdout] 
[INFO] [stderr] error: test failed, to rerun pass `--lib`
[INFO] running `Command { std: "docker" "inspect" "0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8", kill_on_drop: false }`
[INFO] [stdout] 0097f7f2cb956c8150206c509d42febc5ea84e0a350762db46e6ce59840253a8
