[INFO] fetching crate kad 0.6.1... [INFO] testing kad-0.6.1 against 1.55.0 for beta-1.56-1 [INFO] extracting crate kad 0.6.1 into /workspace/builds/worker-61/source [INFO] validating manifest of crates.io crate kad 0.6.1 on toolchain 1.55.0 [INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+1.55.0" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }` [INFO] started tweaking crates.io crate kad 0.6.1 [INFO] finished tweaking crates.io crate kad 0.6.1 [INFO] tweaked toml for crates.io crate kad 0.6.1 written to /workspace/builds/worker-61/source/Cargo.toml [INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+1.55.0" "generate-lockfile" "--manifest-path" "Cargo.toml" "-Zno-index-update", kill_on_drop: false }` [INFO] [stderr] Blocking waiting for file lock on package cache [INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+1.55.0" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }` [INFO] [stderr] Downloading crates ... [INFO] [stderr] Downloaded futures-timer v0.1.1 [INFO] [stderr] Downloaded rr-mux v0.10.1 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-61/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-61/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:a89201d6b5b9fd45c15d5952ece0a0129e7e80cb26ec023fd59cf09bc26f1604" "/opt/rustwide/cargo-home/bin/cargo" "+1.55.0" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }` [INFO] [stdout] c55afa54afa971fafb09869099ee00a3e3abe0ddebe65f5d0d574828e19a84b7 [INFO] running `Command { std: "docker" "start" "-a" "c55afa54afa971fafb09869099ee00a3e3abe0ddebe65f5d0d574828e19a84b7", kill_on_drop: false }` [INFO] running `Command { std: "docker" "inspect" "c55afa54afa971fafb09869099ee00a3e3abe0ddebe65f5d0d574828e19a84b7", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "c55afa54afa971fafb09869099ee00a3e3abe0ddebe65f5d0d574828e19a84b7", kill_on_drop: false }` [INFO] [stdout] c55afa54afa971fafb09869099ee00a3e3abe0ddebe65f5d0d574828e19a84b7 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-61/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-61/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=warn" "-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:a89201d6b5b9fd45c15d5952ece0a0129e7e80cb26ec023fd59cf09bc26f1604" "/opt/rustwide/cargo-home/bin/cargo" "+1.55.0" "build" "--frozen" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 031f458e8259ecd88e463058e53dc0092627ba34e33efa70c9c4191b58b3661a [INFO] running `Command { std: "docker" "start" "-a" "031f458e8259ecd88e463058e53dc0092627ba34e33efa70c9c4191b58b3661a", kill_on_drop: false }` [INFO] [stderr] Compiling syn v1.0.76 [INFO] [stderr] Compiling futures-core v0.3.17 [INFO] [stderr] Compiling futures-channel v0.3.17 [INFO] [stderr] Compiling futures-sink v0.3.17 [INFO] [stderr] Compiling pin-project-lite v0.2.7 [INFO] [stderr] Compiling unicode-segmentation v1.8.0 [INFO] [stderr] Compiling slab v0.4.4 [INFO] [stderr] Compiling pin-utils v0.1.0 [INFO] [stderr] Compiling unicode-width v0.1.8 [INFO] [stderr] Compiling futures-io v0.3.17 [INFO] [stderr] Compiling vec_map v0.8.2 [INFO] [stderr] Compiling strsim v0.8.0 [INFO] [stderr] Compiling log v0.4.14 [INFO] [stderr] Compiling ansi_term v0.11.0 [INFO] [stderr] Compiling futures v0.1.31 [INFO] [stderr] Compiling quick-error v1.2.3 [INFO] [stderr] Compiling strum v0.21.0 [INFO] [stderr] Compiling num-traits v0.2.14 [INFO] [stderr] Compiling num-integer v0.1.44 [INFO] [stderr] Compiling num-bigint v0.2.6 [INFO] [stderr] Compiling num-complex v0.2.4 [INFO] [stderr] Compiling num-rational v0.2.4 [INFO] [stderr] Compiling num-iter v0.1.42 [INFO] [stderr] Compiling rand_core v0.3.1 [INFO] [stderr] Compiling value-bag v1.0.0-alpha.7 [INFO] [stderr] Compiling tracing-core v0.1.19 [INFO] [stderr] Compiling proc-macro-nested v0.1.7 [INFO] [stderr] Compiling futures-task v0.3.17 [INFO] [stderr] Compiling atty v0.2.14 [INFO] [stderr] Compiling textwrap v0.11.0 [INFO] [stderr] Compiling rand v0.5.6 [INFO] [stderr] Compiling humantime v1.3.0 [INFO] [stderr] Compiling heck v0.3.3 [INFO] [stderr] Compiling clap v2.33.3 [INFO] [stderr] Compiling futures-timer v0.1.1 [INFO] [stderr] Compiling proc-macro-error v1.0.4 [INFO] [stderr] Compiling futures-macro v0.3.17 [INFO] [stderr] Compiling ctor v0.1.21 [INFO] [stderr] Compiling structopt-derive v0.4.16 [INFO] [stderr] Compiling tracing-attributes v0.1.15 [INFO] [stderr] Compiling strum_macros v0.21.1 [INFO] [stderr] Compiling async-trait v0.1.51 [INFO] [stderr] Compiling tracing v0.1.26 [INFO] [stderr] Compiling futures-util v0.3.17 [INFO] [stderr] Compiling num v0.2.1 [INFO] [stderr] Compiling structopt v0.3.23 [INFO] [stderr] Compiling futures-executor v0.3.17 [INFO] [stderr] Compiling futures v0.3.17 [INFO] [stderr] Compiling kad v0.6.1 (/opt/rustwide/workdir) [INFO] [stderr] Finished dev [unoptimized + debuginfo] target(s) in 44.65s [INFO] running `Command { std: "docker" "inspect" "031f458e8259ecd88e463058e53dc0092627ba34e33efa70c9c4191b58b3661a", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "031f458e8259ecd88e463058e53dc0092627ba34e33efa70c9c4191b58b3661a", kill_on_drop: false }` [INFO] [stdout] 031f458e8259ecd88e463058e53dc0092627ba34e33efa70c9c4191b58b3661a [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-61/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-61/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=warn" "-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:a89201d6b5b9fd45c15d5952ece0a0129e7e80cb26ec023fd59cf09bc26f1604" "/opt/rustwide/cargo-home/bin/cargo" "+1.55.0" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] b0eac4c69a5d976c68e4510a8ab7d3e2abbef1b7d8a3fb030ce79be0b071a04c [INFO] running `Command { std: "docker" "start" "-a" "b0eac4c69a5d976c68e4510a8ab7d3e2abbef1b7d8a3fb030ce79be0b071a04c", kill_on_drop: false }` [INFO] [stderr] Compiling cache-padded v1.1.1 [INFO] [stderr] Compiling parking v2.0.0 [INFO] [stderr] Compiling fastrand v1.5.0 [INFO] [stderr] Compiling strsim v0.9.3 [INFO] [stderr] Compiling ident_case v1.0.1 [INFO] [stderr] Compiling fnv v1.0.7 [INFO] [stderr] Compiling waker-fn v1.1.0 [INFO] [stderr] Compiling event-listener v2.5.1 [INFO] [stderr] Compiling once_cell v1.8.0 [INFO] [stderr] Compiling async-task v4.0.3 [INFO] [stderr] Compiling derive_builder v0.9.0 [INFO] [stderr] Compiling atomic-waker v1.0.0 [INFO] [stderr] Compiling termcolor v1.1.2 [INFO] [stderr] Compiling crossbeam-utils v0.8.5 [INFO] [stderr] Compiling socket2 v0.4.1 [INFO] [stderr] Compiling async-attributes v1.1.2 [INFO] [stderr] Compiling chrono v0.4.19 [INFO] [stderr] Compiling polling v2.1.0 [INFO] [stderr] Compiling kv-log-macro v1.0.7 [INFO] [stderr] Compiling concurrent-queue v1.2.2 [INFO] [stderr] Compiling async-mutex v1.4.0 [INFO] [stderr] Compiling async-lock v2.4.0 [INFO] [stderr] Compiling darling_core v0.10.2 [INFO] [stderr] Compiling futures-lite v1.12.0 [INFO] [stderr] Compiling async-channel v1.6.1 [INFO] [stderr] Compiling simplelog v0.8.0 [INFO] [stderr] Compiling blocking v1.0.2 [INFO] [stderr] Compiling async-io v1.6.0 [INFO] [stderr] Compiling async-executor v1.4.1 [INFO] [stderr] Compiling async-global-executor v2.0.2 [INFO] [stderr] Compiling async-std v1.10.0 [INFO] [stderr] Compiling darling_macro v0.10.2 [INFO] [stderr] Compiling darling v0.10.2 [INFO] [stderr] Compiling derive_builder_core v0.9.0 [INFO] [stderr] Compiling rr-mux v0.10.1 [INFO] [stderr] Compiling kad v0.6.1 (/opt/rustwide/workdir) [INFO] [stdout] warning: unused import: `std::marker::PhantomData` [INFO] [stdout] --> tests/main.rs:10:5 [INFO] [stdout] | [INFO] [stdout] 10 | use std::marker::PhantomData; [INFO] [stdout] | ^^^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stdout] | [INFO] [stdout] = note: `#[warn(unused_imports)]` on by default [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: unused import: `kad::store::HashMapStore` [INFO] [stdout] --> tests/main.rs:15:5 [INFO] [stdout] | [INFO] [stdout] 15 | use kad::store::HashMapStore; [INFO] [stdout] | ^^^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: unused import: `kad::table::KNodeTable` [INFO] [stdout] --> tests/main.rs:16:5 [INFO] [stdout] | [INFO] [stdout] 16 | use kad::table::KNodeTable; [INFO] [stdout] | ^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: unused import: `futures::executor::block_on` [INFO] [stdout] --> tests/main.rs:20:5 [INFO] [stdout] | [INFO] [stdout] 20 | use futures::executor::block_on; [INFO] [stdout] | ^^^^^^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: unused variable: `sink_rx` [INFO] [stdout] --> tests/main.rs:46:27 [INFO] [stdout] | [INFO] [stdout] 46 | let (sink_tx, sink_rx) = mpsc::channel(10); [INFO] [stdout] | ^^^^^^^ help: if this is intentional, prefix it with an underscore: `_sink_rx` [INFO] [stdout] | [INFO] [stdout] = note: `#[warn(unused_variables)]` on by default [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: struct is never constructed: `MockPeer` [INFO] [stdout] --> tests/main.rs:22:8 [INFO] [stdout] | [INFO] [stdout] 22 | struct MockPeer { [INFO] [stdout] | ^^^^^^^^ [INFO] [stdout] | [INFO] [stdout] = note: `#[warn(dead_code)]` on by default [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: type alias is never used: `PeerMap` [INFO] [stdout] --> tests/main.rs:26:1 [INFO] [stdout] | [INFO] [stdout] 26 | type PeerMap = HashMap>; [INFO] [stdout] | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: struct is never constructed: `MockNetwork` [INFO] [stdout] --> tests/main.rs:28:8 [INFO] [stdout] | [INFO] [stdout] 28 | struct MockNetwork { [INFO] [stdout] | ^^^^^^^^^^^ [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: associated function is never used: `new` [INFO] [stdout] --> tests/main.rs:38:12 [INFO] [stdout] | [INFO] [stdout] 38 | pub fn new(config: Config, nodes: &[Entry]) -> MockNetwork { [INFO] [stdout] | ^^^ [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: 9 warnings emitted [INFO] [stdout] [INFO] [stdout] [INFO] [stderr] Finished test [unoptimized + debuginfo] target(s) in 16.72s [INFO] running `Command { std: "docker" "inspect" "b0eac4c69a5d976c68e4510a8ab7d3e2abbef1b7d8a3fb030ce79be0b071a04c", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "b0eac4c69a5d976c68e4510a8ab7d3e2abbef1b7d8a3fb030ce79be0b071a04c", kill_on_drop: false }` [INFO] [stdout] b0eac4c69a5d976c68e4510a8ab7d3e2abbef1b7d8a3fb030ce79be0b071a04c [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-61/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-61/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=warn" "-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:a89201d6b5b9fd45c15d5952ece0a0129e7e80cb26ec023fd59cf09bc26f1604" "/opt/rustwide/cargo-home/bin/cargo" "+1.55.0" "test" "--frozen", kill_on_drop: false }` [INFO] [stdout] 8213608a84fc0b053a63b8c0255afc13309cd59d8f472f99f0e258e2272328f4 [INFO] running `Command { std: "docker" "start" "-a" "8213608a84fc0b053a63b8c0255afc13309cd59d8f472f99f0e258e2272328f4", kill_on_drop: false }` [INFO] [stderr] Blocking waiting for file lock on package cache [INFO] [stderr] warning: unused import: `std::marker::PhantomData` [INFO] [stderr] --> tests/main.rs:10:5 [INFO] [stderr] | [INFO] [stderr] 10 | use std::marker::PhantomData; [INFO] [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stderr] | [INFO] [stderr] = note: `#[warn(unused_imports)]` on by default [INFO] [stderr] [INFO] [stderr] warning: unused import: `kad::store::HashMapStore` [INFO] [stderr] --> tests/main.rs:15:5 [INFO] [stderr] | [INFO] [stderr] 15 | use kad::store::HashMapStore; [INFO] [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stderr] [INFO] [stderr] warning: unused import: `kad::table::KNodeTable` [INFO] [stderr] --> tests/main.rs:16:5 [INFO] [stderr] | [INFO] [stderr] 16 | use kad::table::KNodeTable; [INFO] [stderr] | ^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stderr] [INFO] [stderr] warning: unused import: `futures::executor::block_on` [INFO] [stderr] --> tests/main.rs:20:5 [INFO] [stderr] | [INFO] [stderr] 20 | use futures::executor::block_on; [INFO] [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stderr] [INFO] [stderr] warning: unused variable: `sink_rx` [INFO] [stderr] --> tests/main.rs:46:27 [INFO] [stderr] | [INFO] [stderr] 46 | let (sink_tx, sink_rx) = mpsc::channel(10); [INFO] [stderr] | ^^^^^^^ help: if this is intentional, prefix it with an underscore: `_sink_rx` [INFO] [stderr] | [INFO] [stderr] = note: `#[warn(unused_variables)]` on by default [INFO] [stderr] [INFO] [stderr] warning: struct is never constructed: `MockPeer` [INFO] [stderr] --> tests/main.rs:22:8 [INFO] [stderr] | [INFO] [stderr] 22 | struct MockPeer { [INFO] [stderr] | ^^^^^^^^ [INFO] [stderr] | [INFO] [stderr] = note: `#[warn(dead_code)]` on by default [INFO] [stderr] [INFO] [stderr] warning: type alias is never used: `PeerMap` [INFO] [stderr] --> tests/main.rs:26:1 [INFO] [stderr] | [INFO] [stderr] 26 | type PeerMap = HashMap>; [INFO] [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stderr] [INFO] [stderr] warning: struct is never constructed: `MockNetwork` [INFO] [stderr] --> tests/main.rs:28:8 [INFO] [stderr] | [INFO] [stderr] 28 | struct MockNetwork { [INFO] [stderr] | ^^^^^^^^^^^ [INFO] [stderr] [INFO] [stderr] warning: associated function is never used: `new` [INFO] [stderr] --> tests/main.rs:38:12 [INFO] [stderr] | [INFO] [stderr] 38 | pub fn new(config: Config, nodes: &[Entry]) -> MockNetwork { [INFO] [stderr] | ^^^ [INFO] [stderr] [INFO] [stderr] warning: `kad` (test "main") generated 9 warnings [INFO] [stderr] Finished test [unoptimized + debuginfo] target(s) in 1.06s [INFO] [stderr] Running unittests (/opt/rustwide/target/debug/deps/kad-5396aa824d6050f8) [INFO] [stdout] [INFO] [stdout] running 11 tests [INFO] [stdout] test dht::tests::test_receive_store ... ok [INFO] [stdout] test dht::tests::test_receive_ping ... ok [INFO] [stdout] test table::kbucket::test::test_k_bucket_update ... ok [INFO] [stdout] test dht::tests::test_receive_find_nodes ... ok [INFO] [stdout] test dht::tests::test_receive_common ... ok [INFO] [stdout] test dht::tests::test_receive_find_values ... ok [INFO] [stdout] test table::knodetable::test::test_k_node_table ... ok [INFO] [stdout] 01:23:24 [INFO] Start connect [INFO] [stdout] 01:23:24 [INFO] Search round 0 [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480 (Connect) start [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Initiating Connect operation (15480), sending FindNode([8]) request to 2 peers [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480 entering searching state [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480 response from [3]: NodesFound([8], 1 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480, adding 1 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480, add node [9] [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: update node [3] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480 response from [2]: NodesFound([8], 1 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480, adding 1 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480, add node [10] [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: update node [2] state: Complete [INFO] [stdout] 01:23:24 [INFO] Search round 1 [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480, all responses received, re-starting search [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480 (Connect) search iteration 1 [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480 nearest: [Entry { id: [10], info: 400, seen: None, state: Ok, frozen: false }, Entry { id: [9], info: 400, seen: None, state: Ok, frozen: false }] [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480 issuing search request: FindNode([8]) to: [Entry { id: [9], info: 400, seen: None, state: Ok, frozen: false }, Entry { id: [10], info: 400, seen: None, state: Ok, frozen: false }] [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480 entering searching state [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480 response from [9]: NodesFound([8], 1 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480, adding 1 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480, add node [9] [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: update node [9] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480 response from [10]: NodesFound([8], 1 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480, adding 1 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480, add node [10] [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: update node [10] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480 search complete! [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operation 15480 entering done state [INFO] [stdout] 01:23:24 [DEBUG] (2) kad::dht: Operating 15480 (Connect) done [INFO] [stdout] 01:23:24 [INFO] Expecting completion [INFO] [stdout] 01:23:24 [INFO] Start store [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Registering operation id: 8500 [INFO] [stdout] 01:23:24 [INFO] Search round 0 [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 (Store) start [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Initiating Store operation (8500), sending FindNode([12]) request to 2 peers [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 entering searching state [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 response from [2]: NodesFound([12], 1 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500, adding 1 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500, add node [9] [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: update node [2] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 response from [3]: NodesFound([12], 1 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500, adding 1 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500, add node [10] [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: update node [3] state: Complete [INFO] [stdout] 01:23:24 [INFO] Search round 1 [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500, all responses received, re-starting search [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 (Store) search iteration 1 [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 nearest: [Entry { id: [9], info: 400, seen: None, state: Ok, frozen: false }, Entry { id: [10], info: 400, seen: None, state: Ok, frozen: false }] [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 issuing search request: FindNode([12]) to: [Entry { id: [9], info: 400, seen: None, state: Ok, frozen: false }, Entry { id: [10], info: 400, seen: None, state: Ok, frozen: false }] [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 entering searching state [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 response from [9]: NodesFound([12], 0 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500, adding 0 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: update node [9] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 response from [10]: NodesFound([12], 0 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500, adding 0 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: update node [10] state: Complete [INFO] [stdout] 01:23:24 [INFO] Store round [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 search complete! [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 (Store) issuing Store([12], 1 values) request to 2 peers [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 response from [9]: ValuesFound([12], 1 values) [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500, adding 1 values to map [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: update node [9] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 response from [10]: ValuesFound([12], 1 values) [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500, adding 1 values to map [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: update node [10] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 (Store) entering done state [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operating 8500 (Store) done [INFO] [stdout] 01:23:24 [DEBUG] (5) kad::dht: Operation 8500 stored at 2 peers [INFO] [stdout] 01:23:24 [INFO] Expecting store completion [INFO] [stdout] 01:23:24 [INFO] Start locate [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Registering operation id: 3831 [INFO] [stdout] 01:23:24 [INFO] Search round 0 [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 (FindValues) start [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Initiating FindValues operation (3831), sending FindNode([12]) request to 2 peers [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 entering searching state [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 response from [3]: NodesFound([12], 1 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831, adding 1 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831, add node [9] [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: update node [3] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 response from [2]: NodesFound([12], 1 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831, adding 1 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831, add node [10] [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: update node [2] state: Complete [INFO] [stdout] 01:23:24 [INFO] Search round 1 [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831, all responses received, re-starting search [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 (FindValues) search iteration 1 [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 nearest: [Entry { id: [10], info: 400, seen: None, state: Ok, frozen: false }, Entry { id: [9], info: 400, seen: None, state: Ok, frozen: false }] [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 issuing search request: FindNode([12]) to: [Entry { id: [9], info: 400, seen: None, state: Ok, frozen: false }, Entry { id: [10], info: 400, seen: None, state: Ok, frozen: false }] [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 entering searching state [INFO] [stdout] test dht::connect::tests::test_connect ... ok [INFO] [stdout] test dht::store::tests::test_store ... ok [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 response from [9]: NodesFound([12], 0 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831, adding 0 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: update node [9] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 response from [10]: NodesFound([12], 0 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831, adding 0 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: update node [10] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 search complete! [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 (FindValues) issuing FindValues([12]) request to 2 peers [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 response from [9]: ValuesFound([12], 1 values) [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831, adding 1 values to map [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: update node [9] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 response from [10]: ValuesFound([12], 1 values) [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831, adding 1 values to map [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: update node [10] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 (FindValues) entering done state [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operating 3831 (FindValues) done [INFO] [stdout] 01:23:24 [DEBUG] (4) kad::dht: Operation 3831 values found: [500, 500] [INFO] [stdout] 01:23:24 [INFO] Expecting search completion [INFO] [stdout] test dht::search::tests::test_search ... ok [INFO] [stdout] 01:23:24 [INFO] Start locate [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Registering operation id: 1286 [INFO] [stdout] 01:23:24 [INFO] Search round 0 [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286 (FindNode) start [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Initiating FindNode operation (1286), sending FindNode([9]) request to 2 peers [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286 entering searching state [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286 response from [2]: NodesFound([9], 1 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286, adding 1 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286, add node [9] [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: update node [2] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286 response from [3]: NodesFound([9], 1 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286, adding 1 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286, add node [10] [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: update node [3] state: Complete [INFO] [stdout] 01:23:24 [INFO] Search round 1 [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286, all responses received, re-starting search [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286 (FindNode) search iteration 1 [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286 nearest: [Entry { id: [10], info: 400, seen: None, state: Ok, frozen: false }, Entry { id: [9], info: 400, seen: None, state: Ok, frozen: false }] [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286 issuing search request: FindNode([9]) to: [Entry { id: [9], info: 400, seen: None, state: Ok, frozen: false }, Entry { id: [10], info: 400, seen: None, state: Ok, frozen: false }] [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286 entering searching state [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286 response from [9]: NodesFound([9], 1 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286, adding 1 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286, add node [9] [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: update node [9] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286 response from [10]: NodesFound([9], 1 nodes) [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286, adding 1 nodes to map [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286, add node [10] [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: update node [10] state: Complete [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286 search complete! [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operation 1286 entering done state [INFO] [stdout] 01:23:24 [DEBUG] (3) kad::dht: Operating 1286 (FindNode) done [INFO] [stdout] 01:23:24 [INFO] Expecting completion [INFO] [stdout] test dht::locate::tests::test_lookup ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 11 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.22s [INFO] [stdout] [INFO] [stderr] Running tests/main.rs (/opt/rustwide/target/debug/deps/main-127bfb894b44e7cb) [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] Doc-tests kad [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] running `Command { std: "docker" "inspect" "8213608a84fc0b053a63b8c0255afc13309cd59d8f472f99f0e258e2272328f4", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "8213608a84fc0b053a63b8c0255afc13309cd59d8f472f99f0e258e2272328f4", kill_on_drop: false }` [INFO] [stdout] 8213608a84fc0b053a63b8c0255afc13309cd59d8f472f99f0e258e2272328f4