[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#67da586efe13aa66eef576ba095e1875ba65fd20 for pr-112849 [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 67da586efe13aa66eef576ba095e1875ba65fd20 [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+67da586efe13aa66eef576ba095e1875ba65fd20" "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" "+67da586efe13aa66eef576ba095e1875ba65fd20" "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 sled v0.34.6 [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:19e73879b68f455e41552ea35293514db52ea292d993f571636dbffedb77a1ee" "/opt/rustwide/cargo-home/bin/cargo" "+67da586efe13aa66eef576ba095e1875ba65fd20" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }` [INFO] [stdout] 4510cadb9940ff788418c8859ae5671d0dabaaca8c9e24ca24c738e0b73dc55f [INFO] running `Command { std: "docker" "start" "-a" "4510cadb9940ff788418c8859ae5671d0dabaaca8c9e24ca24c738e0b73dc55f", kill_on_drop: false }` [INFO] running `Command { std: "docker" "inspect" "4510cadb9940ff788418c8859ae5671d0dabaaca8c9e24ca24c738e0b73dc55f", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "4510cadb9940ff788418c8859ae5671d0dabaaca8c9e24ca24c738e0b73dc55f", kill_on_drop: false }` [INFO] [stdout] 4510cadb9940ff788418c8859ae5671d0dabaaca8c9e24ca24c738e0b73dc55f [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:19e73879b68f455e41552ea35293514db52ea292d993f571636dbffedb77a1ee" "/opt/rustwide/cargo-home/bin/cargo" "+67da586efe13aa66eef576ba095e1875ba65fd20" "build" "--frozen" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 7eb5c9a46be2dd5586cd82866468e10829e90ad12da8ee48fe2bc0749a4d5224 [INFO] running `Command { std: "docker" "start" "-a" "7eb5c9a46be2dd5586cd82866468e10829e90ad12da8ee48fe2bc0749a4d5224", kill_on_drop: false }` [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 memoffset v0.6.4 [INFO] [stderr] Compiling num-traits v0.2.14 [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 num-integer v0.1.44 [INFO] [stderr] Compiling log v0.4.14 [INFO] [stderr] Compiling serde_derive v1.0.126 [INFO] [stderr] Compiling rayon-core v1.9.1 [INFO] [stderr] Compiling bitflags v1.2.1 [INFO] [stderr] Compiling instant v0.1.9 [INFO] [stderr] Compiling smallvec v1.6.1 [INFO] [stderr] Compiling crossbeam-queue v0.3.2 [INFO] [stderr] Compiling crc32fast v1.2.1 [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 rayon v1.5.1 [INFO] [stderr] Compiling anyhow v1.0.41 [INFO] [stderr] Compiling proc-macro-error-attr v1.0.4 [INFO] [stderr] Compiling proc-macro-error v1.0.4 [INFO] [stderr] Compiling ansi_term v0.11.0 [INFO] [stderr] Compiling vec_map v0.8.2 [INFO] [stderr] Compiling strsim v0.8.0 [INFO] [stderr] Compiling serde_json v1.0.64 [INFO] [stderr] Compiling crossbeam-channel v0.5.1 [INFO] [stderr] Compiling predicates-tree v1.0.2 [INFO] [stderr] Compiling owned-alloc v0.2.0 [INFO] [stderr] Compiling either v1.6.1 [INFO] [stderr] Compiling aho-corasick v0.7.18 [INFO] [stderr] Compiling itoa v0.4.7 [INFO] [stderr] Compiling downcast v0.10.0 [INFO] [stderr] Compiling fragile v1.0.0 [INFO] [stderr] Compiling quote v1.0.9 [INFO] [stderr] Compiling crossbeam-deque v0.8.0 [INFO] [stderr] Compiling lockfree v0.5.1 [INFO] [stderr] Compiling atty v0.2.14 [INFO] [stderr] Compiling parking_lot_core v0.8.3 [INFO] [stderr] Compiling time v0.1.43 [INFO] [stderr] Compiling num_cpus v1.13.0 [INFO] [stderr] Compiling colored v1.9.3 [INFO] [stderr] Compiling clap v2.33.3 [INFO] [stderr] Compiling fs2 v0.4.3 [INFO] [stderr] Compiling crossbeam v0.8.1 [INFO] [stderr] Compiling float-cmp v0.8.0 [INFO] [stderr] Compiling parking_lot v0.11.1 [INFO] [stderr] Compiling sled v0.34.6 [INFO] [stderr] Compiling chrono v0.4.19 [INFO] [stderr] Compiling regex v1.5.4 [INFO] [stderr] Compiling simple_logger v1.11.0 [INFO] [stderr] Compiling predicates v1.0.8 [INFO] [stderr] Compiling mockall_derive v0.9.1 [INFO] [stderr] Compiling structopt-derive v0.4.15 [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 [unoptimized + debuginfo] target(s) in 11.61s [INFO] running `Command { std: "docker" "inspect" "7eb5c9a46be2dd5586cd82866468e10829e90ad12da8ee48fe2bc0749a4d5224", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "7eb5c9a46be2dd5586cd82866468e10829e90ad12da8ee48fe2bc0749a4d5224", kill_on_drop: false }` [INFO] [stdout] 7eb5c9a46be2dd5586cd82866468e10829e90ad12da8ee48fe2bc0749a4d5224 [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:19e73879b68f455e41552ea35293514db52ea292d993f571636dbffedb77a1ee" "/opt/rustwide/cargo-home/bin/cargo" "+67da586efe13aa66eef576ba095e1875ba65fd20" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 620e6bbb47e973aef2a24b035236a4aa5ec3d0e6aee9ea49f63724bcfb200f3c [INFO] running `Command { std: "docker" "start" "-a" "620e6bbb47e973aef2a24b035236a4aa5ec3d0e6aee9ea49f63724bcfb200f3c", kill_on_drop: false }` [INFO] [stderr] Compiling semver v1.0.3 [INFO] [stderr] Compiling getrandom v0.2.3 [INFO] [stderr] Compiling plotters-backend v0.3.2 [INFO] [stderr] Compiling ppv-lite86 v0.2.10 [INFO] [stderr] Compiling regex-automata v0.1.10 [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 rand_core v0.6.3 [INFO] [stderr] Compiling serde_cbor v0.11.1 [INFO] [stderr] Compiling plotters-svg v0.3.1 [INFO] [stderr] Compiling bstr v0.2.16 [INFO] [stderr] Compiling plotters v0.3.1 [INFO] [stderr] Compiling rand_chacha v0.3.1 [INFO] [stderr] Compiling rustc_version v0.4.0 [INFO] [stderr] Compiling rand v0.8.4 [INFO] [stderr] Compiling assert_cmd v0.11.1 [INFO] [stderr] Compiling cast v0.2.7 [INFO] [stderr] Compiling csv v1.1.6 [INFO] [stderr] Compiling criterion-plot v0.4.3 [INFO] [stderr] Compiling tempfile v3.2.0 [INFO] [stderr] Compiling criterion v0.3.4 [INFO] [stderr] Compiling kvs v0.1.0 (/opt/rustwide/workdir) [INFO] [stderr] Finished test [unoptimized + debuginfo] target(s) in 5.46s [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" "620e6bbb47e973aef2a24b035236a4aa5ec3d0e6aee9ea49f63724bcfb200f3c", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "620e6bbb47e973aef2a24b035236a4aa5ec3d0e6aee9ea49f63724bcfb200f3c", kill_on_drop: false }` [INFO] [stdout] 620e6bbb47e973aef2a24b035236a4aa5ec3d0e6aee9ea49f63724bcfb200f3c [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:19e73879b68f455e41552ea35293514db52ea292d993f571636dbffedb77a1ee" "/opt/rustwide/cargo-home/bin/cargo" "+67da586efe13aa66eef576ba095e1875ba65fd20" "test" "--frozen", kill_on_drop: false }` [INFO] [stdout] 31cd0d0bbf4b224b8337f5a38e235fd3526aaa7fbe503275b4272e9ba3d7a017 [INFO] running `Command { std: "docker" "start" "-a" "31cd0d0bbf4b224b8337f5a38e235fd3526aaa7fbe503275b4272e9ba3d7a017", kill_on_drop: false }` [INFO] [stderr] Finished test [unoptimized + debuginfo] target(s) in 0.07s [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-5bb42667c50d546e) [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-91baab3471b737b6) [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-72e1cff0733bdc4b) [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-10710722d55ab646) [INFO] [stdout] [INFO] [stdout] running 11 tests [INFO] [stdout] 2023-06-22 18:14:39,006 INFO [kvs_server] Listened at 127.0.0.1:4002, powered by sled, version: 0.1.0 [INFO] [stdout] 2023-06-22 18:14:39,006 INFO [kvs_server] Listened at 127.0.0.1:4005, powered by sled, version: 0.1.0 [INFO] [stdout] 2023-06-22 18:14:39,006 INFO [kvs_server] Listened at 127.0.0.1:4004, powered by kvs, version: 0.1.0 [INFO] [stdout] test client_cli_version ... ok [INFO] [stdout] test client_cli_invalid_subcommand ... ok [INFO] [stdout] test server_cli_version ... ok [INFO] [stdout] test client_cli_no_args ... ok [INFO] [stdout] test client_cli_invalid_get ... ok [INFO] [stdout] test client_cli_invalid_rm ... ok [INFO] [stdout] test client_cli_invalid_set ... ok [INFO] [stdout] 2023-06-22 18:14:39,089 DEBUG [sled::pagecache::snapshot] no previous snapshot found [INFO] [stdout] 2023-06-22 18:14:39,089 DEBUG [sled::pagecache::iterator] ordering before clearing tears: {}, max_header_stable_lsn: 0 [INFO] [stdout] 2023-06-22 18:14:39,089 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] 2023-06-22 18:14:39,089 DEBUG [sled::pagecache::iterator] unable to load new segment: Io(Custom { kind: Other, error: "no segments remaining to iterate over" }) [INFO] [stdout] 2023-06-22 18:14:39,089 DEBUG [sled::pagecache::iterator] filtering out segments after detected tear at (lsn, lid) -1 [INFO] [stdout] 2023-06-22 18:14:39,089 DEBUG [sled::pagecache::iterator] unable to load new segment: Io(Custom { kind: Other, error: "no segments remaining to iterate over" }) [INFO] [stdout] 2023-06-22 18:14:39,089 DEBUG [sled::pagecache::segment] SA starting with tip 0 stable -1 free {} [INFO] [stdout] 2023-06-22 18:14:39,089 DEBUG [sled::pagecache::iobuf] starting log for a totally fresh system [INFO] [stdout] 2023-06-22 18:14:39,089 DEBUG [sled::pagecache::segment] segment accountant returning offset: 0 for lsn 0 on deck: {} [INFO] [stdout] 2023-06-22 18:14:39,089 DEBUG [sled::pagecache::iobuf] starting IoBufs with next_lsn: 0 next_lid: 0 [INFO] [stdout] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache::iobuf] storing lsn 0 in beginning of buffer [INFO] [stdout] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache] load_snapshot loading pages from 0..0 [INFO] [stdout] 2023-06-22 18:14:39,090 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] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache::snapshot] no previous snapshot found [INFO] [stdout] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 0 to 71 [INFO] [stdout] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache::iterator] ordering before clearing tears: {}, max_header_stable_lsn: 0 [INFO] [stdout] 2023-06-22 18:14:39,090 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] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache::iterator] unable to load new segment: Io(Custom { kind: Other, error: "no segments remaining to iterate over" }) [INFO] [stdout] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache::iterator] filtering out segments after detected tear at (lsn, lid) -1 [INFO] [stdout] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache::iterator] unable to load new segment: Io(Custom { kind: Other, error: "no segments remaining to iterate over" }) [INFO] [stdout] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache::segment] SA starting with tip 0 stable -1 free {} [INFO] [stdout] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache::iobuf] starting log for a totally fresh system [INFO] [stdout] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache::segment] segment accountant returning offset: 0 for lsn 0 on deck: {} [INFO] [stdout] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache::iobuf] starting IoBufs with next_lsn: 0 next_lid: 0 [INFO] [stdout] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache::iobuf] storing lsn 0 in beginning of buffer [INFO] [stdout] 2023-06-22 18:14:39,090 DEBUG [sled::pagecache] load_snapshot loading pages from 0..0 [INFO] [stdout] 2023-06-22 18:14:39,091 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] 2023-06-22 18:14:39,093 DEBUG [sled::pagecache::iobuf] wrote lsns 0-70 to disk at offsets 0-70, maxed false complete_len 71 [INFO] [stdout] 2023-06-22 18:14:39,093 DEBUG [sled::pagecache::iobuf] mark_interval(0, 71) [INFO] [stdout] 2023-06-22 18:14:39,093 DEBUG [sled::pagecache::iobuf] new highest interval: 0 - 70 [INFO] [stdout] 2023-06-22 18:14:39,590 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 71 to 96 [INFO] [stdout] 2023-06-22 18:14:39,590 DEBUG [sled::pagecache::iobuf] wrote lsns 71-95 to disk at offsets 71-95, maxed false complete_len 25 [INFO] [stdout] 2023-06-22 18:14:39,590 DEBUG [sled::pagecache::iobuf] mark_interval(71, 25) [INFO] [stdout] 2023-06-22 18:14:39,590 DEBUG [sled::pagecache::iobuf] new highest interval: 71 - 95 [INFO] [stdout] 2023-06-22 18:14:39,591 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 0 to 96 [INFO] [stdout] 2023-06-22 18:14:39,591 DEBUG [sled::pagecache::iobuf] wrote lsns 0-95 to disk at offsets 0-95, maxed false complete_len 96 [INFO] [stdout] 2023-06-22 18:14:39,592 DEBUG [sled::pagecache::iobuf] mark_interval(0, 96) [INFO] [stdout] 2023-06-22 18:14:39,592 DEBUG [sled::pagecache::iobuf] new highest interval: 0 - 95 [INFO] [stdout] test cli_log_configuration ... ok [INFO] [stdout] 2023-06-22 18:14:40,007 INFO [kvs::server] Accept connection from client: 127.0.0.1:37032 [INFO] [stdout] 2023-06-22 18:14:40,007 INFO [kvs::server] Accept connection from client: 127.0.0.1:54862 [INFO] [stdout] 2023-06-22 18:14:40,007 INFO [kvs::server] Client: 127.0.0.1:37032 disconnected [INFO] [stdout] 2023-06-22 18:14:40,007 INFO [kvs::server] Client: 127.0.0.1:54862 disconnected [INFO] [stdout] 2023-06-22 18:14:40,007 DEBUG [kvs::server] [client->server] {"Set":{"key":"key1","value":"value1"}} [INFO] [stdout] 2023-06-22 18:14:40,007 DEBUG [kvs::server] [client->server] {"Set":{"key":"key1","value":"value1"}} [INFO] [stdout] 2023-06-22 18:14:40,007 DEBUG [kvs::server] command: Set { key: "key1", value: "value1" } [INFO] [stdout] 2023-06-22 18:14:40,007 DEBUG [kvs::server] command: Set { key: "key1", value: "value1" } [INFO] [stdout] 2023-06-22 18:14:40,007 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2023-06-22 18:14:40,007 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 96 to 117 [INFO] [stdout] 2023-06-22 18:14:40,007 DEBUG [sled::pagecache::iobuf] wrote lsns 96-116 to disk at offsets 96-116, maxed false complete_len 21 [INFO] [stdout] 2023-06-22 18:14:40,007 DEBUG [sled::pagecache::iobuf] mark_interval(96, 21) [INFO] [stdout] 2023-06-22 18:14:40,007 DEBUG [sled::pagecache::iobuf] new highest interval: 96 - 116 [INFO] [stdout] 2023-06-22 18:14:40,007 DEBUG [sled::pagecache::iobuf] make_stable(116) returning [INFO] [stdout] 2023-06-22 18:14:40,007 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2023-06-22 18:14:40,008 INFO [kvs::server] Accept connection from client: 127.0.0.1:54876 [INFO] [stdout] 2023-06-22 18:14:40,008 INFO [kvs::server] Client: 127.0.0.1:54876 disconnected [INFO] [stdout] 2023-06-22 18:14:40,008 DEBUG [kvs::server] [client->server] {"Get":{"key":"key1"}} [INFO] [stdout] 2023-06-22 18:14:40,008 DEBUG [kvs::server] command: Get { key: "key1" } [INFO] [stdout] 2023-06-22 18:14:40,009 DEBUG [kvs::server] [server->client] Ok("value1") [INFO] [stdout] 2023-06-22 18:14:40,009 INFO [kvs::server] Accept connection from client: 127.0.0.1:37034 [INFO] [stdout] 2023-06-22 18:14:40,009 INFO [kvs::server] Client: 127.0.0.1:37034 disconnected [INFO] [stdout] 2023-06-22 18:14:40,009 DEBUG [kvs::server] [client->server] {"Get":{"key":"key1"}} [INFO] [stdout] 2023-06-22 18:14:40,009 DEBUG [kvs::server] command: Get { key: "key1" } [INFO] [stdout] 2023-06-22 18:14:40,009 DEBUG [kvs::server] [server->client] Ok("value1") [INFO] [stdout] 2023-06-22 18:14:40,010 INFO [kvs::server] Accept connection from client: 127.0.0.1:54880 [INFO] [stdout] 2023-06-22 18:14:40,010 INFO [kvs::server] Client: 127.0.0.1:54880 disconnected [INFO] [stdout] 2023-06-22 18:14:40,010 DEBUG [kvs::server] [client->server] {"Set":{"key":"key1","value":"value2"}} [INFO] [stdout] 2023-06-22 18:14:40,010 DEBUG [kvs::server] command: Set { key: "key1", value: "value2" } [INFO] [stdout] 2023-06-22 18:14:40,010 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2023-06-22 18:14:40,010 INFO [kvs::server] Accept connection from client: 127.0.0.1:37040 [INFO] [stdout] 2023-06-22 18:14:40,010 INFO [kvs::server] Client: 127.0.0.1:37040 disconnected [INFO] [stdout] 2023-06-22 18:14:40,010 DEBUG [kvs::server] [client->server] {"Set":{"key":"key1","value":"value2"}} [INFO] [stdout] 2023-06-22 18:14:40,010 DEBUG [kvs::server] command: Set { key: "key1", value: "value2" } [INFO] [stdout] 2023-06-22 18:14:40,010 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 117 to 138 [INFO] [stdout] 2023-06-22 18:14:40,011 DEBUG [sled::pagecache::iobuf] wrote lsns 117-137 to disk at offsets 117-137, maxed false complete_len 21 [INFO] [stdout] 2023-06-22 18:14:40,011 DEBUG [sled::pagecache::iobuf] mark_interval(117, 21) [INFO] [stdout] 2023-06-22 18:14:40,011 DEBUG [sled::pagecache::iobuf] new highest interval: 117 - 137 [INFO] [stdout] 2023-06-22 18:14:40,011 DEBUG [sled::pagecache::iobuf] make_stable(137) returning [INFO] [stdout] 2023-06-22 18:14:40,011 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2023-06-22 18:14:40,011 INFO [kvs::server] Accept connection from client: 127.0.0.1:54890 [INFO] [stdout] 2023-06-22 18:14:40,011 INFO [kvs::server] Client: 127.0.0.1:54890 disconnected [INFO] [stdout] 2023-06-22 18:14:40,012 DEBUG [kvs::server] [client->server] {"Get":{"key":"key1"}} [INFO] [stdout] 2023-06-22 18:14:40,012 DEBUG [kvs::server] command: Get { key: "key1" } [INFO] [stdout] 2023-06-22 18:14:40,012 DEBUG [kvs::server] [server->client] Ok("value2") [INFO] [stdout] 2023-06-22 18:14:40,012 INFO [kvs::server] Accept connection from client: 127.0.0.1:37044 [INFO] [stdout] 2023-06-22 18:14:40,012 INFO [kvs::server] Client: 127.0.0.1:37044 disconnected [INFO] [stdout] 2023-06-22 18:14:40,012 DEBUG [kvs::server] [client->server] {"Get":{"key":"key1"}} [INFO] [stdout] 2023-06-22 18:14:40,012 DEBUG [kvs::server] command: Get { key: "key1" } [INFO] [stdout] 2023-06-22 18:14:40,012 DEBUG [kvs::server] [server->client] Ok("value2") [INFO] [stdout] 2023-06-22 18:14:40,013 INFO [kvs::server] Accept connection from client: 127.0.0.1:54894 [INFO] [stdout] 2023-06-22 18:14:40,013 INFO [kvs::server] Client: 127.0.0.1:54894 disconnected [INFO] [stdout] 2023-06-22 18:14:40,013 DEBUG [kvs::server] [client->server] {"Get":{"key":"key2"}} [INFO] [stdout] 2023-06-22 18:14:40,013 DEBUG [kvs::server] command: Get { key: "key2" } [INFO] [stdout] 2023-06-22 18:14:40,013 DEBUG [kvs::server] [server->client] Ok("Key: key2 not found") [INFO] [stdout] 2023-06-22 18:14:40,013 INFO [kvs::server] Accept connection from client: 127.0.0.1:37056 [INFO] [stdout] 2023-06-22 18:14:40,013 INFO [kvs::server] Client: 127.0.0.1:37056 disconnected [INFO] [stdout] 2023-06-22 18:14:40,013 DEBUG [kvs::server] [client->server] {"Get":{"key":"key2"}} [INFO] [stdout] 2023-06-22 18:14:40,013 DEBUG [kvs::server] command: Get { key: "key2" } [INFO] [stdout] 2023-06-22 18:14:40,014 DEBUG [kvs::server] [server->client] Ok("Key: key2 not found") [INFO] [stdout] 2023-06-22 18:14:40,014 INFO [kvs::server] Accept connection from client: 127.0.0.1:54904 [INFO] [stdout] 2023-06-22 18:14:40,014 INFO [kvs::server] Client: 127.0.0.1:54904 disconnected [INFO] [stdout] 2023-06-22 18:14:40,014 DEBUG [kvs::server] [client->server] {"Rm":{"key":"key2"}} [INFO] [stdout] 2023-06-22 18:14:40,014 DEBUG [kvs::server] command: Rm { key: "key2" } [INFO] [stdout] 2023-06-22 18:14:40,014 DEBUG [kvs::server] [server->client] Error("Key: key2 not found.") [INFO] [stdout] 2023-06-22 18:14:40,015 INFO [kvs::server] Accept connection from client: 127.0.0.1:37068 [INFO] [stdout] 2023-06-22 18:14:40,015 INFO [kvs::server] Client: 127.0.0.1:37068 disconnected [INFO] [stdout] 2023-06-22 18:14:40,015 DEBUG [kvs::server] [client->server] {"Rm":{"key":"key2"}} [INFO] [stdout] 2023-06-22 18:14:40,015 DEBUG [kvs::server] command: Rm { key: "key2" } [INFO] [stdout] 2023-06-22 18:14:40,015 DEBUG [kvs::server] [server->client] Error("Key: key2 not found.") [INFO] [stdout] 2023-06-22 18:14:40,015 INFO [kvs::server] Accept connection from client: 127.0.0.1:54908 [INFO] [stdout] 2023-06-22 18:14:40,016 INFO [kvs::server] Client: 127.0.0.1:54908 disconnected [INFO] [stdout] 2023-06-22 18:14:40,016 DEBUG [kvs::server] [client->server] {"Set":{"key":"key2","value":"value3"}} [INFO] [stdout] 2023-06-22 18:14:40,016 DEBUG [kvs::server] command: Set { key: "key2", value: "value3" } [INFO] [stdout] 2023-06-22 18:14:40,016 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2023-06-22 18:14:40,016 INFO [kvs::server] Accept connection from client: 127.0.0.1:37070 [INFO] [stdout] 2023-06-22 18:14:40,016 INFO [kvs::server] Client: 127.0.0.1:37070 disconnected [INFO] [stdout] 2023-06-22 18:14:40,016 DEBUG [kvs::server] [client->server] {"Set":{"key":"key2","value":"value3"}} [INFO] [stdout] 2023-06-22 18:14:40,016 DEBUG [kvs::server] command: Set { key: "key2", value: "value3" } [INFO] [stdout] 2023-06-22 18:14:40,016 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 138 to 159 [INFO] [stdout] 2023-06-22 18:14:40,016 DEBUG [sled::pagecache::iobuf] wrote lsns 138-158 to disk at offsets 138-158, maxed false complete_len 21 [INFO] [stdout] 2023-06-22 18:14:40,016 DEBUG [sled::pagecache::iobuf] mark_interval(138, 21) [INFO] [stdout] 2023-06-22 18:14:40,016 DEBUG [sled::pagecache::iobuf] new highest interval: 138 - 158 [INFO] [stdout] 2023-06-22 18:14:40,016 DEBUG [sled::pagecache::iobuf] make_stable(158) returning [INFO] [stdout] 2023-06-22 18:14:40,016 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2023-06-22 18:14:40,017 INFO [kvs::server] Accept connection from client: 127.0.0.1:54916 [INFO] [stdout] 2023-06-22 18:14:40,017 INFO [kvs::server] Client: 127.0.0.1:54916 disconnected [INFO] [stdout] 2023-06-22 18:14:40,017 DEBUG [kvs::server] [client->server] {"Rm":{"key":"key1"}} [INFO] [stdout] 2023-06-22 18:14:40,017 DEBUG [kvs::server] command: Rm { key: "key1" } [INFO] [stdout] 2023-06-22 18:14:40,017 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2023-06-22 18:14:40,018 INFO [kvs::server] Accept connection from client: 127.0.0.1:37072 [INFO] [stdout] 2023-06-22 18:14:40,018 INFO [kvs::server] Client: 127.0.0.1:37072 disconnected [INFO] [stdout] 2023-06-22 18:14:40,018 DEBUG [kvs::server] [client->server] {"Rm":{"key":"key1"}} [INFO] [stdout] 2023-06-22 18:14:40,018 DEBUG [kvs::server] command: Rm { key: "key1" } [INFO] [stdout] 2023-06-22 18:14:40,018 DEBUG [sled::pagecache::iobuf] advancing offset within the current segment from 159 to 173 [INFO] [stdout] 2023-06-22 18:14:40,018 DEBUG [sled::pagecache::iobuf] wrote lsns 159-172 to disk at offsets 159-172, maxed false complete_len 14 [INFO] [stdout] 2023-06-22 18:14:40,018 DEBUG [sled::pagecache::iobuf] mark_interval(159, 14) [INFO] [stdout] 2023-06-22 18:14:40,018 DEBUG [sled::pagecache::iobuf] new highest interval: 159 - 172 [INFO] [stdout] 2023-06-22 18:14:40,018 DEBUG [sled::pagecache::iobuf] make_stable(172) returning [INFO] [stdout] 2023-06-22 18:14:40,018 DEBUG [kvs::server] [server->client] Ok("") [INFO] [stdout] 2023-06-22 18:14:40,019 INFO [kvs_server] Retrieving last work. engine: kvs [INFO] [stdout] 2023-06-22 18:14:40,019 INFO [kvs_server] Listened at 127.0.0.1:4004, powered by kvs, version: 0.1.0 [INFO] [stdout] 2023-06-22 18:14:40,019 INFO [kvs_server] Retrieving last work. engine: sled [INFO] [stdout] 2023-06-22 18:14:40,020 INFO [kvs_server] Listened at 127.0.0.1:4005, powered by sled, version: 0.1.0 [INFO] [stderr] thread 'main' panicked at 'Failed to create a sled engine.: IO error: could not acquire lock on "/tmp/.tmpbMnwvj/db": Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" }', src/bin/kvs-server.rs:63:54 [INFO] [stderr] stack backtrace: [INFO] [stdout] 2023-06-22 18:14:40,024 INFO [kvs_server] Listened at 127.0.0.1:4002, powered by kvs, version: 0.1.0 [INFO] [stderr] 0: 0x55ad93fc79c1 - std::backtrace_rs::backtrace::libunwind::trace::h14bc19b012153c4e [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5 [INFO] [stderr] 1: 0x55ad93fc79c1 - std::backtrace_rs::backtrace::trace_unsynchronized::hbc9aa10cf185443a [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5 [INFO] [stderr] 2: 0x55ad93fc79c1 - std::sys_common::backtrace::_print_fmt::hc902810bae4e6a55 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys_common/backtrace.rs:65:5 [INFO] [stderr] 3: 0x55ad93fc79c1 - ::fmt::hdedc778f0cce9ba3 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys_common/backtrace.rs:44:22 [INFO] [stderr] 4: 0x55ad93fedf3f - core::fmt::rt::Argument::fmt::h72a88a69c8be5aef [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/fmt/rt.rs:138:9 [INFO] [stderr] 5: 0x55ad93fedf3f - core::fmt::write::hbcfa49c4e0540f31 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/fmt/mod.rs:1094:21 [INFO] [stderr] 6: 0x55ad93fc43e7 - std::io::Write::write_fmt::he5dff0b778ee1897 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/io/mod.rs:1714:15 [INFO] [stderr] 7: 0x55ad93fc77d5 - std::sys_common::backtrace::_print::hfdf9478d9ba7451e [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys_common/backtrace.rs:47:5 [INFO] [stderr] 8: 0x55ad93fc77d5 - std::sys_common::backtrace::print::h899b5001459c9891 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys_common/backtrace.rs:34:9 [INFO] [stderr] 9: 0x55ad93fc8cd3 - std::panicking::default_hook::{{closure}}::h6ce7a9fa337d4ae0 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:269:22 [INFO] [stderr] 10: 0x55ad93fc8a64 - std::panicking::default_hook::hb4a3976d57330484 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:288:9 [INFO] [stderr] 11: 0x55ad93fc9259 - std::panicking::rust_panic_with_hook::h9b55d6b1e057a963 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:705:13 [INFO] [stderr] 12: 0x55ad93fc9157 - std::panicking::begin_panic_handler::{{closure}}::hbef64bb3761b3da8 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:597:13 [INFO] [stderr] 13: 0x55ad93fc7df6 - std::sys_common::backtrace::__rust_end_short_backtrace::he627f204232a89a2 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys_common/backtrace.rs:151:18 [INFO] [stderr] 14: 0x55ad93fc8ea2 - rust_begin_unwind [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:593:5 [INFO] [stderr] 15: 0x55ad93c12493 - core::panicking::panic_fmt::h648da198469ea5f4 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/panicking.rs:67:14 [INFO] [stderr] 16: 0x55ad93c12a23 - core::result::unwrap_failed::h1b6ec98f7bf729f5 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/result.rs:1651:5 [INFO] [stderr] 17: 0x55ad93c13bf4 - core::result::Result::expect::h7dc42855b8bc8486 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/result.rs:1033:23 [INFO] [stderr] 18: 0x55ad93c202e8 - kvs_server::main::h622bcd5aa9aeeb16 [INFO] [stderr] at /opt/rustwide/workdir/src/bin/kvs-server.rs:63:13 [INFO] [stderr] 19: 0x55ad93c1988b - core::ops::function::FnOnce::call_once::h1f2b82e48752a3d1 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/ops/function.rs:250:5 [INFO] [stderr] 20: 0x55ad93c12fce - std::sys_common::backtrace::__rust_begin_short_backtrace::h28db20e25a71ff21 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys_common/backtrace.rs:135:18 [INFO] [stderr] 21: 0x55ad93c25bb1 - std::rt::lang_start::{{closure}}::h4d72d5f8422666a7 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/rt.rs:166:18 [INFO] [stderr] 22: 0x55ad93fbf35b - core::ops::function::impls:: for &F>::call_once::h888f3f11ef52c0a2 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/ops/function.rs:284:13 [INFO] [stderr] 23: 0x55ad93fbf35b - std::panicking::try::do_call::hcc54d39d99c06a3e [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:500:40 [INFO] [stderr] 24: 0x55ad93fbf35b - std::panicking::try::h185e5ba28c43fefc [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:464:19 [INFO] [stderr] 25: 0x55ad93fbf35b - std::panic::catch_unwind::hcad7a53aa9fb15b2 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panic.rs:142:14 [INFO] [stderr] 26: 0x55ad93fbf35b - std::rt::lang_start_internal::{{closure}}::h394447eb8d8e755c [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/rt.rs:148:48 [INFO] [stderr] 27: 0x55ad93fbf35b - std::panicking::try::do_call::hfba338ff598a5938 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:500:40 [INFO] [stderr] 28: 0x55ad93fbf35b - std::panicking::try::hb6e292f13fc107b7 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:464:19 [INFO] [stderr] 29: 0x55ad93fbf35b - std::panic::catch_unwind::hb8e434d961fa6a62 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panic.rs:142:14 [INFO] [stderr] 30: 0x55ad93fbf35b - std::rt::lang_start_internal::h86c6f47e41a3902f [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/rt.rs:148:20 [INFO] [stderr] 31: 0x55ad93c25b8a - std::rt::lang_start::haaac2536a683ca47 [INFO] [stderr] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/rt.rs:165:17 [INFO] [stderr] 32: 0x55ad93c2125e - main [INFO] [stderr] 33: 0x7f739131bd90 - [INFO] [stderr] 34: 0x7f739131be40 - __libc_start_main [INFO] [stderr] 35: 0x55ad93c12d25 - _start [INFO] [stderr] 36: 0x0 - [INFO] [stdout] 2023-06-22 18:14:41,019 INFO [kvs::server] Accept connection from client: 127.0.0.1:41998 [INFO] [stdout] 2023-06-22 18:14:41,019 INFO [kvs::server] Client: 127.0.0.1:41998 disconnected [INFO] [stdout] 2023-06-22 18:14:41,019 DEBUG [kvs::server] [client->server] {"Get":{"key":"key2"}} [INFO] [stdout] 2023-06-22 18:14:41,019 DEBUG [kvs::server] command: Get { key: "key2" } [INFO] [stdout] 2023-06-22 18:14:41,020 DEBUG [kvs::server] [server->client] Ok("value3") [INFO] [stdout] 2023-06-22 18:14:41,021 INFO [kvs::server] Accept connection from client: 127.0.0.1:42012 [INFO] [stdout] 2023-06-22 18:14:41,021 INFO [kvs::server] Client: 127.0.0.1:42012 disconnected [INFO] [stdout] 2023-06-22 18:14:41,021 DEBUG [kvs::server] [client->server] {"Get":{"key":"key1"}} [INFO] [stdout] 2023-06-22 18:14:41,021 DEBUG [kvs::server] command: Get { key: "key1" } [INFO] [stdout] 2023-06-22 18:14:41,021 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] thread 'cli_access_server_sled_engine' panicked at 'Unexpected failure. [INFO] [stdout] code-255 [INFO] [stdout] stderr=```Connection refused (os error 111) [INFO] [stdout] ``` [INFO] [stdout] command=`cd "/tmp/.tmpbMnwvj" && "/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] ', /opt/rustwide/cargo-home/registry/src/index.crates.io-6f17d22bba15001f/assert_cmd-0.11.1/src/assert.rs:154:13 [INFO] [stdout] stack backtrace: [INFO] [stdout] 0: 0x557a0c9a9f81 - std::backtrace_rs::backtrace::libunwind::trace::h14bc19b012153c4e [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5 [INFO] [stdout] 1: 0x557a0c9a9f81 - std::backtrace_rs::backtrace::trace_unsynchronized::hbc9aa10cf185443a [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5 [INFO] [stdout] 2: 0x557a0c9a9f81 - std::sys_common::backtrace::_print_fmt::hc902810bae4e6a55 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys_common/backtrace.rs:65:5 [INFO] [stdout] 3: 0x557a0c9a9f81 - ::fmt::hdedc778f0cce9ba3 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys_common/backtrace.rs:44:22 [INFO] [stdout] 4: 0x557a0c9d13cf - core::fmt::rt::Argument::fmt::h72a88a69c8be5aef [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/fmt/rt.rs:138:9 [INFO] [stdout] 5: 0x557a0c9d13cf - core::fmt::write::hbcfa49c4e0540f31 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/fmt/mod.rs:1094:21 [INFO] [stdout] 6: 0x557a0c9a6eb7 - std::io::Write::write_fmt::h18acf23cd92ecffb [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/io/mod.rs:1714:15 [INFO] [stdout] 7: 0x557a0c9a9d95 - std::sys_common::backtrace::_print::hfdf9478d9ba7451e [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys_common/backtrace.rs:47:5 [INFO] [stdout] 8: 0x557a0c9a9d95 - std::sys_common::backtrace::print::h899b5001459c9891 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys_common/backtrace.rs:34:9 [INFO] [stdout] 9: 0x557a0c9aba73 - std::panicking::default_hook::{{closure}}::h6ce7a9fa337d4ae0 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:269:22 [INFO] [stdout] 10: 0x557a0c9ab790 - std::panicking::default_hook::hb4a3976d57330484 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:285:9 [INFO] [stdout] 11: 0x557a0c913332 - as core::ops::function::Fn>::call::h44ae33e5fc62e84d [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/alloc/src/boxed.rs:2007:9 [INFO] [stdout] 12: 0x557a0c913332 - test::test_main::{{closure}}::heeb5020ff7cd0307 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/test/src/lib.rs:134:21 [INFO] [stdout] 13: 0x557a0c9ac16e - as core::ops::function::Fn>::call::hfc4fd049a549cb23 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/alloc/src/boxed.rs:2007:9 [INFO] [stdout] 14: 0x557a0c9ac16e - std::panicking::rust_panic_with_hook::h9b55d6b1e057a963 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:709:13 [INFO] [stdout] 15: 0x557a0c9abef7 - std::panicking::begin_panic_handler::{{closure}}::hbef64bb3761b3da8 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:597:13 [INFO] [stdout] 16: 0x557a0c9aa3b6 - std::sys_common::backtrace::__rust_end_short_backtrace::he627f204232a89a2 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys_common/backtrace.rs:151:18 [INFO] [stdout] 17: 0x557a0c9abc42 - rust_begin_unwind [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:593:5 [INFO] [stdout] 18: 0x557a0c8bcc03 - core::panicking::panic_fmt::h648da198469ea5f4 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/panicking.rs:67:14 [INFO] [stdout] 19: 0x557a0c95a2e0 - assert_cmd::assert::Assert::success::hac90d118e845914c [INFO] [stdout] at /opt/rustwide/cargo-home/registry/src/index.crates.io-6f17d22bba15001f/assert_cmd-0.11.1/src/assert.rs:154:13 [INFO] [stdout] 20: 0x557a0c8cef96 - cli::cli_access_server::h2062602e4ebad88e [INFO] [stdout] at /opt/rustwide/workdir/tests/cli.rs:313:5 [INFO] [stdout] 21: 0x557a0c8d167e - cli::cli_access_server_sled_engine::h790ca7b8e43b2b03 [INFO] [stdout] at /opt/rustwide/workdir/tests/cli.rs:338:5 [INFO] [stdout] 22: 0x557a0c8d1647 - cli::cli_access_server_sled_engine::{{closure}}::h642f9ec3cbd7295b [INFO] [stdout] at /opt/rustwide/workdir/tests/cli.rs:337:36 [INFO] [stdout] 23: 0x557a0c8d3d65 - core::ops::function::FnOnce::call_once::hc3504e9c98bdc68a [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 24: 0x557a0c91877f - core::ops::function::FnOnce::call_once::h6bc30f66680984ea [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 25: 0x557a0c91877f - test::__rust_begin_short_backtrace::h9d1b819fb7088a9f [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/test/src/lib.rs:655:18 [INFO] [stdout] 26: 0x557a0c8e40fc - test::run_test::{{closure}}::he33c05959616bf43 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/test/src/lib.rs:646:30 [INFO] [stdout] 27: 0x557a0c8e40fc - core::ops::function::FnOnce::call_once{{vtable.shim}}::h0efb49a8157434c3 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 28: 0x557a0c917719 - as core::ops::function::FnOnce>::call_once::he0f271a83d677b94 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/alloc/src/boxed.rs:1993:9 [INFO] [stdout] 29: 0x557a0c917719 - as core::ops::function::FnOnce<()>>::call_once::h1659f8ebd02d03f3 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/panic/unwind_safe.rs:271:9 [INFO] [stdout] 30: 0x557a0c917719 - std::panicking::try::do_call::h813b98abe8a1f8c0 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:500:40 [INFO] [stdout] 31: 0x557a0c917719 - std::panicking::try::h885e718b66367fac [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:464:19 [INFO] [stdout] 32: 0x557a0c917719 - std::panic::catch_unwind::h90cca2ccc80a126a [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panic.rs:142:14 [INFO] [stdout] 33: 0x557a0c917719 - test::run_test_in_process::hdd049b79d49b124b [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/test/src/lib.rs:678:27 [INFO] [stdout] 34: 0x557a0c917719 - test::run_test::run_test_inner::{{closure}}::he854e2e6886327bf [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/test/src/lib.rs:572:39 [INFO] [stdout] 35: 0x557a0c8de448 - test::run_test::run_test_inner::{{closure}}::hf97180155b2806bb [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/test/src/lib.rs:599:37 [INFO] [stdout] 36: 0x557a0c8de448 - std::sys_common::backtrace::__rust_begin_short_backtrace::h3b0a6bc3e66eed40 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys_common/backtrace.rs:135:18 [INFO] [stdout] 37: 0x557a0c8e432f - std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}::hde1aad51bdcfbc9c [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/thread/mod.rs:529:17 [INFO] [stdout] 38: 0x557a0c8e432f - as core::ops::function::FnOnce<()>>::call_once::h08b261b7b808318e [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/panic/unwind_safe.rs:271:9 [INFO] [stdout] 39: 0x557a0c8e432f - std::panicking::try::do_call::h1788313a80cc5f82 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:500:40 [INFO] [stdout] 40: 0x557a0c8e432f - std::panicking::try::h130f12a8109721d8 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panicking.rs:464:19 [INFO] [stdout] 41: 0x557a0c8e432f - std::panic::catch_unwind::h0478d33b1b2a7979 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/panic.rs:142:14 [INFO] [stdout] 42: 0x557a0c8e432f - std::thread::Builder::spawn_unchecked_::{{closure}}::h4da82aacc4498de6 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/thread/mod.rs:528:30 [INFO] [stdout] 43: 0x557a0c8e432f - core::ops::function::FnOnce::call_once{{vtable.shim}}::hd7b2c4b1ed0b9ce5 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 44: 0x557a0c9b16b5 - as core::ops::function::FnOnce>::call_once::h8a6d893de3fbe198 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/alloc/src/boxed.rs:1993:9 [INFO] [stdout] 45: 0x557a0c9b16b5 - as core::ops::function::FnOnce>::call_once::hdfd4a760783b8422 [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/alloc/src/boxed.rs:1993:9 [INFO] [stdout] 46: 0x557a0c9b16b5 - std::sys::unix::thread::Thread::new::thread_start::hbf63fe4c32dea9ed [INFO] [stdout] at /rustc/67da586efe13aa66eef576ba095e1875ba65fd20/library/std/src/sys/unix/thread.rs:108:17 [INFO] [stdout] 47: 0x7ff30ef5cb43 - [INFO] [stdout] 48: 0x7ff30efedbb4 - __clone [INFO] [stdout] 49: 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.03s [INFO] [stdout] [INFO] [stderr] error: test failed, to rerun pass `--test cli` [INFO] running `Command { std: "docker" "inspect" "31cd0d0bbf4b224b8337f5a38e235fd3526aaa7fbe503275b4272e9ba3d7a017", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "31cd0d0bbf4b224b8337f5a38e235fd3526aaa7fbe503275b4272e9ba3d7a017", kill_on_drop: false }` [INFO] [stdout] 31cd0d0bbf4b224b8337f5a38e235fd3526aaa7fbe503275b4272e9ba3d7a017