[INFO] cloning repository https://github.com/LebranceBW/KvStore [INFO] running `Command { std: "git" "-c" "credential.helper=" "-c" "credential.helper=/workspace/cargo-home/bin/git-credential-null" "clone" "--bare" "https://github.com/LebranceBW/KvStore" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2FLebranceBW%2FKvStore", kill_on_drop: false }` [INFO] [stderr] Cloning into bare repository '/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2FLebranceBW%2FKvStore'... [INFO] running `Command { std: "git" "rev-parse" "HEAD", kill_on_drop: false }` [INFO] [stdout] 84a1b0a435196234fafeb64e7b939aabcde08466 [INFO] testing LebranceBW/KvStore against master#ebf0cf75d368c035f4c7e7246d203bd469ee4a51 for pr-137940 [INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2FLebranceBW%2FKvStore" "/workspace/builds/worker-4-tc1/source", kill_on_drop: false }` [INFO] [stderr] Cloning into '/workspace/builds/worker-4-tc1/source'... [INFO] [stderr] done. [INFO] validating manifest of git repo https://github.com/LebranceBW/KvStore on toolchain ebf0cf75d368c035f4c7e7246d203bd469ee4a51 [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+ebf0cf75d368c035f4c7e7246d203bd469ee4a51" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }` [INFO] started tweaking git repo https://github.com/LebranceBW/KvStore [INFO] finished tweaking git repo https://github.com/LebranceBW/KvStore [INFO] tweaked toml for git repo https://github.com/LebranceBW/KvStore written to /workspace/builds/worker-4-tc1/source/Cargo.toml [INFO] crate git repo https://github.com/LebranceBW/KvStore 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" "+ebf0cf75d368c035f4c7e7246d203bd469ee4a51" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }` [INFO] [stderr] Updating crates.io index [INFO] [stderr] Downloading crates ... [INFO] [stderr] Downloaded panic-control v0.1.4 [INFO] [stderr] Downloaded mockall v0.9.1 [INFO] [stderr] Downloaded downcast v0.10.0 [INFO] [stderr] Downloaded predicates-tree v1.0.2 [INFO] [stderr] Downloaded fragile v1.0.0 [INFO] [stderr] Downloaded mockall_derive v0.9.1 [INFO] [stderr] Downloaded serde_cbor v0.11.1 [INFO] [stderr] Downloaded semver v1.0.3 [INFO] [stderr] Downloaded criterion-plot v0.4.3 [INFO] [stderr] Downloaded half v1.7.1 [INFO] [stderr] Downloaded sled v0.34.6 [INFO] [stderr] Downloaded criterion v0.3.4 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/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:1680c8fbd8dfb46fcd6d22e546df16ab0e007457dc29fcd9e987cdd5077fd1af" "/opt/rustwide/cargo-home/bin/cargo" "+ebf0cf75d368c035f4c7e7246d203bd469ee4a51" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }` [INFO] [stdout] 724f0c2e8ff77d0fcfdd9f703d59e5cda07ad384e54298462372cc9553879a00 [INFO] running `Command { std: "docker" "start" "-a" "724f0c2e8ff77d0fcfdd9f703d59e5cda07ad384e54298462372cc9553879a00", kill_on_drop: false }` [INFO] running `Command { std: "docker" "inspect" "724f0c2e8ff77d0fcfdd9f703d59e5cda07ad384e54298462372cc9553879a00", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "724f0c2e8ff77d0fcfdd9f703d59e5cda07ad384e54298462372cc9553879a00", kill_on_drop: false }` [INFO] [stdout] 724f0c2e8ff77d0fcfdd9f703d59e5cda07ad384e54298462372cc9553879a00 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/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" "RUSTDOCFLAGS=--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:1680c8fbd8dfb46fcd6d22e546df16ab0e007457dc29fcd9e987cdd5077fd1af" "/opt/rustwide/cargo-home/bin/cargo" "+ebf0cf75d368c035f4c7e7246d203bd469ee4a51" "build" "--frozen" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 582a390d467f7191920affc6da60cc7a195928665fc3a850b33b6952786b962a [INFO] running `Command { std: "docker" "start" "-a" "582a390d467f7191920affc6da60cc7a195928665fc3a850b33b6952786b962a", kill_on_drop: false }` [INFO] [stderr] Compiling autocfg v1.0.1 [INFO] [stderr] Compiling libc v0.2.98 [INFO] [stderr] Compiling proc-macro2 v1.0.27 [INFO] [stderr] Compiling crossbeam-utils v0.8.5 [INFO] [stderr] Compiling syn v1.0.73 [INFO] [stderr] Compiling version_check v0.9.3 [INFO] [stderr] Compiling crossbeam-epoch v0.9.5 [INFO] [stderr] Compiling memchr v2.4.0 [INFO] [stderr] Compiling rayon-core v1.9.1 [INFO] [stderr] Compiling serde_derive v1.0.126 [INFO] [stderr] Compiling bitflags v1.2.1 [INFO] [stderr] Compiling log v0.4.14 [INFO] [stderr] Compiling instant v0.1.9 [INFO] [stderr] Compiling crc32fast v1.2.1 [INFO] [stderr] Compiling smallvec v1.6.1 [INFO] [stderr] Compiling crossbeam-queue v0.3.2 [INFO] [stderr] Compiling serde v1.0.126 [INFO] [stderr] Compiling textwrap v0.11.0 [INFO] [stderr] Compiling lock_api v0.4.4 [INFO] [stderr] Compiling strsim v0.8.0 [INFO] [stderr] Compiling serde_json v1.0.64 [INFO] [stderr] Compiling ansi_term v0.11.0 [INFO] [stderr] Compiling anyhow v1.0.41 [INFO] [stderr] Compiling vec_map v0.8.2 [INFO] [stderr] Compiling proc-macro-error-attr v1.0.4 [INFO] [stderr] Compiling num-traits v0.2.14 [INFO] [stderr] Compiling memoffset v0.6.4 [INFO] [stderr] Compiling num-integer v0.1.44 [INFO] [stderr] Compiling proc-macro-error v1.0.4 [INFO] [stderr] Compiling rayon v1.5.1 [INFO] [stderr] Compiling byteorder v1.4.3 [INFO] [stderr] Compiling predicates-tree v1.0.2 [INFO] [stderr] Compiling downcast v0.10.0 [INFO] [stderr] Compiling itoa v0.4.7 [INFO] [stderr] Compiling crossbeam-channel v0.5.1 [INFO] [stderr] Compiling aho-corasick v0.7.18 [INFO] [stderr] Compiling fxhash v0.2.1 [INFO] [stderr] Compiling fragile v1.0.0 [INFO] [stderr] Compiling owned-alloc v0.2.0 [INFO] [stderr] Compiling either v1.6.1 [INFO] [stderr] Compiling quote v1.0.9 [INFO] [stderr] Compiling crossbeam-deque v0.8.0 [INFO] [stderr] Compiling atty v0.2.14 [INFO] [stderr] Compiling time v0.1.43 [INFO] [stderr] Compiling parking_lot_core v0.8.3 [INFO] [stderr] Compiling num_cpus v1.13.0 [INFO] [stderr] Compiling fs2 v0.4.3 [INFO] [stderr] Compiling lockfree v0.5.1 [INFO] [stderr] Compiling clap v2.33.3 [INFO] [stderr] Compiling colored v1.9.3 [INFO] [stderr] Compiling parking_lot v0.11.1 [INFO] [stderr] Compiling crossbeam v0.8.1 [INFO] [stderr] Compiling float-cmp v0.8.0 [INFO] [stderr] Compiling regex v1.5.4 [INFO] [stderr] Compiling chrono v0.4.19 [INFO] [stderr] Compiling sled v0.34.6 [INFO] [stderr] Compiling simple_logger v1.11.0 [INFO] [stderr] Compiling predicates v1.0.8 [INFO] [stderr] Compiling structopt-derive v0.4.15 [INFO] [stderr] Compiling mockall_derive v0.9.1 [INFO] [stderr] Compiling structopt v0.3.22 [INFO] [stderr] Compiling mockall v0.9.1 [INFO] [stderr] Compiling kvs v0.1.0 (/opt/rustwide/workdir) [INFO] [stderr] Finished `dev` profile [unoptimized + debuginfo] target(s) in 14.10s [INFO] running `Command { std: "docker" "inspect" "582a390d467f7191920affc6da60cc7a195928665fc3a850b33b6952786b962a", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "582a390d467f7191920affc6da60cc7a195928665fc3a850b33b6952786b962a", kill_on_drop: false }` [INFO] [stdout] 582a390d467f7191920affc6da60cc7a195928665fc3a850b33b6952786b962a [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/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" "RUSTDOCFLAGS=--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:1680c8fbd8dfb46fcd6d22e546df16ab0e007457dc29fcd9e987cdd5077fd1af" "/opt/rustwide/cargo-home/bin/cargo" "+ebf0cf75d368c035f4c7e7246d203bd469ee4a51" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 4a5a4bd5df968ddb2924dc21c9709652805bf49a96a6d2bc5a5a967ac3723cc0 [INFO] running `Command { std: "docker" "start" "-a" "4a5a4bd5df968ddb2924dc21c9709652805bf49a96a6d2bc5a5a967ac3723cc0", kill_on_drop: false }` [INFO] [stderr] Compiling semver v1.0.3 [INFO] [stderr] Compiling getrandom v0.2.3 [INFO] [stderr] Compiling ppv-lite86 v0.2.10 [INFO] [stderr] Compiling regex-automata v0.1.10 [INFO] [stderr] Compiling plotters-backend v0.3.2 [INFO] [stderr] Compiling csv-core v0.1.10 [INFO] [stderr] Compiling itertools v0.9.0 [INFO] [stderr] Compiling half v1.7.1 [INFO] [stderr] Compiling tinytemplate v1.2.1 [INFO] [stderr] Compiling itertools v0.10.1 [INFO] [stderr] Compiling remove_dir_all v0.5.3 [INFO] [stderr] Compiling oorandom v11.1.3 [INFO] [stderr] Compiling escargot v0.4.0 [INFO] [stderr] Compiling panic-control v0.1.4 [INFO] [stderr] Compiling bstr v0.2.16 [INFO] [stderr] Compiling rand_core v0.6.3 [INFO] [stderr] Compiling serde_cbor v0.11.1 [INFO] [stderr] Compiling plotters-svg v0.3.1 [INFO] [stderr] Compiling rustc_version v0.4.0 [INFO] [stderr] Compiling plotters v0.3.1 [INFO] [stderr] Compiling rand_chacha v0.3.1 [INFO] [stderr] Compiling cast v0.2.7 [INFO] [stderr] Compiling csv v1.1.6 [INFO] [stderr] Compiling rand v0.8.4 [INFO] [stderr] Compiling assert_cmd v0.11.1 [INFO] [stderr] Compiling criterion-plot v0.4.3 [INFO] [stderr] Compiling criterion v0.3.4 [INFO] [stderr] Compiling tempfile v3.2.0 [INFO] [stderr] Compiling kvs v0.1.0 (/opt/rustwide/workdir) [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 14.32s [INFO] [stderr] warning: the following packages contain code that will be rejected by a future version of Rust: criterion v0.3.4 [INFO] [stderr] note: to see what the problems were, use the option `--future-incompat-report`, or run `cargo report future-incompatibilities --id 1` [INFO] running `Command { std: "docker" "inspect" "4a5a4bd5df968ddb2924dc21c9709652805bf49a96a6d2bc5a5a967ac3723cc0", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "4a5a4bd5df968ddb2924dc21c9709652805bf49a96a6d2bc5a5a967ac3723cc0", kill_on_drop: false }` [INFO] [stdout] 4a5a4bd5df968ddb2924dc21c9709652805bf49a96a6d2bc5a5a967ac3723cc0 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/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" "RUSTDOCFLAGS=--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:1680c8fbd8dfb46fcd6d22e546df16ab0e007457dc29fcd9e987cdd5077fd1af" "/opt/rustwide/cargo-home/bin/cargo" "+ebf0cf75d368c035f4c7e7246d203bd469ee4a51" "test" "--frozen", kill_on_drop: false }` [INFO] [stdout] 3dcc03104fd96955229ae7958a6ef248167c8ca5f6a2c9ca900125a48b4e2958 [INFO] running `Command { std: "docker" "start" "-a" "3dcc03104fd96955229ae7958a6ef248167c8ca5f6a2c9ca900125a48b4e2958", kill_on_drop: false }` [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 0.26s [INFO] [stderr] warning: the following packages contain code that will be rejected by a future version of Rust: criterion v0.3.4 [INFO] [stderr] note: to see what the problems were, use the option `--future-incompat-report`, or run `cargo report future-incompatibilities --id 1` [INFO] [stderr] Running unittests src/bin/kvs.rs (/opt/rustwide/target/debug/deps/kvs-49808b0b5c6b182b) [INFO] [stdout] [INFO] [stdout] running 0 tests [INFO] [stdout] [INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s [INFO] [stdout] [INFO] [stderr] Running unittests src/bin/kvs-client.rs (/opt/rustwide/target/debug/deps/kvs_client-e9002164f7ed05f1) [INFO] [stdout] [INFO] [stdout] running 0 tests [INFO] [stdout] [INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s [INFO] [stdout] [INFO] [stderr] Running unittests src/bin/kvs-server.rs (/opt/rustwide/target/debug/deps/kvs_server-57c06612f2b3e7ab) [INFO] [stdout] [INFO] [stdout] running 0 tests [INFO] [stdout] [INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s [INFO] [stdout] [INFO] [stderr] Running tests/cli.rs (/opt/rustwide/target/debug/deps/cli-77ab042ddb351790) [INFO] [stdout] [INFO] [stdout] running 11 tests [INFO] [stdout] 2025-03-14 02:38:39,280 INFO [kvs_server] Listened at 127.0.0.1:4005, powered by sled, version: 0.1.0 [INFO] [stdout] 2025-03-14 02:38:39,282 INFO [kvs_server] Listened at 127.0.0.1:4004, powered by kvs, version: 0.1.0 [INFO] [stdout] test client_cli_invalid_subcommand ... ok [INFO] [stdout] 2025-03-14 02:38:39,292 INFO [kvs_server] Listened at 127.0.0.1:4002, powered by sled, version: 0.1.0 [INFO] [stdout] test client_cli_no_args ... ok [INFO] [stdout] test server_cli_version ... ok [INFO] [stdout] test client_cli_invalid_get ... ok [INFO] [stdout] test client_cli_invalid_rm ... ok [INFO] [stdout] test client_cli_version ... ok [INFO] [stdout] test client_cli_invalid_set ... ok [INFO] [stdout] 2025-03-14 02:38:39,442 DEBUG [sled::pagecache::snapshot] no previous snapshot found [INFO] [stdout] 2025-03-14 02:38:39,446 DEBUG [sled::pagecache::iterator] ordering before clearing tears: {}, max_header_stable_lsn: 0 [INFO] [stdout] 2025-03-14 02:38:39,446 DEBUG [sled::pagecache::iterator] in clean_tail_tears, found missing item in tail: None and we'll scan segments {} above lowest lsn 0 [INFO] [stdout] 2025-03-14 02:38:39,446 DEBUG [sled::pagecache::iterator] unable to load new segment: Io(Custom { kind: Other, error: "no segments remaining to iterate over" }) [INFO] [stdout] 2025-03-14 02:38:39,446 DEBUG [sled::pagecache::iterator] filtering out segments after detected tear at (lsn, lid) -1 [INFO] [stdout] 2025-03-14 02:38:39,446 DEBUG [sled::pagecache::iterator] unable to load new segment: Io(Custom { kind: Other, error: "no segments remaining to iterate over" }) [INFO] [stdout] 2025-03-14 02:38:39,446 DEBUG [sled::pagecache::segment] SA starting with tip 0 stable -1 free {} [INFO] [stdout] 2025-03-14 02:38:39,447 DEBUG [sled::pagecache::iobuf] starting log for a totally fresh system [INFO] [stdout] 2025-03-14 02:38:39,447 DEBUG [sled::pagecache::segment] segment accountant returning offset: 0 for lsn 0 on deck: {} [INFO] [stdout] 2025-03-14 02:38:39,447 DEBUG [sled::pagecache::iobuf] starting IoBufs with next_lsn: 0 next_lid: 0 [INFO] [stdout] 2025-03-14 02:38:39,447 DEBUG [sled::pagecache::iobuf] storing lsn 0 in beginning of buffer [INFO] [stdout] 2025-03-14 02:38:39,447 DEBUG [sled::pagecache] load_snapshot loading pages from 0..0 [INFO] [stdout] 2025-03-14 02:38:39,448 DEBUG [sled::meta] allocated pid 3 for root of new_tree [95, 95, 115, 108, 101, 100, 95, 95, 100, 101, 102, 97, 117, 108, 116] [INFO] [stdout] 2025-03-14 02:38:39,448 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 0 to 71 [INFO] [stdout] 2025-03-14 02:38:39,462 DEBUG [sled::pagecache::iobuf] wrote lsns 0-70 to disk at offsets 0-70, maxed false complete_len 71 [INFO] [stdout] 2025-03-14 02:38:39,462 DEBUG [sled::pagecache::iobuf] mark_interval(0, 71) [INFO] [stdout] 2025-03-14 02:38:39,462 DEBUG [sled::pagecache::iobuf] new highest interval: 0 - 70 [INFO] [stdout] 2025-03-14 02:38:39,492 DEBUG [sled::pagecache::snapshot] no previous snapshot found [INFO] [stdout] 2025-03-14 02:38:39,492 DEBUG [sled::pagecache::iterator] ordering before clearing tears: {}, max_header_stable_lsn: 0 [INFO] [stdout] 2025-03-14 02:38:39,492 DEBUG [sled::pagecache::iterator] in clean_tail_tears, found missing item in tail: None and we'll scan segments {} above lowest lsn 0 [INFO] [stdout] 2025-03-14 02:38:39,492 DEBUG [sled::pagecache::iterator] unable to load new segment: Io(Custom { kind: Other, error: "no segments remaining to iterate over" }) [INFO] [stdout] 2025-03-14 02:38:39,492 DEBUG [sled::pagecache::iterator] filtering out segments after detected tear at (lsn, lid) -1 [INFO] [stdout] 2025-03-14 02:38:39,492 DEBUG [sled::pagecache::iterator] unable to load new segment: Io(Custom { kind: Other, error: "no segments remaining to iterate over" }) [INFO] [stdout] 2025-03-14 02:38:39,496 DEBUG [sled::pagecache::segment] SA starting with tip 0 stable -1 free {} [INFO] [stdout] 2025-03-14 02:38:39,496 DEBUG [sled::pagecache::iobuf] starting log for a totally fresh system [INFO] [stdout] 2025-03-14 02:38:39,496 DEBUG [sled::pagecache::segment] segment accountant returning offset: 0 for lsn 0 on deck: {} [INFO] [stdout] 2025-03-14 02:38:39,496 DEBUG [sled::pagecache::iobuf] starting IoBufs with next_lsn: 0 next_lid: 0 [INFO] [stdout] 2025-03-14 02:38:39,496 DEBUG [sled::pagecache::iobuf] storing lsn 0 in beginning of buffer [INFO] [stdout] 2025-03-14 02:38:39,496 DEBUG [sled::pagecache] load_snapshot loading pages from 0..0 [INFO] [stdout] 2025-03-14 02:38:39,497 DEBUG [sled::meta] allocated pid 3 for root of new_tree [95, 95, 115, 108, 101, 100, 95, 95, 100, 101, 102, 97, 117, 108, 116] [INFO] [stdout] 2025-03-14 02:38:39,497 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 0 to 71 [INFO] [stdout] 2025-03-14 02:38:39,526 DEBUG [sled::pagecache::iobuf] wrote lsns 0-70 to disk at offsets 0-70, maxed false complete_len 71 [INFO] [stdout] 2025-03-14 02:38:39,526 DEBUG [sled::pagecache::iobuf] mark_interval(0, 71) [INFO] [stdout] 2025-03-14 02:38:39,526 DEBUG [sled::pagecache::iobuf] new highest interval: 0 - 70 [INFO] [stdout] 2025-03-14 02:38:39,948 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 71 to 96 [INFO] [stdout] 2025-03-14 02:38:39,948 DEBUG [sled::pagecache::iobuf] wrote lsns 71-95 to disk at offsets 71-95, maxed false complete_len 25 [INFO] [stdout] 2025-03-14 02:38:39,948 DEBUG [sled::pagecache::iobuf] mark_interval(71, 25) [INFO] [stdout] 2025-03-14 02:38:39,948 DEBUG [sled::pagecache::iobuf] new highest interval: 71 - 95 [INFO] [stdout] 2025-03-14 02:38:39,997 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 71 to 96 [INFO] [stdout] 2025-03-14 02:38:39,997 DEBUG [sled::pagecache::iobuf] wrote lsns 71-95 to disk at offsets 71-95, maxed false complete_len 25 [INFO] [stdout] 2025-03-14 02:38:39,997 DEBUG [sled::pagecache::iobuf] mark_interval(71, 25) [INFO] [stdout] 2025-03-14 02:38:39,997 DEBUG [sled::pagecache::iobuf] new highest interval: 71 - 95 [INFO] [stdout] 2025-03-14 02:38:40,280 INFO [kvs::server] Accept connection from client: 127.0.0.1:48490 [INFO] [stdout] 2025-03-14 02:38:40,280 INFO [kvs::server] Accept connection from client: 127.0.0.1:34646 [INFO] [stdout] 2025-03-14 02:38:40,280 INFO [kvs::server] Client: 127.0.0.1:34646 disconnected [INFO] [stdout] 2025-03-14 02:38:40,280 INFO [kvs::server] Client: 127.0.0.1:48490 disconnected [INFO] [stdout] 2025-03-14 02:38:40,280 DEBUG [kvs::server] [client->server] {"Set":{"key":"key1","value":"value1"}} [INFO] [stdout] 2025-03-14 02:38:40,280 DEBUG [kvs::server] [client->server] {"Set":{"key":"key1","value":"value1"}} [INFO] [stdout] 2025-03-14 02:38:40,280 DEBUG [kvs::server] command: Set { key: "key1", value: "value1" } [INFO] [stdout] 2025-03-14 02:38:40,281 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 96 to 117 [INFO] [stdout] test cli_log_configuration ... ok [INFO] [stdout] 2025-03-14 02:38:40,284 DEBUG [kvs::server] command: Set { key: "key1", value: "value1" } [INFO] [stdout] 2025-03-14 02:38:40,284 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2025-03-14 02:38:40,287 INFO [kvs::server] Accept connection from client: 127.0.0.1:34650 [INFO] [stdout] 2025-03-14 02:38:40,287 INFO [kvs::server] Client: 127.0.0.1:34650 disconnected [INFO] [stdout] 2025-03-14 02:38:40,287 DEBUG [kvs::server] [client->server] {"Get":{"key":"key1"}} [INFO] [stdout] 2025-03-14 02:38:40,287 DEBUG [kvs::server] command: Get { key: "key1" } [INFO] [stdout] 2025-03-14 02:38:40,287 DEBUG [kvs::server] [server->client] Ok("value1") [INFO] [stdout] 2025-03-14 02:38:40,288 DEBUG [sled::pagecache::iobuf] wrote lsns 96-116 to disk at offsets 96-116, maxed false complete_len 21 [INFO] [stdout] 2025-03-14 02:38:40,288 DEBUG [sled::pagecache::iobuf] mark_interval(96, 21) [INFO] [stdout] 2025-03-14 02:38:40,288 DEBUG [sled::pagecache::iobuf] new highest interval: 96 - 116 [INFO] [stdout] 2025-03-14 02:38:40,288 DEBUG [sled::pagecache::iobuf] make_stable(116) returning [INFO] [stdout] 2025-03-14 02:38:40,288 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2025-03-14 02:38:40,291 INFO [kvs::server] Accept connection from client: 127.0.0.1:48502 [INFO] [stdout] 2025-03-14 02:38:40,291 INFO [kvs::server] Client: 127.0.0.1:48502 disconnected [INFO] [stdout] 2025-03-14 02:38:40,291 DEBUG [kvs::server] [client->server] {"Get":{"key":"key1"}} [INFO] [stdout] 2025-03-14 02:38:40,292 DEBUG [kvs::server] command: Get { key: "key1" } [INFO] [stdout] 2025-03-14 02:38:40,292 DEBUG [kvs::server] [server->client] Ok("value1") [INFO] [stdout] 2025-03-14 02:38:40,292 INFO [kvs::server] Accept connection from client: 127.0.0.1:34656 [INFO] [stdout] 2025-03-14 02:38:40,292 INFO [kvs::server] Client: 127.0.0.1:34656 disconnected [INFO] [stdout] 2025-03-14 02:38:40,292 DEBUG [kvs::server] [client->server] {"Set":{"key":"key1","value":"value2"}} [INFO] [stdout] 2025-03-14 02:38:40,292 DEBUG [kvs::server] command: Set { key: "key1", value: "value2" } [INFO] [stdout] 2025-03-14 02:38:40,292 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2025-03-14 02:38:40,294 INFO [kvs::server] Accept connection from client: 127.0.0.1:48506 [INFO] [stdout] 2025-03-14 02:38:40,294 INFO [kvs::server] Client: 127.0.0.1:48506 disconnected [INFO] [stdout] 2025-03-14 02:38:40,295 DEBUG [kvs::server] [client->server] {"Set":{"key":"key1","value":"value2"}} [INFO] [stdout] 2025-03-14 02:38:40,295 DEBUG [kvs::server] command: Set { key: "key1", value: "value2" } [INFO] [stdout] 2025-03-14 02:38:40,295 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 117 to 138 [INFO] [stdout] 2025-03-14 02:38:40,295 DEBUG [sled::pagecache::iobuf] wrote lsns 117-137 to disk at offsets 117-137, maxed false complete_len 21 [INFO] [stdout] 2025-03-14 02:38:40,295 DEBUG [sled::pagecache::iobuf] mark_interval(117, 21) [INFO] [stdout] 2025-03-14 02:38:40,295 DEBUG [sled::pagecache::iobuf] new highest interval: 117 - 137 [INFO] [stdout] 2025-03-14 02:38:40,295 DEBUG [sled::pagecache::iobuf] make_stable(137) returning [INFO] [stdout] 2025-03-14 02:38:40,296 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2025-03-14 02:38:40,296 INFO [kvs::server] Accept connection from client: 127.0.0.1:34664 [INFO] [stdout] 2025-03-14 02:38:40,296 INFO [kvs::server] Client: 127.0.0.1:34664 disconnected [INFO] [stdout] 2025-03-14 02:38:40,297 DEBUG [kvs::server] [client->server] {"Get":{"key":"key1"}} [INFO] [stdout] 2025-03-14 02:38:40,297 DEBUG [kvs::server] command: Get { key: "key1" } [INFO] [stdout] 2025-03-14 02:38:40,297 DEBUG [kvs::server] [server->client] Ok("value2") [INFO] [stdout] 2025-03-14 02:38:40,298 INFO [kvs::server] Accept connection from client: 127.0.0.1:48512 [INFO] [stdout] 2025-03-14 02:38:40,299 INFO [kvs::server] Client: 127.0.0.1:48512 disconnected [INFO] [stdout] 2025-03-14 02:38:40,299 DEBUG [kvs::server] [client->server] {"Get":{"key":"key1"}} [INFO] [stdout] 2025-03-14 02:38:40,299 DEBUG [kvs::server] command: Get { key: "key1" } [INFO] [stdout] 2025-03-14 02:38:40,299 DEBUG [kvs::server] [server->client] Ok("value2") [INFO] [stdout] 2025-03-14 02:38:40,299 INFO [kvs::server] Accept connection from client: 127.0.0.1:34670 [INFO] [stdout] 2025-03-14 02:38:40,299 INFO [kvs::server] Client: 127.0.0.1:34670 disconnected [INFO] [stdout] 2025-03-14 02:38:40,300 DEBUG [kvs::server] [client->server] {"Get":{"key":"key2"}} [INFO] [stdout] 2025-03-14 02:38:40,300 DEBUG [kvs::server] command: Get { key: "key2" } [INFO] [stdout] 2025-03-14 02:38:40,300 DEBUG [kvs::server] [server->client] Ok("Key: key2 not found") [INFO] [stdout] 2025-03-14 02:38:40,305 INFO [kvs::server] Accept connection from client: 127.0.0.1:48514 [INFO] [stdout] 2025-03-14 02:38:40,306 INFO [kvs::server] Client: 127.0.0.1:48514 disconnected [INFO] [stdout] 2025-03-14 02:38:40,306 DEBUG [kvs::server] [client->server] {"Get":{"key":"key2"}} [INFO] [stdout] 2025-03-14 02:38:40,306 DEBUG [kvs::server] command: Get { key: "key2" } [INFO] [stdout] 2025-03-14 02:38:40,306 DEBUG [kvs::server] [server->client] Ok("Key: key2 not found") [INFO] [stdout] 2025-03-14 02:38:40,306 INFO [kvs::server] Accept connection from client: 127.0.0.1:34672 [INFO] [stdout] 2025-03-14 02:38:40,306 INFO [kvs::server] Client: 127.0.0.1:34672 disconnected [INFO] [stdout] 2025-03-14 02:38:40,306 DEBUG [kvs::server] [client->server] {"Rm":{"key":"key2"}} [INFO] [stdout] 2025-03-14 02:38:40,307 DEBUG [kvs::server] command: Rm { key: "key2" } [INFO] [stdout] 2025-03-14 02:38:40,307 DEBUG [kvs::server] [server->client] Error("Key: key2 not found.") [INFO] [stdout] 2025-03-14 02:38:40,309 INFO [kvs::server] Accept connection from client: 127.0.0.1:48518 [INFO] [stdout] 2025-03-14 02:38:40,309 INFO [kvs::server] Client: 127.0.0.1:48518 disconnected [INFO] [stdout] 2025-03-14 02:38:40,309 DEBUG [kvs::server] [client->server] {"Rm":{"key":"key2"}} [INFO] [stdout] 2025-03-14 02:38:40,310 DEBUG [kvs::server] command: Rm { key: "key2" } [INFO] [stdout] 2025-03-14 02:38:40,310 DEBUG [kvs::server] [server->client] Error("Key: key2 not found.") [INFO] [stdout] 2025-03-14 02:38:40,313 INFO [kvs::server] Accept connection from client: 127.0.0.1:34676 [INFO] [stdout] 2025-03-14 02:38:40,313 INFO [kvs::server] Client: 127.0.0.1:34676 disconnected [INFO] [stdout] 2025-03-14 02:38:40,315 INFO [kvs::server] Accept connection from client: 127.0.0.1:48530 [INFO] [stdout] 2025-03-14 02:38:40,315 DEBUG [kvs::server] [client->server] {"Set":{"key":"key2","value":"value3"}} [INFO] [stdout] 2025-03-14 02:38:40,315 DEBUG [kvs::server] command: Set { key: "key2", value: "value3" } [INFO] [stdout] 2025-03-14 02:38:40,315 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 138 to 159 [INFO] [stdout] 2025-03-14 02:38:40,315 INFO [kvs::server] Client: 127.0.0.1:48530 disconnected [INFO] [stdout] 2025-03-14 02:38:40,316 DEBUG [sled::pagecache::iobuf] wrote lsns 138-158 to disk at offsets 138-158, maxed false complete_len 21 [INFO] [stdout] 2025-03-14 02:38:40,316 DEBUG [sled::pagecache::iobuf] mark_interval(138, 21) [INFO] [stdout] 2025-03-14 02:38:40,316 DEBUG [sled::pagecache::iobuf] new highest interval: 138 - 158 [INFO] [stdout] 2025-03-14 02:38:40,316 DEBUG [sled::pagecache::iobuf] make_stable(158) returning [INFO] [stdout] 2025-03-14 02:38:40,316 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2025-03-14 02:38:40,316 DEBUG [kvs::server] [client->server] {"Set":{"key":"key2","value":"value3"}} [INFO] [stdout] 2025-03-14 02:38:40,316 DEBUG [kvs::server] command: Set { key: "key2", value: "value3" } [INFO] [stdout] 2025-03-14 02:38:40,317 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2025-03-14 02:38:40,322 INFO [kvs::server] Accept connection from client: 127.0.0.1:48546 [INFO] [stdout] 2025-03-14 02:38:40,323 DEBUG [kvs::server] [client->server] {"Rm":{"key":"key1"}} [INFO] [stdout] 2025-03-14 02:38:40,323 DEBUG [kvs::server] command: Rm { key: "key1" } [INFO] [stdout] 2025-03-14 02:38:40,323 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 159 to 173 [INFO] [stdout] 2025-03-14 02:38:40,323 DEBUG [sled::pagecache::iobuf] wrote lsns 159-172 to disk at offsets 159-172, maxed false complete_len 14 [INFO] [stdout] 2025-03-14 02:38:40,323 DEBUG [sled::pagecache::iobuf] mark_interval(159, 14) [INFO] [stdout] 2025-03-14 02:38:40,323 DEBUG [sled::pagecache::iobuf] new highest interval: 159 - 172 [INFO] [stdout] 2025-03-14 02:38:40,323 DEBUG [sled::pagecache::iobuf] make_stable(172) returning [INFO] [stdout] 2025-03-14 02:38:40,323 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2025-03-14 02:38:40,324 INFO [kvs::server] Accept connection from client: 127.0.0.1:34678 [INFO] [stdout] 2025-03-14 02:38:40,324 INFO [kvs::server] Client: 127.0.0.1:34678 disconnected [INFO] [stdout] 2025-03-14 02:38:40,324 DEBUG [kvs::server] [client->server] {"Rm":{"key":"key1"}} [INFO] [stdout] 2025-03-14 02:38:40,324 DEBUG [kvs::server] command: Rm { key: "key1" } [INFO] [stdout] 2025-03-14 02:38:40,324 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2025-03-14 02:38:40,326 INFO [kvs_server] Retrieving last work. engine: sled [INFO] [stdout] 2025-03-14 02:38:40,326 INFO [kvs_server] Listened at 127.0.0.1:4005, powered by sled, version: 0.1.0 [INFO] [stderr] [INFO] [stderr] thread 'main' panicked at src/bin/kvs-server.rs:63:54: [INFO] [stderr] Failed to create a sled engine.: IO error: could not acquire lock on "/tmp/.tmpv6cfkJ/db": Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } [INFO] [stderr] stack backtrace: [INFO] [stdout] 2025-03-14 02:38:40,327 INFO [kvs_server] Retrieving last work. engine: kvs [INFO] [stdout] 2025-03-14 02:38:40,327 INFO [kvs_server] Listened at 127.0.0.1:4004, powered by kvs, version: 0.1.0 [INFO] [stdout] 2025-03-14 02:38:40,351 INFO [kvs_server] Listened at 127.0.0.1:4002, powered by kvs, version: 0.1.0 [INFO] [stderr] 0: 0x57da51cd0d82 - std::backtrace_rs::backtrace::libunwind::trace::hf010e1dbae51cb72 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9 [INFO] [stderr] 1: 0x57da51cd0d82 - std::backtrace_rs::backtrace::trace_unsynchronized::hfea1b1ce70c8ef04 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14 [INFO] [stderr] 2: 0x57da51cd0d82 - std::sys::backtrace::_print_fmt::h2997a50d2484a6a6 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/sys/backtrace.rs:66:9 [INFO] [stderr] 3: 0x57da51cd0d82 - ::fmt::h7fb80f6afbe41a33 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/sys/backtrace.rs:39:26 [INFO] [stderr] 4: 0x57da51cf9533 - core::fmt::rt::Argument::fmt::hd3a68c3e7e846625 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/fmt/rt.rs:185:76 [INFO] [stderr] 5: 0x57da51cf9533 - core::fmt::write::h000527be0eea6fe8 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/fmt/mod.rs:1449:21 [INFO] [stderr] 6: 0x57da51cccea3 - std::io::Write::write_fmt::h4991a22851475fb5 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/io/mod.rs:1890:15 [INFO] [stderr] 7: 0x57da51cd0bd2 - std::sys::backtrace::BacktraceLock::print::hffad87dde00cbe3e [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/sys/backtrace.rs:42:9 [INFO] [stderr] 8: 0x57da51cd1bc0 - std::panicking::default_hook::{{closure}}::ha46397973bec1239 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:298:22 [INFO] [stderr] 9: 0x57da51cd195d - std::panicking::default_hook::h706de72a1550eed4 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:325:9 [INFO] [stderr] 10: 0x57da51cd25e2 - std::panicking::rust_panic_with_hook::h6666776865bd21f5 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:831:13 [INFO] [stderr] 11: 0x57da51cd236a - std::panicking::begin_panic_handler::{{closure}}::hb8595612365d24db [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:704:13 [INFO] [stderr] 12: 0x57da51cd1279 - std::sys::backtrace::__rust_end_short_backtrace::h7037f177c7ae4ed3 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/sys/backtrace.rs:168:18 [INFO] [stderr] 13: 0x57da51cd1ffd - rust_begin_unwind [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:695:5 [INFO] [stderr] 14: 0x57da51cf7290 - core::panicking::panic_fmt::hd26142fa9828e2a3 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/panicking.rs:75:14 [INFO] [stderr] 15: 0x57da51cf7736 - core::result::unwrap_failed::hfccce26cc7701817 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/result.rs:1704:5 [INFO] [stderr] 16: 0x57da51963fb5 - core::result::Result::expect::h017e8861f1fbe502 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/result.rs:1061:23 [INFO] [stderr] 17: 0x57da51969b94 - kvs_server::main::h6ccb2729ea5fa6e8 [INFO] [stderr] at /opt/rustwide/workdir/src/bin/kvs-server.rs:63:13 [INFO] [stderr] 18: 0x57da5196d24b - core::ops::function::FnOnce::call_once::h4b25678b9184a7da [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/ops/function.rs:250:5 [INFO] [stderr] 19: 0x57da5196c79e - std::sys::backtrace::__rust_begin_short_backtrace::h6466e5edd235a3b9 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/sys/backtrace.rs:152:18 [INFO] [stderr] 20: 0x57da5196c2e1 - std::rt::lang_start::{{closure}}::hd245106956bc9f09 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/rt.rs:199:18 [INFO] [stderr] 21: 0x57da51cc7520 - core::ops::function::impls:: for &F>::call_once::hc7eeca589e16a550 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/ops/function.rs:284:13 [INFO] [stderr] 22: 0x57da51cc7520 - std::panicking::try::do_call::h221101e4880b2c2e [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:587:40 [INFO] [stderr] 23: 0x57da51cc7520 - std::panicking::try::h3149f937a0e2213c [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:550:19 [INFO] [stderr] 24: 0x57da51cc7520 - std::panic::catch_unwind::hb296358a26114f71 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panic.rs:359:14 [INFO] [stderr] 25: 0x57da51cc7520 - std::rt::lang_start_internal::{{closure}}::hd3a3ab4349d9e2b8 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/rt.rs:168:24 [INFO] [stderr] 26: 0x57da51cc7520 - std::panicking::try::do_call::ha227ee1f38141b4d [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:587:40 [INFO] [stderr] 27: 0x57da51cc7520 - std::panicking::try::h3cdd1a0cf9511c85 [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:550:19 [INFO] [stderr] 28: 0x57da51cc7520 - std::panic::catch_unwind::h22aa65835b0f767d [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panic.rs:359:14 [INFO] [stderr] 29: 0x57da51cc7520 - std::rt::lang_start_internal::hc64d421b1e79a38b [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/rt.rs:164:5 [INFO] [stderr] 30: 0x57da5196c2c7 - std::rt::lang_start::h4c24373f6fb03d7b [INFO] [stderr] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/rt.rs:198:5 [INFO] [stderr] 31: 0x57da5196af0e - main [INFO] [stderr] 32: 0x7ec907cc3d90 - [INFO] [stderr] 33: 0x7ec907cc3e40 - __libc_start_main [INFO] [stderr] 34: 0x57da5195c335 - _start [INFO] [stderr] 35: 0x0 - [INFO] [stdout] 2025-03-14 02:38:41,331 INFO [kvs::server] Accept connection from client: 127.0.0.1:34686 [INFO] [stdout] 2025-03-14 02:38:41,331 INFO [kvs::server] Client: 127.0.0.1:34686 disconnected [INFO] [stdout] 2025-03-14 02:38:41,332 DEBUG [kvs::server] [client->server] {"Get":{"key":"key2"}} [INFO] [stdout] 2025-03-14 02:38:41,332 DEBUG [kvs::server] command: Get { key: "key2" } [INFO] [stdout] 2025-03-14 02:38:41,332 DEBUG [kvs::server] [server->client] Ok("value3") [INFO] [stdout] 2025-03-14 02:38:41,338 INFO [kvs::server] Accept connection from client: 127.0.0.1:34692 [INFO] [stdout] 2025-03-14 02:38:41,338 INFO [kvs::server] Client: 127.0.0.1:34692 disconnected [INFO] [stdout] 2025-03-14 02:38:41,340 DEBUG [kvs::server] [client->server] {"Get":{"key":"key1"}} [INFO] [stdout] 2025-03-14 02:38:41,340 DEBUG [kvs::server] command: Get { key: "key1" } [INFO] [stdout] 2025-03-14 02:38:41,340 DEBUG [kvs::server] [server->client] Ok("Key: key1 not found") [INFO] [stdout] test cli_access_server_kvs_engine ... ok [INFO] [stdout] test cli_access_server_sled_engine ... FAILED [INFO] [stdout] test cli_wrong_engine ... ok [INFO] [stdout] [INFO] [stdout] failures: [INFO] [stdout] [INFO] [stdout] ---- cli_access_server_sled_engine stdout ---- [INFO] [stdout] [INFO] [stdout] thread 'cli_access_server_sled_engine' panicked at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/assert_cmd-0.11.1/src/assert.rs:154:13: [INFO] [stdout] Unexpected failure. [INFO] [stdout] code-255 [INFO] [stdout] stderr=```Connection refused (os error 111) [INFO] [stdout] ``` [INFO] [stdout] command=`cd "/tmp/.tmpv6cfkJ" && "/opt/rustwide/target/debug/kvs-client" "get" "key2" "--addr" "127.0.0.1:4005"` [INFO] [stdout] code=255 [INFO] [stdout] stdout=`````` [INFO] [stdout] stderr=```Connection refused (os error 111) [INFO] [stdout] ``` [INFO] [stdout] [INFO] [stdout] stack backtrace: [INFO] [stdout] 0: 0x56ab29e04832 - std::backtrace_rs::backtrace::libunwind::trace::hf010e1dbae51cb72 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9 [INFO] [stdout] 1: 0x56ab29e04832 - std::backtrace_rs::backtrace::trace_unsynchronized::hfea1b1ce70c8ef04 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14 [INFO] [stdout] 2: 0x56ab29e04832 - std::sys::backtrace::_print_fmt::h2997a50d2484a6a6 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/sys/backtrace.rs:66:9 [INFO] [stdout] 3: 0x56ab29e04832 - ::fmt::h7fb80f6afbe41a33 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/sys/backtrace.rs:39:26 [INFO] [stdout] 4: 0x56ab29e2d973 - core::fmt::rt::Argument::fmt::hd3a68c3e7e846625 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/fmt/rt.rs:185:76 [INFO] [stdout] 5: 0x56ab29e2d973 - core::fmt::write::h000527be0eea6fe8 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/fmt/mod.rs:1449:21 [INFO] [stdout] 6: 0x56ab29e01073 - std::io::Write::write_fmt::h5402e677befea770 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/io/mod.rs:1890:15 [INFO] [stdout] 7: 0x56ab29e04682 - std::sys::backtrace::BacktraceLock::print::hffad87dde00cbe3e [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/sys/backtrace.rs:42:9 [INFO] [stdout] 8: 0x56ab29e05d5a - std::panicking::default_hook::{{closure}}::ha46397973bec1239 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:298:22 [INFO] [stdout] 9: 0x56ab29e05b49 - std::panicking::default_hook::h706de72a1550eed4 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:322:9 [INFO] [stdout] 10: 0x56ab29d7ad07 - as core::ops::function::Fn>::call::hde091e5c6e92bb68 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/alloc/src/boxed.rs:1984:9 [INFO] [stdout] 11: 0x56ab29d7ad07 - test::test_main::{{closure}}::h769424ff54c41197 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/test/src/lib.rs:136:21 [INFO] [stdout] 12: 0x56ab29e06843 - as core::ops::function::Fn>::call::hbd7480c9dddf3315 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/alloc/src/boxed.rs:1984:9 [INFO] [stdout] 13: 0x56ab29e06843 - std::panicking::rust_panic_with_hook::h6666776865bd21f5 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:839:13 [INFO] [stdout] 14: 0x56ab29e064fa - std::panicking::begin_panic_handler::{{closure}}::hb8595612365d24db [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:704:13 [INFO] [stdout] 15: 0x56ab29e04d29 - std::sys::backtrace::__rust_end_short_backtrace::h7037f177c7ae4ed3 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/sys/backtrace.rs:168:18 [INFO] [stdout] 16: 0x56ab29e0618d - rust_begin_unwind [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:695:5 [INFO] [stdout] 17: 0x56ab29e2c090 - core::panicking::panic_fmt::hd26142fa9828e2a3 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/panicking.rs:75:14 [INFO] [stdout] 18: 0x56ab29db3042 - assert_cmd::assert::Assert::success::h3e1e4298aa5d369f [INFO] [stdout] at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/assert_cmd-0.11.1/src/assert.rs:154:13 [INFO] [stdout] 19: 0x56ab29d3c813 - cli::cli_access_server::he00ca9e27526f18c [INFO] [stdout] at /opt/rustwide/workdir/tests/cli.rs:313:5 [INFO] [stdout] 20: 0x56ab29d40d5e - cli::cli_access_server_sled_engine::ha51fdf565c128530 [INFO] [stdout] at /opt/rustwide/workdir/tests/cli.rs:338:5 [INFO] [stdout] 21: 0x56ab29d40d27 - cli::cli_access_server_sled_engine::{{closure}}::h0d7d1cf4b160f3ee [INFO] [stdout] at /opt/rustwide/workdir/tests/cli.rs:337:35 [INFO] [stdout] 22: 0x56ab29d371a6 - core::ops::function::FnOnce::call_once::h08612b837f68f1fc [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 23: 0x56ab29d8060b - core::ops::function::FnOnce::call_once::h537cb3ba0681a85d [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 24: 0x56ab29d8060b - test::__rust_begin_short_backtrace::ha34590b284b8a909 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/test/src/lib.rs:638:18 [INFO] [stdout] 25: 0x56ab29d7f6a5 - test::run_test_in_process::{{closure}}::h7e5cb0195a5ea6a6 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/test/src/lib.rs:661:60 [INFO] [stdout] 26: 0x56ab29d7f6a5 - as core::ops::function::FnOnce<()>>::call_once::h4fd7826f39023efe [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/panic/unwind_safe.rs:272:9 [INFO] [stdout] 27: 0x56ab29d7f6a5 - std::panicking::try::do_call::h840562177f324507 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:587:40 [INFO] [stdout] 28: 0x56ab29d7f6a5 - std::panicking::try::h2360ed2f8f8e7bd8 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:550:19 [INFO] [stdout] 29: 0x56ab29d7f6a5 - std::panic::catch_unwind::h98cd8da2f8eb8f7b [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panic.rs:359:14 [INFO] [stdout] 30: 0x56ab29d7f6a5 - test::run_test_in_process::hcd6b1143eaf140ef [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/test/src/lib.rs:661:27 [INFO] [stdout] 31: 0x56ab29d7f6a5 - test::run_test::{{closure}}::h12da0337272887dc [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/test/src/lib.rs:582:43 [INFO] [stdout] 32: 0x56ab29d42694 - test::run_test::{{closure}}::h11d537cad5364bdc [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/test/src/lib.rs:612:41 [INFO] [stdout] 33: 0x56ab29d42694 - std::sys::backtrace::__rust_begin_short_backtrace::h5f533949825eb644 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/sys/backtrace.rs:152:18 [INFO] [stdout] 34: 0x56ab29d460fa - std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}::hf8cffede9b676267 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/thread/mod.rs:559:17 [INFO] [stdout] 35: 0x56ab29d460fa - as core::ops::function::FnOnce<()>>::call_once::h3160424131f9b05b [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/panic/unwind_safe.rs:272:9 [INFO] [stdout] 36: 0x56ab29d460fa - std::panicking::try::do_call::h4821f856f783960c [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:587:40 [INFO] [stdout] 37: 0x56ab29d460fa - std::panicking::try::hd6726363e8162e27 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panicking.rs:550:19 [INFO] [stdout] 38: 0x56ab29d460fa - std::panic::catch_unwind::hb75a27d7bd2912cb [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/panic.rs:359:14 [INFO] [stdout] 39: 0x56ab29d460fa - std::thread::Builder::spawn_unchecked_::{{closure}}::h36d5666a81748b85 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/thread/mod.rs:557:30 [INFO] [stdout] 40: 0x56ab29d460fa - core::ops::function::FnOnce::call_once{{vtable.shim}}::ha3d6556f1deabcaf [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 41: 0x56ab29e0a92b - as core::ops::function::FnOnce>::call_once::h454485597884df01 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/alloc/src/boxed.rs:1970:9 [INFO] [stdout] 42: 0x56ab29e0a92b - as core::ops::function::FnOnce>::call_once::h421b8b5dc09cf3b4 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/alloc/src/boxed.rs:1970:9 [INFO] [stdout] 43: 0x56ab29e0a92b - std::sys::pal::unix::thread::Thread::new::thread_start::ha1530b93ff336c49 [INFO] [stdout] at /rustc/ebf0cf75d368c035f4c7e7246d203bd469ee4a51/library/std/src/sys/pal/unix/thread.rs:109:17 [INFO] [stdout] 44: 0x7a55eab8bac3 - [INFO] [stdout] 45: 0x7a55eac1ca04 - clone [INFO] [stdout] 46: 0x0 - [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] failures: [INFO] [stdout] cli_access_server_sled_engine [INFO] [stdout] [INFO] [stdout] test result: FAILED. 10 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.12s [INFO] [stdout] [INFO] [stderr] error: test failed, to rerun pass `--test cli` [INFO] running `Command { std: "docker" "inspect" "3dcc03104fd96955229ae7958a6ef248167c8ca5f6a2c9ca900125a48b4e2958", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "3dcc03104fd96955229ae7958a6ef248167c8ca5f6a2c9ca900125a48b4e2958", kill_on_drop: false }` [INFO] [stdout] 3dcc03104fd96955229ae7958a6ef248167c8ca5f6a2c9ca900125a48b4e2958