[INFO] fetching crate swarmforge 0.1.0...
[INFO] testing swarmforge-0.1.0 against 1.99.0-beta.8 for beta-1.100-2
[INFO] extracting crate swarmforge 0.1.0 into /workspace/builds/worker-6-tc1/source
[INFO] started tweaking crates.io crate swarmforge 0.1.0
[INFO] removed 0 missing examples
[INFO] finished tweaking crates.io crate swarmforge 0.1.0
[INFO] tweaked toml for crates.io crate swarmforge 0.1.0 written to /workspace/builds/worker-6-tc1/source/Cargo.toml
[INFO] validating manifest of crates.io crate swarmforge 0.1.0 on toolchain 1.99.0-beta.8
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.99.0-beta.8" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate swarmforge 0.1.0 already has a lockfile, it will not be regenerated
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.99.0-beta.8" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Updating crates.io index
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded utoipa-axum v0.2.0
[INFO] [stderr]   Downloaded wasm-bindgen-futures v0.4.73
[INFO] [stderr]   Downloaded swarmforge-upnp-serve v0.1.0
[INFO] [stderr]   Downloaded swarmforge-upnp v0.1.0
[INFO] [stderr]   Downloaded tokio-socks v0.5.3
[INFO] [stderr]   Downloaded web-sys v0.3.100
[INFO] [stderr]   Downloaded quick-xml v0.40.1
[INFO] [stderr]   Downloaded swarmforge-tracker-comms v0.1.0
[INFO] [stderr]   Downloaded leaky-bucket v1.1.2
[INFO] [stderr]   Downloaded swarmforge-peer-protocol v0.1.0
[INFO] [stderr]   Downloaded swarmforge-dht v0.1.0
[INFO] [stderr]   Downloaded swarmforge-lsd v0.1.0
[INFO] [stderr]   Downloaded whoami v2.1.2
[INFO] [stderr]   Downloaded size_format v1.0.2
[INFO] [stderr]   Downloaded rsqlite-vfs v0.1.1
[INFO] [stderr]   Downloaded rlimit v0.11.0
[INFO] [stderr]   Downloaded rusqlite v0.39.0
[INFO] [stderr]   Downloaded inotify v0.11.2
[INFO] [stderr]   Downloaded kqueue v1.2.0
[INFO] [stderr]   Downloaded metrics-exporter-prometheus v0.18.3
[INFO] [stderr]   Downloaded metrics-util v0.20.4
[INFO] [stderr]   Downloaded rapidhash v4.4.1
[INFO] [stderr]   Downloaded metrics v0.24.6
[INFO] [stderr]   Downloaded left-right v0.11.7
[INFO] [stderr]   Downloaded evmap v11.0.0
[INFO] [stderr]   Downloaded governor v0.10.4
[INFO] [stderr]   Downloaded intervaltree v0.2.7
[INFO] [stderr]   Downloaded librqbit-utp v0.7.0
[INFO] [stderr]   Downloaded hashbag v0.1.13
[INFO] [stderr]   Downloaded dontfrag v1.0.1
[INFO] [stderr]   Downloaded console-subscriber v0.5.0
[INFO] [stderr]   Downloaded mediatype v0.19.20
[INFO] [stderr]   Downloaded feed-rs v2.3.1
[INFO] [stderr]   Downloaded hdrhistogram v7.5.4
[INFO] [stderr]   Downloaded console-api v0.9.0
[INFO] [stderr]   Downloaded sqlite-wasm-rs v0.5.5
[INFO] [stderr]   Downloaded axum-extra v0.12.6
[INFO] [stderr]   Downloaded serde_html_form v0.2.8
[INFO] [stderr]   Downloaded async-compression v0.4.42
[INFO] [stderr]   Downloaded async-backtrace v0.2.7
[INFO] [stderr]   Downloaded async-backtrace-attributes v0.2.7
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-6-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-m" "1610612736" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:3111399a4047eeb3a02b7a90e478d715f38a8c6669b5c4b49d30a17385265909" "sleep" "infinity", kill_on_drop: false }`
[INFO] [stdout] 0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453
[INFO] running `Command { std: "docker" "start" "0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-w" "/opt/rustwide/workdir" "--user" "0:0" "0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stderr]    Compiling libc v0.2.186
[INFO] [stderr]    Compiling memchr v2.8.2
[INFO] [stderr]    Compiling serde_core v1.0.228
[INFO] [stderr]    Compiling bitflags v2.13.0
[INFO] [stderr]    Compiling syn v2.0.117
[INFO] [stderr]    Compiling num-traits v0.2.19
[INFO] [stderr]    Compiling http v1.4.2
[INFO] [stderr]    Compiling openssl v0.10.80
[INFO] [stderr]    Compiling httpdate v1.0.3
[INFO] [stderr]    Compiling matchit v0.8.4
[INFO] [stderr]    Compiling anyhow v1.0.102
[INFO] [stderr]    Compiling typewit v1.15.2
[INFO] [stderr]    Compiling swarmforge-clone-to-owned v0.1.0
[INFO] [stderr]    Compiling getrandom v0.3.4
[INFO] [stderr]    Compiling fastrand v2.4.1
[INFO] [stderr]    Compiling hex v0.3.2
[INFO] [stderr]    Compiling either v1.16.0
[INFO] [stderr]    Compiling chacha20 v0.10.0
[INFO] [stderr]    Compiling log v0.4.32
[INFO] [stderr]    Compiling const_panic v0.2.15
[INFO] [stderr]    Compiling itertools v0.14.0
[INFO] [stderr]    Compiling radium v0.7.0
[INFO] [stderr]    Compiling num-rational v0.2.4
[INFO] [stderr]    Compiling assert_cfg v0.1.0
[INFO] [stderr]    Compiling num-complex v0.2.4
[INFO] [stderr]    Compiling aho-corasick v1.1.4
[INFO] [stderr]    Compiling chardetng v1.0.0
[INFO] [stderr]    Compiling simd-adler32 v0.3.9
[INFO] [stderr]    Compiling tap v1.0.1
[INFO] [stderr]    Compiling wyz v0.5.1
[INFO] [stderr]    Compiling miniz_oxide v0.8.9
[INFO] [stderr]    Compiling portable-atomic v1.13.1
[INFO] [stderr]    Compiling hashbrown v0.14.5
[INFO] [stderr]    Compiling atoi v3.0.0
[INFO] [stderr]    Compiling num-integer v0.1.46
[INFO] [stderr]    Compiling aws-lc-rs v1.17.0
[INFO] [stderr]    Compiling funty v2.0.0
[INFO] [stderr]    Compiling nix v0.31.3
[INFO] [stderr]    Compiling flate2 v1.1.9
[INFO] [stderr]    Compiling regex-automata v0.4.14
[INFO] [stderr]    Compiling num-iter v0.1.45
[INFO] [stderr]    Compiling rapidhash v4.4.1
[INFO] [stderr]    Compiling http-body v1.0.1
[INFO] [stderr]    Compiling http-body-util v0.1.3
[INFO] [stderr]    Compiling raw-cpuid v11.6.0
[INFO] [stderr]    Compiling bitvec v1.0.1
[INFO] [stderr]    Compiling virtue v0.0.18
[INFO] [stderr]    Compiling rlimit v0.11.0
[INFO] [stderr]    Compiling jobserver v0.1.34
[INFO] [stderr]    Compiling compression-core v0.4.32
[INFO] [stderr]    Compiling num v0.2.1
[INFO] [stderr]    Compiling generic-array v0.12.4
[INFO] [stderr]    Compiling serde_json v1.0.150
[INFO] [stderr]    Compiling serde_path_to_error v0.1.20
[INFO] [stderr]    Compiling cc v1.2.63
[INFO] [stderr]    Compiling compression-codecs v0.4.38
[INFO] [stderr]    Compiling serde_html_form v0.2.8
[INFO] [stderr]    Compiling metrics v0.24.6
[INFO] [stderr]    Compiling socket2 v0.6.4
[INFO] [stderr]    Compiling mio v1.2.1
[INFO] [stderr]    Compiling parking_lot_core v0.9.12
[INFO] [stderr]    Compiling getrandom v0.4.2
[INFO] [stderr]    Compiling dirs-sys v0.5.0
[INFO] [stderr]    Compiling directories v6.0.0
[INFO] [stderr]    Compiling rand_core v0.9.5
[INFO] [stderr]    Compiling parking_lot v0.12.5
[INFO] [stderr]    Compiling rand v0.10.1
[INFO] [stderr]    Compiling uuid v1.23.3
[INFO] [stderr]    Compiling rand_chacha v0.9.0
[INFO] [stderr]    Compiling bincode_derive v2.0.1
[INFO] [stderr]    Compiling swarmforge v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]    Compiling quick-xml v0.37.5
[INFO] [stderr]    Compiling cmake v0.1.58
[INFO] [stderr]    Compiling rand v0.9.4
[INFO] [stderr]    Compiling ringbuf v0.4.8
[INFO] [stderr]    Compiling spinning_top v0.3.0
[INFO] [stderr]    Compiling siphasher v1.0.3
[INFO] [stderr]    Compiling urlencoding v2.1.3
[INFO] [stderr]    Compiling nonzero_ext v0.3.0
[INFO] [stderr]    Compiling unty v0.0.4
[INFO] [stderr]    Compiling bincode v2.0.1
[INFO] [stderr]    Compiling memmap2 v0.9.10
[INFO] [stderr]    Compiling size_format v1.0.2
[INFO] [stderr]    Compiling intervaltree v0.2.7
[INFO] [stderr]    Compiling openssl-sys v0.9.116
[INFO] [stderr]    Compiling network-interface v2.0.5
[INFO] [stderr]    Compiling aws-lc-sys v0.41.0
[INFO] [stderr]    Compiling quanta v0.12.6
[INFO] [stderr]    Compiling bstr v1.12.1
[INFO] [stderr]    Compiling regex v1.12.4
[INFO] [stderr]    Compiling synstructure v0.13.2
[INFO] [stderr]    Compiling darling_core v0.23.0
[INFO] [stderr]    Compiling native-tls v0.2.18
[INFO] [stderr]    Compiling tokio-macros v2.7.0
[INFO] [stderr]    Compiling zerofrom-derive v0.1.7
[INFO] [stderr]    Compiling yoke-derive v0.8.2
[INFO] [stderr]    Compiling zerovec-derive v0.11.3
[INFO] [stderr]    Compiling serde_derive v1.0.228
[INFO] [stderr]    Compiling displaydoc v0.2.6
[INFO] [stderr]    Compiling futures-macro v0.3.32
[INFO] [stderr]    Compiling tracing-attributes v0.1.31
[INFO] [stderr]    Compiling openssl-macros v0.1.1
[INFO] [stderr]    Compiling thiserror-impl v2.0.18
[INFO] [stderr]    Compiling async-stream-impl v0.3.6
[INFO] [stderr]    Compiling thiserror-impl v1.0.69
[INFO] [stderr]    Compiling async-trait v0.1.89
[INFO] [stderr]    Compiling async-stream v0.3.6
[INFO] [stderr]    Compiling futures-util v0.3.32
[INFO] [stderr]    Compiling tokio v1.52.3
[INFO] [stderr]    Compiling zerofrom v0.1.8
[INFO] [stderr]    Compiling tracing v0.1.44
[INFO] [stderr]    Compiling thiserror v1.0.69
[INFO] [stderr]    Compiling yoke v0.8.3
[INFO] [stderr]    Compiling thiserror v2.0.18
[INFO] [stderr]    Compiling axum-core v0.5.6
[INFO] [stderr]    Compiling zerovec v0.11.6
[INFO] [stderr]    Compiling zerotrie v0.2.4
[INFO] [stderr]    Compiling darling_macro v0.23.0
[INFO] [stderr]    Compiling darling v0.23.0
[INFO] [stderr]    Compiling serde_with_macros v3.21.0
[INFO] [stderr]    Compiling tinystr v0.8.3
[INFO] [stderr]    Compiling potential_utf v0.1.5
[INFO] [stderr]    Compiling serde v1.0.228
[INFO] [stderr]    Compiling icu_collections v2.2.0
[INFO] [stderr]    Compiling icu_locale_core v2.2.0
[INFO] [stderr]    Compiling swarmforge-buffers v0.1.0
[INFO] [stderr]    Compiling serde_urlencoded v0.7.1
[INFO] [stderr]    Compiling chrono v0.4.45
[INFO] [stderr]    Compiling dashmap v6.2.1
[INFO] [stderr]    Compiling serde_with v3.21.0
[INFO] [stderr]    Compiling quick-xml v0.40.1
[INFO] [stderr]    Compiling mediatype v0.19.20
[INFO] [stderr]    Compiling swarmforge-bencode v0.1.0
[INFO] [stderr]    Compiling futures-executor v0.3.32
[INFO] [stderr]    Compiling icu_provider v2.2.0
[INFO] [stderr]    Compiling futures v0.3.32
[INFO] [stderr]    Compiling governor v0.10.4
[INFO] [stderr]    Compiling crypto-hash v0.3.4
[INFO] [stderr]    Compiling icu_properties v2.2.0
[INFO] [stderr]    Compiling icu_normalizer v2.2.0
[INFO] [stderr]    Compiling swarmforge-sha1-wrapper v0.1.0
[INFO] [stderr]    Compiling idna_adapter v1.2.2
[INFO] [stderr]    Compiling idna v1.1.0
[INFO] [stderr]    Compiling hyper v1.10.1
[INFO] [stderr]    Compiling tower v0.5.3
[INFO] [stderr]    Compiling tokio-util v0.7.18
[INFO] [stderr]    Compiling backon v1.6.0
[INFO] [stderr]    Compiling tokio-native-tls v0.3.1
[INFO] [stderr]    Compiling leaky-bucket v1.1.2
[INFO] [stderr]    Compiling dontfrag v1.0.1
[INFO] [stderr]    Compiling async-compression v0.4.42
[INFO] [stderr]    Compiling tokio-socks v0.5.3
[INFO] [stderr]    Compiling url v2.5.8
[INFO] [stderr]    Compiling tokio-stream v0.1.18
[INFO] [stderr]    Compiling swarmforge-core v0.1.0
[INFO] [stderr]    Compiling tower-http v0.6.11
[INFO] [stderr]    Compiling feed-rs v2.3.1
[INFO] [stderr]    Compiling hyper-util v0.1.20
[INFO] [stderr]    Compiling swarmforge-peer-protocol v0.1.0
[INFO] [stderr]    Compiling axum v0.8.9
[INFO] [stderr]    Compiling hyper-tls v0.6.0
[INFO] [stderr]    Compiling reqwest v0.13.4
[INFO] [stderr]    Compiling librqbit-dualstack-sockets v0.7.0
[INFO] [stderr]    Compiling axum-extra v0.12.6
[INFO] [stderr]    Compiling librqbit-utp v0.7.0
[INFO] [stderr]    Compiling swarmforge-upnp v0.1.0
[INFO] [stderr]    Compiling swarmforge-lsd v0.1.0
[INFO] [stderr]    Compiling swarmforge-tracker-comms v0.1.0
[INFO] [stderr]    Compiling swarmforge-dht v0.1.0
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 1m 26s
[INFO] running `Command { std: "docker" "inspect" "0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stderr]    Compiling tokio v1.52.3
[INFO] [stderr]    Compiling openssl v0.10.80
[INFO] [stderr]    Compiling raw-cpuid v11.6.0
[INFO] [stderr]    Compiling nix v0.31.3
[INFO] [stderr]    Compiling rustix v1.1.4
[INFO] [stderr]    Compiling pollster v0.4.0
[INFO] [stderr]    Compiling tracing-subscriber v0.3.23
[INFO] [stderr]    Compiling quanta v0.12.6
[INFO] [stderr]    Compiling tempfile v3.27.0
[INFO] [stderr]    Compiling governor v0.10.4
[INFO] [stderr]    Compiling crypto-hash v0.3.4
[INFO] [stderr]    Compiling native-tls v0.2.18
[INFO] [stderr]    Compiling swarmforge-sha1-wrapper v0.1.0
[INFO] [stderr]    Compiling hyper v1.10.1
[INFO] [stderr]    Compiling tower v0.5.3
[INFO] [stderr]    Compiling tokio-util v0.7.18
[INFO] [stderr]    Compiling backon v1.6.0
[INFO] [stderr]    Compiling tokio-native-tls v0.3.1
[INFO] [stderr]    Compiling dontfrag v1.0.1
[INFO] [stderr]    Compiling leaky-bucket v1.1.2
[INFO] [stderr]    Compiling tokio-socks v0.5.3
[INFO] [stderr]    Compiling async-compression v0.4.42
[INFO] [stderr]    Compiling swarmforge-core v0.1.0
[INFO] [stderr]    Compiling tokio-stream v0.1.18
[INFO] [stderr]    Compiling tower-http v0.6.11
[INFO] [stderr]    Compiling tokio-test v0.4.5
[INFO] [stderr]    Compiling swarmforge-peer-protocol v0.1.0
[INFO] [stderr]    Compiling hyper-util v0.1.20
[INFO] [stderr]    Compiling axum v0.8.9
[INFO] [stderr]    Compiling hyper-tls v0.6.0
[INFO] [stderr]    Compiling reqwest v0.13.4
[INFO] [stderr]    Compiling librqbit-dualstack-sockets v0.7.0
[INFO] [stderr]    Compiling axum-extra v0.12.6
[INFO] [stderr]    Compiling librqbit-utp v0.7.0
[INFO] [stderr]    Compiling swarmforge-dht v0.1.0
[INFO] [stderr]    Compiling swarmforge-lsd v0.1.0
[INFO] [stderr]    Compiling swarmforge-tracker-comms v0.1.0
[INFO] [stderr]    Compiling swarmforge-upnp v0.1.0
[INFO] [stderr]    Compiling swarmforge v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 56.60s
[INFO] running `Command { std: "docker" "inspect" "0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "test" "--frozen", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 2.17s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/librtbit-b08df50b6f21d049)
[INFO] [stdout] 
[INFO] [stdout] running 119 tests
[INFO] [stdout] test chunk_tracker::tests::test_compute_chunk_status ... ok
[INFO] [stdout] test chunk_tracker::tests::test_mark_piece_downloaded_updates_hns ... ok
[INFO] [stdout] test chunk_tracker::tests::test_update_only_files_expand ... ok
[INFO] [stdout] test dht_utils::tests::read_metainfo_from_dht ... ignored
[INFO] [stdout] test chunk_tracker::tests::test_update_only_files_shrink ... ok
[INFO] [stdout] test chunk_tracker::tests::test_mark_piece_broken_requeues ... ok
[INFO] [stdout] test ip_ranges::tests::test_list_empty ... ok
[INFO] [stdout] test file_info::tests::test_iter_piece_priorities ... ok
[INFO] [stdout] test chunk_tracker::tests::test_update_only_files ... ok
[INFO] [stdout] test chunk_tracker::tests::test_eta_overflow_safety ... ok
[INFO] [stdout] test chunk_tracker::tests::test_chunk_status_partial ... ok
[INFO] [stdout] test chunk_tracker::tests::test_piece_index_large_values ... ok
[INFO] [stdout] test chunk_tracker::tests::test_chunk_status_all_complete ... ok
[INFO] [stdout] test ip_ranges::tests::test_list_real_url ... ignored
[INFO] [stdout] test ip_ranges::tests::test_manual_ranges ... ok
[INFO] [stdout] test peer_connection::tests::test_peer_connection_handshake_encoding ... ok
[INFO] [stdout] test peer_connection::tests::test_peer_connection_handshake_deserialize_too_short ... ok
[INFO] [stdout] test chunk_tracker::tests::test_is_chunk_ready_to_upload ... ok
[INFO] [stdout] test ip_ranges::tests::test_list_plaintext ... ok
[INFO] [stdout] test peer_connection::tests::test_peer_connection_handshake_supports_extended ... ok
[INFO] [stdout] test peer_connection::tests::test_peer_connection_options_default ... ok
[INFO] [stdout] test peer_connection::tests::test_peer_connection_options_serialization ... ok
[INFO] [stdout] test ip_ranges::tests::test_list_gzipped ... ok
[INFO] [stdout] test peer_connection::tests::test_peer_connection_message_framing ... ok
[INFO] [stdout] test peer_connection::tests::test_peer_connection_unchoke_message ... ok
[INFO] [stdout] test piece_tracker::tests::test_fail_piece_requeues ... ok
[INFO] [stdout] test piece_tracker::tests::test_multiple_peers_competing ... ok
[INFO] [stdout] test piece_tracker::tests::test_new_piece_tracker ... ok
[INFO] [stdout] test piece_tracker::tests::test_complete_piece ... ok
[INFO] [stdout] test piece_tracker::tests::test_none_available_when_no_pieces ... ok
[INFO] [stdout] test peer_connection::tests::test_peer_connection_handshake_roundtrip ... ok
[INFO] [stdout] test piece_tracker::tests::test_release_pieces_owned_by_peer ... ok
[INFO] [stdout] test piece_tracker::tests::test_priority_pieces_checked_first ... ok
[INFO] [stdout] test piece_tracker::tests::test_reserve_filters_by_peer_has_piece ... ok
[INFO] [stdout] test piece_tracker::tests::test_reserve_piece_from_queue ... ok
[INFO] [stdout] test piece_tracker::tests::test_take_inflight_nonexistent_piece_returns_none ... ok
[INFO] [stdout] test read_buf::tests::test_read_buf_miri ... ignored, run with --features=miri only, doesn't work with tokio
[INFO] [stdout] test peer_connection::tests::test_peer_connection_interested_message ... ok
[INFO] [stdout] test read_buf::tests::test_ringbuf_advance ... ok
[INFO] [stdout] test piece_tracker::tests::test_into_chunks_requeues_inflight ... ok
[INFO] [stdout] test piece_tracker::tests::test_all_pieces_completed ... ok
[INFO] [stdout] test read_buf::tests::test_ringbuf_make_contiguous ... ok
[INFO] [stdout] test read_buf::tests::test_read_buf_error_large_values ... ok
[INFO] [stdout] test read_buf::tests::test_unfilled_ioslices ... ok
[INFO] [stdout] test piece_tracker::tests::test_steal_only_pieces_peer_has ... ok
[INFO] [stdout] test read_buf::tests::test_ringbuf_ranges ... ok
[INFO] [stdout] test piece_tracker::tests::test_steal_piece_from_slowest_peer ... ok
[INFO] [stdout] test create_torrent_file::tests::test_create_torrent_with_trackers ... ok
[INFO] [stdout] test create_torrent_file::tests::test_create_torrent_roundtrip ... ok
[INFO] [stdout] test create_torrent_file::tests::test_create_torrent_single_file ... ok
[INFO] [stdout] test session::helpers::tests::test_compute_only_files_none ... ok
[INFO] [stdout] test session::helpers::tests::test_merge_two_optional_streams_both ... ok
[INFO] [stdout] test session::helpers::tests::test_merge_two_optional_streams_both_none ... ok
[INFO] [stdout] test create_torrent_file::tests::test_create_torrent_multi_file ... ok
[INFO] [stdout] test session::helpers::tests::test_compute_only_files_by_index ... ok
[INFO] [stdout] test session::helpers::tests::test_compute_only_files_regex ... ok
[INFO] [stdout] test create_torrent_file::tests::test_create_torrent_magnet ... ok
[INFO] [stdout] test create_torrent_file::tests::test_create_torrent_piece_hashes ... ok
[INFO] [stdout] test session::helpers::tests::test_merge_two_optional_streams_first_only ... ok
[INFO] [stdout] test session::helpers::tests::test_merge_two_optional_streams_second_only ... ok
[INFO] [stdout] test session::tests::expand_folder_template_replaces_and_sanitizes_category ... ok
[INFO] [stdout] test session::peer_sources::tests::private_torrents_keep_all_declared_trackers ... ok
[INFO] [stdout] test session::tests::test_torrent_file_from_info_and_bytes ... ok
[INFO] [stdout] test session::helpers::tests::test_torrent_from_bytes_valid ... ok
[INFO] [stdout] test session::peer_sources::tests::disabling_trackers_clears_private_and_public_trackers ... ok
[INFO] [stdout] test storage::filesystem::fs::tests::test_filesystem_storage_piece_hash_verification ... ok
[INFO] [stdout] test storage::filesystem::fs::tests::test_filesystem_storage_write_at_offset ... ok
[INFO] [stdout] test create_torrent_file::tests::test_create_torrent ... ok
[INFO] [stdout] test storage::filesystem::fs::tests::test_storage_ensure_file_length ... ok
[INFO] [stdout] test storage::filesystem::fs::tests::test_filesystem_storage_write_and_read ... ok
[INFO] [stdout] test session::peer_sources::tests::public_torrents_include_session_trackers ... ok
[INFO] [stdout] test storage::filesystem::fs::tests::test_storage_file_boundaries ... ok
[INFO] [stdout] test storage::filesystem::fs::tests::test_storage_remove_directory_if_empty ... ok
[INFO] [stdout] test storage::filesystem::fs::tests::test_storage_handles_sparse_writes ... ok
[INFO] [stdout] 2026-10-06T19:24:53.148273Z  WARN librtbit::storage::filesystem::fs: did not remove "/tmp/.tmpjF8npX/subdir" as it was not empty
[INFO] [stdout] test storage::filesystem::fs::tests::test_storage_remove_directory_not_empty ... ok
[INFO] [stdout] test storage::filesystem::fs::tests::test_storage_take ... ok
[INFO] [stdout] test storage::filesystem::fs::tests::test_storage_remove_file ... ok
[INFO] [stdout] test session_persistence::json::tests::json_store_persists_session_settings ... ok
[INFO] [stdout] test storage::filesystem::opened_file::tests::test_pwrite_all_vectored ... ok
[INFO] [stdout] 2026-10-06T19:24:53.157734Z  INFO librtbit::tests::test_util: created tempdir path="/tmp/test_pause_initqfPY0s"
[INFO] [stdout] 2026-10-06T19:24:53.159658Z  INFO librtbit::tests::test_util: created tempdir path="/tmp/test_session_shutdownDdppUV"
[INFO] [stdout] 2026-10-06T19:24:53.165943Z  INFO librtbit::tests::test_util: created tempdir path="/tmp/test_delete_initlf8eSH"
[INFO] [stdout] 2026-10-06T19:24:53.168907Z  INFO librtbit::tests::test_util: created tempdir path="/tmp/test_cancel_tokenBI4cH3"
[INFO] [stdout] test session::tests::test_init_semaphore_doesnt_deadlock ... ok
[INFO] [stdout] 2026-10-06T19:24:53.196197Z  INFO librtbit::tests::e2e: increased ulimit limit=524288
[INFO] [stdout] 2026-10-06T19:24:53.196570Z  INFO librtbit::tests::test_util: created tempdir path="/tmp/rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:53.236767Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:53.237126Z  INFO librtbit::session: added torrent name="test_pause_initqfPY0s"
[INFO] [stdout] 2026-10-06T19:24:53.268574Z  INFO librtbit::session: added torrent name="test_session_shutdownDdppUV"
[INFO] [stdout] 2026-10-06T19:24:53.270227Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:53.297125Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:53.297996Z  INFO librtbit::session: added torrent name="test_cancel_tokenBI4cH3"
[INFO] [stdout] test session::helpers::tests::torrent_from_file_url_reads_local_torrent ... ok
[INFO] [stdout] 2026-10-06T19:24:53.320635Z  INFO librtbit::tests::e2e: increased ulimit limit=524288
[INFO] [stdout] 2026-10-06T19:24:53.320806Z  INFO librtbit::tests::test_util: created tempdir path="/tmp/rtbit_e2evnGdnk"
[INFO] [stdout] test ip_ranges::tests::test_list_from_plaintext_file ... FAILED
[INFO] [stdout] test session::helpers::tests::test_compute_only_files_invalid_index ... ok
[INFO] [stdout] test session::helpers::tests::test_compute_only_files_regex_no_match ... ok
[INFO] [stdout] test session::helpers::tests::test_compute_only_files_mutually_exclusive ... ok
[INFO] [stdout] test session::helpers::tests::test_torrent_from_bytes_invalid ... ok
[INFO] [stdout] test tests::e2e_another_local_client::test_tcp_with_another_client ... ignored
[INFO] [stdout] test tests::e2e_another_local_client::test_utp_with_another_client ... ignored
[INFO] [stdout] test storage::filesystem::fs::tests::test_storage_invalid_file_id ... ok
[INFO] [stdout] test torrent_state::live::peer::stats::atomic::tests::test_backoff_produces_bounded_delays ... ok
[INFO] [stdout] test storage::filesystem::opened_file::tests::test_write_path_large_file_offsets ... ok
[INFO] [stdout] test torrent_state::live::peer::stats::atomic::tests::test_backoff_reset_produces_new_delays ... ok
[INFO] [stdout] test torrent_state::live::peer::stats::atomic::tests::test_backoff_reset_is_independent ... ok
[INFO] [stdout] 2026-10-06T19:24:53.341296Z  INFO librtbit::listen: Listening on TCP 127.0.0.1:40969 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:53.344081Z  INFO librtbit::tests::cancel_init: pause succeeded during initialization
[INFO] [stdout] 2026-10-06T19:24:53.344176Z  INFO librtbit::tests::cancel_init: state after pause: error
[INFO] [stdout] 2026-10-06T19:24:53.344216Z  INFO librtbit::tests::cancel_init: test_pause_during_initialization passed
[INFO] [stdout] test session::tests::test_concurrent_init_limit_configurable ... ok
[INFO] [stdout] 2026-10-06T19:24:53.350732Z  INFO librtbit::listen: Listening on TCP 127.0.0.1:36603 for incoming peer connections
[INFO] [stdout] test torrent_state::live::peer_handler::tests::private_torrent_strips_metadata_extensions ... ok
[INFO] [stdout] test torrent_state::live::peers::tests::test_backoff_reset_on_rediscovery ... ok
[INFO] [stdout] test torrent_state::live::peers::tests::test_dead_peer_pruning_counters_are_decremented ... ok
[INFO] [stdout] test torrent_state::live::peers::tests::test_dead_peer_pruning_preserves_recent_peers ... ok
[INFO] [stdout] test torrent_state::live::peers::tests::test_dead_peer_pruning_removes_stale_dead_peers ... ok
[INFO] [stdout] test torrent_state::live::peers::tests::test_dead_peer_pruning_removes_stale_not_needed_peers ... ok
[INFO] [stdout] test torrent_state::live::peers::tests::test_dead_peer_requeue ... 2026-10-06T19:24:53.356147Z  INFO librtbit::tests::test_util: created tempdir path="/tmp/test_e2e_streamHZM7tN"
[INFO] [stdout] ok
[INFO] [stdout] test torrent_state::live::peers::tests::test_peer_stats_tracking ... ok
[INFO] [stdout] 2026-10-06T19:24:53.363853Z  INFO librtbit::torrent_state::initializing: Initial check results: have 0, needed 4.0Ki, total selected 4.0Ki torrent=0
[INFO] [stdout] 2026-10-06T19:24:53.365175Z  INFO librtbit::torrent_state::initializing: Initial check results: have 0, needed 4.0Ki, total selected 4.0Ki torrent=0
[INFO] [stdout] 2026-10-06T19:24:53.372873Z  INFO librtbit::listen: Listening on TCP 127.0.0.1:16001 for incoming peer connections
[INFO] [stdout] test torrent_state::live::peers::tests::test_peers_not_permanently_dropped ... ok
[INFO] [stdout] test session::tests::test_magnet_resolution_timeout ... FAILED
[INFO] [stdout] test torrent_state::live::peers::tests::test_active_peer_count ... ok
[INFO] [stdout] test torrent_state::live::peers::tests::test_dead_peer_pruning_preserves_queued_and_connecting ... ok
[INFO] [stdout] test tests::mock_tracker::tests::supports_connect_announce_and_scrape ... ok
[INFO] [stdout] test torrent_state::live::peer_handler::tests::public_torrent_advertises_metadata_size ... ok
[INFO] [stdout] test torrent_state::live::peers::tests::test_semaphore_permit_returned_on_drop ... ok
[INFO] [stdout] 2026-10-06T19:24:53.423125Z  INFO librtbit::session: deleted torrent id=0
[INFO] [stdout] 2026-10-06T19:24:53.423174Z  INFO librtbit::tests::cancel_init: test_cancellation_token_propagation passed
[INFO] [stdout] 2026-10-06T19:24:53.424837Z ERROR librtbit_core::spawn_utils: initialize_and_start finished with error: initial check cancelled
[INFO] [stdout] 
[INFO] [stdout] Stack backtrace:
[INFO] [stdout]    0: <anyhow::Error>::msg::<&str>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/anyhow-1.0.102/src/backtrace.rs:10:14
[INFO] [stdout]    1: anyhow::__private::format_err
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/anyhow-1.0.102/src/lib.rs:687:13
[INFO] [stdout]    2: <librtbit::file_ops::FileOps>::initial_check
[INFO] [stdout]              at ./src/file_ops.rs:118:17
[INFO] [stdout]    3: <librtbit::torrent_state::initializing::TorrentStateInitializing>::check::{closure#0}::{closure#0}
[INFO] [stdout]              at ./src/torrent_state/initializing.rs:232:30
[INFO] [stdout]    4: tokio::runtime::context::runtime_mt::exit_runtime::<<librtbit::torrent_state::initializing::TorrentStateInitializing>::check::{closure#0}::{closure#0}, core::result::Result<bitvec::boxed::BitBox<u8, bitvec::order::Msb0>, anyhow::Error>>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context/runtime_mt.rs:35:5
[INFO] [stdout]    5: tokio::runtime::scheduler::multi_thread::worker::block_in_place::<<librtbit::torrent_state::initializing::TorrentStateInitializing>::check::{closure#0}::{closure#0}, core::result::Result<bitvec::boxed::BitBox<u8, bitvec::order::Msb0>, anyhow::Error>>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:494:9
[INFO] [stdout]    6: tokio::runtime::scheduler::block_in_place::block_in_place::<<librtbit::torrent_state::initializing::TorrentStateInitializing>::check::{closure#0}::{closure#0}, core::result::Result<bitvec::boxed::BitBox<u8, bitvec::order::Msb0>, anyhow::Error>>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/block_in_place.rs:8:5
[INFO] [stdout]    7: tokio::task::blocking::block_in_place::<<librtbit::torrent_state::initializing::TorrentStateInitializing>::check::{closure#0}::{closure#0}, core::result::Result<bitvec::boxed::BitBox<u8, bitvec::order::Msb0>, anyhow::Error>>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/task/blocking.rs:78:9
[INFO] [stdout]    8: <librtbit::spawn_utils::BlockingSpawner>::block_in_place_with_semaphore::<<librtbit::torrent_state::initializing::TorrentStateInitializing>::check::{closure#0}::{closure#0}, core::result::Result<bitvec::boxed::BitBox<u8, bitvec::order::Msb0>, anyhow::Error>>::{closure#0}
[INFO] [stdout]              at ./src/spawn_utils.rs:49:20
[INFO] [stdout]    9: <librtbit::torrent_state::initializing::TorrentStateInitializing>::check::{closure#0}
[INFO] [stdout]              at ./src/torrent_state/initializing.rs:234:22
[INFO] [stdout]   10: <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}
[INFO] [stdout]              at ./src/torrent_state/mod.rs:405:48
[INFO] [stdout]   11: librtbit_core::spawn_utils::spawn_with_cancel::<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/macros/select.rs:705:49
[INFO] [stdout]   12: <core::future::poll_fn::PollFn<librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}::{closure#0}> as core::future::future::Future>::poll
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/future/poll_fn.rs:151:9
[INFO] [stdout]   13: librtbit_core::spawn_utils::spawn_with_cancel::<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/swarmforge-core-0.1.0/src/spawn_utils.rs:50:9
[INFO] [stdout]   14: <core::pin::Pin<&mut librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}> as core::future::future::Future>::poll
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/future/future.rs:133:9
[INFO] [stdout]   15: <&mut core::pin::Pin<&mut librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}> as core::future::future::Future>::poll
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/future/future.rs:121:9
[INFO] [stdout]   16: librtbit_core::spawn_utils::spawn::<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}::{closure#1}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/macros/select.rs:705:49
[INFO] [stdout]   17: <core::future::poll_fn::PollFn<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}::{closure#1}> as core::future::future::Future>::poll
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/future/poll_fn.rs:151:9
[INFO] [stdout]   18: librtbit_core::spawn_utils::spawn::<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/swarmforge-core-0.1.0/src/spawn_utils.rs:20:13
[INFO] [stdout]   19: <tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}> as core::future::future::Future>::poll
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tracing-0.1.44/src/instrument.rs:321:15
[INFO] [stdout]   20: <core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>> as core::future::future::Future>::poll
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/future/future.rs:133:9
[INFO] [stdout]   21: <tokio::runtime::task::core::Core<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>, alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>>::poll::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/core.rs:375:24
[INFO] [stdout]   22: <tokio::loom::std::unsafe_cell::UnsafeCell<tokio::runtime::task::core::Stage<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>>>>::with_mut::<core::task::poll::Poll<()>, <tokio::runtime::task::core::Core<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>, alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>>::poll::{closure#0}>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/loom/std/unsafe_cell.rs:16:9
[INFO] [stdout]   23: <tokio::runtime::task::core::Core<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>, alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>>::poll
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/core.rs:364:30
[INFO] [stdout]   24: tokio::runtime::task::harness::poll_future::<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>, alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:535:30
[INFO] [stdout]   25: <core::panic::unwind_safe::AssertUnwindSafe<tokio::runtime::task::harness::poll_future<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>, alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>::{closure#0}> as core::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   26: std::panicking::catch_unwind::do_call::<core::panic::unwind_safe::AssertUnwindSafe<tokio::runtime::task::harness::poll_future<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>, alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>::{closure#0}>, core::task::poll::Poll<()>>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:576:43
[INFO] [stdout]   27: __rust_try
[INFO] [stdout]   28: std::panicking::catch_unwind::<core::task::poll::Poll<()>, core::panic::unwind_safe::AssertUnwindSafe<tokio::runtime::task::harness::poll_future<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>, alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>::{closure#0}>>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:544:19
[INFO] [stdout]   29: std::panic::catch_unwind::<core::panic::unwind_safe::AssertUnwindSafe<tokio::runtime::task::harness::poll_future<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>, alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>::{closure#0}>, core::task::poll::Poll<()>>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panic.rs:359:14
[INFO] [stdout]   30: tokio::runtime::task::harness::poll_future::<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>, alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:523:18
[INFO] [stdout]   31: <tokio::runtime::task::harness::Harness<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>, alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>>::poll_inner
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:210:27
[INFO] [stdout]   32: <tokio::runtime::task::harness::Harness<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>, alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>>::poll
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:155:20
[INFO] [stdout]   33: tokio::runtime::task::raw::poll::<core::pin::Pin<alloc::boxed::Box<tracing::instrument::Instrumented<librtbit_core::spawn_utils::spawn<anyhow::Error, &str, librtbit_core::spawn_utils::spawn_with_cancel<anyhow::Error, &str, <librtbit::torrent_state::ManagedTorrent>::start::_start::{closure#1}>::{closure#0}>::{closure#0}>>>, alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/raw.rs:337:13
[INFO] [stdout]   34: <tokio::runtime::task::raw::RawTask>::poll
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/raw.rs:267:18
[INFO] [stdout]   35: <tokio::runtime::task::LocalNotified<alloc::sync::Arc<tokio::runtime::scheduler::multi_thread::handle::Handle>>>::run
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/mod.rs:510:13
[INFO] [stdout]   36: <tokio::runtime::scheduler::multi_thread::worker::Context>::run_task::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:684:18
[INFO] [stdout]   37: tokio::task::coop::with_budget::<core::result::Result<alloc::boxed::Box<tokio::runtime::scheduler::multi_thread::worker::Core>, ()>, <tokio::runtime::scheduler::multi_thread::worker::Context>::run_task::{closure#0}>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/task/coop/mod.rs:167:5
[INFO] [stdout]   38: tokio::task::coop::budget::<core::result::Result<alloc::boxed::Box<tokio::runtime::scheduler::multi_thread::worker::Core>, ()>, <tokio::runtime::scheduler::multi_thread::worker::Context>::run_task::{closure#0}>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/task/coop/mod.rs:133:5
[INFO] [stdout]   39: <tokio::runtime::scheduler::multi_thread::worker::Context>::run_task
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:675:9
[INFO] [stdout]   40: <tokio::runtime::scheduler::multi_thread::worker::Context>::run
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:585:29
[INFO] [stdout]   41: tokio::runtime::scheduler::multi_thread::worker::run::{closure#0}::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:550:24
[INFO] [stdout]   42: <tokio::runtime::context::scoped::Scoped<tokio::runtime::scheduler::Context>>::set::<tokio::runtime::scheduler::multi_thread::worker::run::{closure#0}::{closure#0}, ()>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context/scoped.rs:40:9
[INFO] [stdout]   43: tokio::runtime::context::set_scheduler::<(), tokio::runtime::scheduler::multi_thread::worker::run::{closure#0}::{closure#0}>::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context.rs:181:38
[INFO] [stdout]   44: <std::thread::local::LocalKey<tokio::runtime::context::Context>>::try_with::<tokio::runtime::context::set_scheduler<(), tokio::runtime::scheduler::multi_thread::worker::run::{closure#0}::{closure#0}>::{closure#0}, ()>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/thread/local.rs:463:12
[INFO] [stdout]   45: <std::thread::local::LocalKey<tokio::runtime::context::Context>>::with::<tokio::runtime::context::set_scheduler<(), tokio::runtime::scheduler::multi_thread::worker::run::{closure#0}::{closure#0}>::{closure#0}, ()>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/thread/local.rs:427:20
[INFO] [stdout]   46: tokio::runtime::context::set_scheduler::<(), tokio::runtime::scheduler::multi_thread::worker::run::{closure#0}::{closure#0}>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context.rs:181:17
[INFO] [stdout]   47: tokio::runtime::scheduler::multi_thread::worker::run::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:545:9
[INFO] [stdout]   48: tokio::runtime::context::runtime::enter_runtime::<tokio::runtime::scheduler::multi_thread::worker::run::{closure#0}, ()>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context/runtime.rs:65:16
[INFO] [stdout]   49: tokio::runtime::scheduler::multi_thread::worker::run
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:537:5
[INFO] [stdout]   50: <tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/worker.rs:503:45
[INFO] [stdout]   51: <tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}> as core::future::future::Future>::poll
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/blocking/task.rs:42:21
[INFO] [stdout]   52: <tokio::runtime::task::core::Core<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>, tokio::runtime::blocking::schedule::BlockingSchedule>>::poll::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/core.rs:375:24
[INFO] [stdout]   53: <tokio::loom::std::unsafe_cell::UnsafeCell<tokio::runtime::task::core::Stage<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>>>>::with_mut::<core::task::poll::Poll<()>, <tokio::runtime::task::core::Core<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>, tokio::runtime::blocking::schedule::BlockingSchedule>>::poll::{closure#0}>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/loom/std/unsafe_cell.rs:16:9
[INFO] [stdout]   54: <tokio::runtime::task::core::Core<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>, tokio::runtime::blocking::schedule::BlockingSchedule>>::poll
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/core.rs:364:30
[INFO] [stdout]   55: tokio::runtime::task::harness::poll_future::<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>, tokio::runtime::blocking::schedule::BlockingSchedule>::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:535:30
[INFO] [stdout]   56: <core::panic::unwind_safe::AssertUnwindSafe<tokio::runtime::task::harness::poll_future<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>, tokio::runtime::blocking::schedule::BlockingSchedule>::{closure#0}> as core::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   57: std::panicking::catch_unwind::do_call::<core::panic::unwind_safe::AssertUnwindSafe<tokio::runtime::task::harness::poll_future<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>, tokio::runtime::blocking::schedule::BlockingSchedule>::{closure#0}>, core::task::poll::Poll<()>>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:576:43
[INFO] [stdout]   58: __rust_try
[INFO] [stdout]   59: std::panicking::catch_unwind::<core::task::poll::Poll<()>, core::panic::unwind_safe::AssertUnwindSafe<tokio::runtime::task::harness::poll_future<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>, tokio::runtime::blocking::schedule::BlockingSchedule>::{closure#0}>>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:544:19
[INFO] [stdout]   60: std::panic::catch_unwind::<core::panic::unwind_safe::AssertUnwindSafe<tokio::runtime::task::harness::poll_future<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>, tokio::runtime::blocking::schedule::BlockingSchedule>::{closure#0}>, core::task::poll::Poll<()>>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panic.rs:359:14
[INFO] [stdout]   61: tokio::runtime::task::harness::poll_future::<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>, tokio::runtime::blocking::schedule::BlockingSchedule>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:523:18
[INFO] [stdout]   62: <tokio::runtime::task::harness::Harness<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>, tokio::runtime::blocking::schedule::BlockingSchedule>>::poll_inner
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:210:27
[INFO] [stdout]   63: <tokio::runtime::task::harness::Harness<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>, tokio::runtime::blocking::schedule::BlockingSchedule>>::poll
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/harness.rs:155:20
[INFO] [stdout]   64: tokio::runtime::task::raw::poll::<tokio::runtime::blocking::task::BlockingTask<<tokio::runtime::scheduler::multi_thread::worker::Launch>::launch::{closure#0}>, tokio::runtime::blocking::schedule::BlockingSchedule>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/raw.rs:337:13
[INFO] [stdout]   65: <tokio::runtime::task::raw::RawTask>::poll
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/raw.rs:267:18
[INFO] [stdout]   66: <tokio::runtime::task::UnownedTask<tokio::runtime::blocking::schedule::BlockingSchedule>>::run
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/task/mod.rs:547:13
[INFO] [stdout]   67: <tokio::runtime::blocking::pool::Task>::run
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/blocking/pool.rs:161:19
[INFO] [stdout]   68: <tokio::runtime::blocking::pool::Inner>::run
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/blocking/pool.rs:518:22
[INFO] [stdout]   69: <tokio::runtime::blocking::pool::Spawner>::spawn_thread::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/blocking/pool.rs:474:47
[INFO] [stdout]   70: std::sys::backtrace::__rust_begin_short_backtrace::<<tokio::runtime::blocking::pool::Spawner>::spawn_thread::{closure#0}, ()>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   71: std::thread::lifecycle::spawn_unchecked::<<tokio::runtime::blocking::pool::Spawner>::spawn_thread::{closure#0}, ()>::{closure#1}::{closure#0}
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/thread/lifecycle.rs:70:13
[INFO] [stdout]   72: <core::panic::unwind_safe::AssertUnwindSafe<std::thread::lifecycle::spawn_unchecked<<tokio::runtime::blocking::pool::Spawner>::spawn_thread::{closure#0}, ()>::{closure#1}::{closure#0}> as core::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   73: std::panicking::catch_unwind::do_call::<core::panic::unwind_safe::AssertUnwindSafe<std::thread::lifecycle::spawn_unchecked<<tokio::runtime::blocking::pool::Spawner>::spawn_thread::{closure#0}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:576:43
[INFO] [stdout]   74: __rust_try
[INFO] [stdout]   75: std::panicking::catch_unwind::<(), core::panic::unwind_safe::AssertUnwindSafe<std::thread::lifecycle::spawn_unchecked<<tokio::runtime::blocking::pool::Spawner>::spawn_thread::{closure#0}, ()>::{closure#1}::{closure#0}>>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:544:19
[INFO] [stdout]   76: std::panic::catch_unwind::<core::panic::unwind_safe::AssertUnwindSafe<std::thread::lifecycle::spawn_unchecked<<tokio::runtime::blocking::pool::Spawner>::spawn_thread::{closure#0}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panic.rs:359:14
[INFO] [stdout]   77: std::thread::lifecycle::spawn_unchecked::<<tokio::runtime::blocking::pool::Spawner>::spawn_thread::{closure#0}, ()>::{closure#1}
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/thread/lifecycle.rs:68:26
[INFO] [stdout]   78: <std::thread::lifecycle::spawn_unchecked<<tokio::runtime::blocking::pool::Spawner>::spawn_thread::{closure#0}, ()>::{closure#1} as core::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   79: <alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output = ()> + core::marker::Send> as core::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/alloc/src/boxed.rs:2320:9
[INFO] [stdout]   80: <std::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/sys/thread/unix.rs:123:17
[INFO] [stdout]   81: <unknown>
[INFO] [stdout]   82: clone
[INFO] [stdout] test tests::cancel_init::test_pause_during_initialization ... ok
[INFO] [stdout] 2026-10-06T19:24:53.431451Z  INFO librtbit::session: added torrent name="payload.bin"
[INFO] [stdout] 2026-10-06T19:24:53.431740Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] test tests::cancel_init::test_cancellation_token_propagation ... ok
[INFO] [stdout] 2026-10-06T19:24:53.432303Z  INFO librtbit::torrent_state::initializing: Initial check results: have 256.0Ki, needed 0, total selected 256.0Ki torrent=0
[INFO] [stdout] 2026-10-06T19:24:53.438135Z  INFO librtbit::tests::e2e_stream: created server session
[INFO] [stdout] 2026-10-06T19:24:53.438566Z  INFO librtbit::session: added torrent name="test_e2e_streamHZM7tN"
[INFO] [stdout] 2026-10-06T19:24:53.438785Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:53.439130Z  INFO librtbit::torrent_state::initializing: Initial check results: have 8.0Ki, needed 0, total selected 8.0Ki torrent=0
[INFO] [stdout] 2026-10-06T19:24:53.439612Z  INFO librtbit::tests::e2e_stream: server torrent was completed
[INFO] [stdout] 2026-10-06T19:24:53.444093Z  INFO librtbit::listen: Listening on TCP 127.0.0.1:34787 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:53.468115Z  INFO librtbit::session: added torrent name="payload.bin"
[INFO] [stdout] 2026-10-06T19:24:53.489138Z  INFO librtbit::tests::e2e_stream: created client session
[INFO] [stdout] 2026-10-06T19:24:53.489675Z  INFO librtbit::session: added torrent name="test_e2e_streamHZM7tN"
[INFO] [stdout] 2026-10-06T19:24:53.489906Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:53.490245Z  INFO librtbit::torrent_state::initializing: Initial check results: have 0, needed 8.0Ki, total selected 8.0Ki torrent=0
[INFO] [stdout] 2026-10-06T19:24:53.491140Z  INFO librtbit::tests::e2e_stream: client torrent initialized, starting stream
[INFO] [stdout] 2026-10-06T19:24:53.532757Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:53.534010Z  INFO librtbit::session: added torrent name="test_delete_initlf8eSH"
[INFO] [stdout] 2026-10-06T19:24:53.534033Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:53.534093Z  INFO librtbit::tests::cancel_init: torrent is initializing: true
[INFO] [stdout] 2026-10-06T19:24:53.534182Z  INFO librtbit::session: deleted torrent id=0
[INFO] [stdout] 2026-10-06T19:24:53.534203Z  INFO librtbit::tests::cancel_init: test_delete_cancels_initializing_torrent passed
[INFO] [stdout] 2026-10-06T19:24:53.534429Z  INFO librtbit::torrent_state::initializing: Initial check results: have 0, needed 256.0Ki, total selected 256.0Ki torrent=0
[INFO] [stdout] 2026-10-06T19:24:53.536317Z  INFO librtbit::torrent_state::initializing: Initial check results: have 0, needed 4.0Mi, total selected 4.0Mi torrent=0
[INFO] [stdout] test tests::cancel_init::test_delete_cancels_initializing_torrent ... ok
[INFO] [stdout] 2026-10-06T19:24:53.543110Z  INFO librtbit::session: added torrent name="payload.bin"
[INFO] [stdout] 2026-10-06T19:24:53.543386Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:53.543616Z  INFO librtbit::torrent_state::initializing: Initial check results: have 16.0Ki, needed 0, total selected 16.0Ki torrent=0
[INFO] [stdout] 2026-10-06T19:24:53.578743Z  INFO librtbit::torrent_state::live: torrent finished downloading id=0 info_hash=3c803143e4ca14c5fa0a2c64a7b3a61548ed4c61
[INFO] [stdout] test tests::e2e_stream::test_e2e_stream ... ok
[INFO] [stdout] 2026-10-06T19:24:53.591456Z  INFO librtbit::torrent_state::live: torrent finished downloading id=0 info_hash=acf360272356c7348edffc5940c177d18431106a
[INFO] [stdout] test tests::mock_tracker::tests::leech_discovers_seed_through_tracker ... ok
[INFO] [stdout] 2026-10-06T19:24:54.059020Z  INFO server{id=0}: librtbit::listen: Listening on TCP 127.0.0.1:15100 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.060498Z  INFO server{id=1}: librtbit::listen: Listening on TCP 127.0.0.1:15101 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.067359Z  INFO server{id=2}: librtbit::listen: Listening on TCP 127.0.0.1:15102 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.067398Z  INFO server{id=4}: librtbit::listen: Listening on TCP 127.0.0.1:15104 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.067538Z  INFO server{id=6}: librtbit::listen: Listening on TCP 127.0.0.1:15106 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.077230Z  INFO server{id=10}: librtbit::listen: Listening on TCP 127.0.0.1:15110 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.067795Z  INFO server{id=8}: librtbit::listen: Listening on TCP 127.0.0.1:15108 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.080333Z  INFO server{id=12}: librtbit::listen: Listening on TCP 127.0.0.1:15112 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.083271Z  INFO server{id=14}: librtbit::listen: Listening on TCP 127.0.0.1:15114 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.089320Z  INFO server{id=16}: librtbit::listen: Listening on TCP 127.0.0.1:15116 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.097325Z  INFO server{id=18}: librtbit::listen: Listening on TCP 127.0.0.1:15118 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.115534Z  INFO server{id=19}: librtbit::listen: Listening on TCP 127.0.0.1:15119 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.117261Z  WARN server{id=1}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.118997Z  INFO server{id=1}: librtbit::listen: Listening on UDP 127.0.0.1:15101 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.121236Z  INFO server{id=20}: librtbit::listen: Listening on TCP 127.0.0.1:15120 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.117683Z  WARN server{id=2}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.121985Z  INFO server{id=2}: librtbit::listen: Listening on UDP 127.0.0.1:15102 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.123115Z  WARN server{id=5}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.118023Z  WARN server{id=3}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.118359Z  WARN server{id=4}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.123660Z  INFO server{id=5}: librtbit::listen: Listening on UDP 127.0.0.1:15105 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.124030Z  INFO server{id=4}: librtbit::listen: Listening on UDP 127.0.0.1:15104 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.130457Z  INFO server{id=3}: librtbit::listen: Listening on UDP 127.0.0.1:15103 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.131230Z  WARN server{id=7}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.131805Z  INFO server{id=7}: librtbit::listen: Listening on UDP 127.0.0.1:15107 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.116882Z  WARN server{id=0}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.132200Z  WARN server{id=9}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.132729Z  INFO server{id=9}: librtbit::listen: Listening on UDP 127.0.0.1:15109 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.132733Z  INFO server{id=0}: librtbit::listen: Listening on UDP 127.0.0.1:15100 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.135089Z  WARN server{id=15}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.135132Z  WARN server{id=11}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.135475Z  WARN server{id=21}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.135616Z  INFO server{id=15}: librtbit::listen: Listening on UDP 127.0.0.1:15115 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.135706Z  INFO server{id=11}: librtbit::listen: Listening on UDP 127.0.0.1:15111 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.135886Z  INFO server{id=21}: librtbit::listen: Listening on UDP 127.0.0.1:15121 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.138082Z  WARN server{id=19}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.138566Z  INFO server{id=19}: librtbit::listen: Listening on UDP 127.0.0.1:15119 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.139042Z  WARN server{id=13}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.139573Z  INFO server{id=13}: librtbit::listen: Listening on UDP 127.0.0.1:15113 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.139697Z  INFO server{id=8}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.141223Z  WARN server{id=20}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.141769Z  INFO server{id=20}: librtbit::listen: Listening on UDP 127.0.0.1:15120 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.141894Z  INFO server{id=10}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.142057Z  INFO server{id=21}: librtbit::listen: Listening on TCP 127.0.0.1:15121 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.143401Z  INFO server{id=8}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.143461Z  INFO server{id=8}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.143629Z  INFO server{id=9}: librtbit::listen: Listening on TCP 127.0.0.1:15109 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.144227Z  INFO server{id=22}: librtbit::listen: Listening on TCP 127.0.0.1:15122 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.144843Z  WARN server{id=18}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.145282Z  INFO server{id=10}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.145337Z  INFO server{id=10}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.145483Z  INFO server{id=11}: librtbit::listen: Listening on TCP 127.0.0.1:15111 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.145560Z  INFO server{id=18}: librtbit::listen: Listening on UDP 127.0.0.1:15118 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.147640Z  WARN server{id=17}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.148318Z  INFO server{id=17}: librtbit::listen: Listening on UDP 127.0.0.1:15117 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.163466Z  INFO server{id=23}: librtbit::listen: Listening on TCP 127.0.0.1:15123 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.179666Z  INFO server{id=0}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.182351Z  INFO server{id=0}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.182429Z  INFO server{id=0}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.182613Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.188292Z  INFO server{id=24}: librtbit::listen: Listening on TCP 127.0.0.1:15124 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.207418Z  INFO server{id=1}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.209075Z  INFO server{id=25}: librtbit::listen: Listening on TCP 127.0.0.1:15125 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.211658Z  INFO server{id=4}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.214679Z  INFO server{id=4}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.218054Z  INFO server{id=4}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.218394Z  INFO server{id=5}: librtbit::listen: Listening on TCP 127.0.0.1:15105 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.233204Z  INFO server{id=1}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.233361Z  INFO server{id=1}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.233394Z  INFO server{id=9}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.234036Z  INFO server{id=9}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.234091Z  INFO server{id=9}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.234287Z  WARN server{id=10}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.234450Z  INFO server{id=10}: librtbit::listen: Listening on UDP 127.0.0.1:15110 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.237025Z  INFO server{id=6}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.237617Z  INFO server{id=6}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.242021Z  INFO server{id=6}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.242222Z  INFO server{id=7}: librtbit::listen: Listening on TCP 127.0.0.1:15107 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.263329Z  INFO server{id=20}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.264020Z  INFO server{id=20}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.264117Z  INFO server{id=20}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.264526Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.266314Z  WARN server{id=22}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.266874Z  INFO server{id=22}: librtbit::listen: Listening on UDP 127.0.0.1:15122 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.267444Z  INFO server{id=15}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.269736Z  INFO server{id=15}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.269813Z  INFO server{id=15}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.270043Z  WARN server{id=16}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.270204Z  INFO server{id=16}: librtbit::listen: Listening on UDP 127.0.0.1:15116 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.242942Z  INFO server{id=21}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.250442Z  INFO server{id=21}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.271984Z  INFO server{id=21}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.272072Z  INFO server{id=21}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.272368Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.273374Z  WARN server{id=23}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.273901Z  INFO server{id=23}: librtbit::listen: Listening on UDP 127.0.0.1:15123 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.276253Z  INFO server{id=21}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.276419Z  INFO server{id=21}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.276706Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.277938Z  INFO server{id=2}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.313625Z  INFO server{id=2}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.313712Z  INFO server{id=2}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.313952Z  INFO server{id=3}: librtbit::listen: Listening on TCP 127.0.0.1:15103 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.255271Z  INFO server{id=13}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.318901Z  INFO server{id=13}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.319030Z  INFO server{id=13}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.319404Z  WARN server{id=14}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.319562Z  INFO server{id=14}: librtbit::listen: Listening on UDP 127.0.0.1:15114 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.323898Z  INFO server{id=12}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.324604Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:54.256383Z  INFO server{id=11}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.325996Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.325992Z  INFO server{id=11}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.326085Z  INFO server{id=11}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.326428Z  INFO server{id=27}: librtbit::listen: Listening on TCP 127.0.0.1:15127 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.260085Z  INFO server{id=9}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.328210Z  INFO server{id=19}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.351621Z  INFO server{id=19}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.351732Z  INFO server{id=19}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.353290Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.357549Z  INFO server{id=12}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.362087Z  INFO server{id=12}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.362377Z  INFO server{id=13}: librtbit::listen: Listening on TCP 127.0.0.1:15113 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.369549Z  INFO server{id=14}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.370553Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.374431Z  INFO server{id=5}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.377124Z  INFO server{id=2}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.387688Z  INFO server{id=2}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.392068Z  INFO server{id=2}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.304402Z  INFO server{id=24}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.399613Z  INFO server{id=24}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.399734Z  INFO server{id=24}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.255117Z  INFO server{id=17}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.403169Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.328606Z  INFO server{id=9}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.403576Z  INFO server{id=9}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.403832Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.404350Z  INFO server{id=28}: librtbit::listen: Listening on TCP 127.0.0.1:15128 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.405275Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.405634Z  INFO server{id=17}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.405734Z  INFO server{id=17}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.406039Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.407296Z  INFO server{id=29}: librtbit::listen: Listening on TCP 127.0.0.1:15129 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.408230Z  WARN server{id=26}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.408783Z  INFO server{id=26}: librtbit::listen: Listening on UDP 127.0.0.1:15126 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.341107Z  INFO server{id=16}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.410591Z  INFO server{id=16}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.410655Z  INFO server{id=16}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.410892Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.414265Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.415569Z  WARN server{id=27}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.416042Z  INFO server{id=27}: librtbit::listen: Listening on UDP 127.0.0.1:15127 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.417109Z  INFO server{id=25}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.417121Z  INFO server{id=18}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.278273Z  INFO server{id=26}: librtbit::listen: Listening on TCP 127.0.0.1:15126 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.357996Z  WARN server{id=24}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.377226Z  WARN server{id=25}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.418009Z  INFO server{id=25}: librtbit::listen: Listening on UDP 127.0.0.1:15125 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.420358Z  INFO server{id=30}: librtbit::listen: Listening on TCP 127.0.0.1:15130 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.377302Z  WARN server{id=6}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.423199Z  INFO server{id=25}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.423260Z  INFO server{id=25}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.423474Z  INFO server{id=6}: librtbit::listen: Listening on UDP 127.0.0.1:15106 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.425199Z  INFO librtbit::tests::cancel_init: test_session_shutdown_cancels_torrent_tokens passed
[INFO] [stdout] 2026-10-06T19:24:54.377498Z  INFO server{id=14}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.431094Z  INFO server{id=14}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.432278Z  INFO server{id=18}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.432364Z  INFO server{id=18}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.432566Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.377680Z  INFO server{id=5}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.281872Z  INFO server{id=7}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.434870Z  INFO server{id=7}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.435178Z  INFO server{id=7}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.435259Z  INFO server{id=7}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.435462Z  WARN server{id=8}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.435493Z  INFO server{id=16}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.435623Z  INFO server{id=8}: librtbit::listen: Listening on UDP 127.0.0.1:15108 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.443068Z  INFO server{id=5}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.443660Z  INFO server{id=24}: librtbit::listen: Listening on UDP 127.0.0.1:15124 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.444376Z  INFO server{id=14}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.445432Z  INFO server{id=28}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.382302Z  INFO server{id=27}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.447358Z  INFO server{id=31}: librtbit::listen: Listening on TCP 127.0.0.1:15131 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.447779Z  INFO server{id=27}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.447892Z  INFO server{id=27}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.448140Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.451229Z  INFO server{id=4}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.451781Z  INFO server{id=4}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.451840Z  INFO server{id=4}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.453614Z  INFO server{id=16}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.453675Z  INFO server{id=16}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.453736Z  INFO server{id=7}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.453794Z  INFO server{id=7}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.453814Z  INFO server{id=17}: librtbit::listen: Listening on TCP 127.0.0.1:15117 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.390051Z  INFO server{id=1}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.457793Z  INFO server{id=1}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.457856Z  INFO server{id=1}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.458103Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.283874Z  INFO server{id=18}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.458779Z  INFO server{id=18}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.460052Z  INFO server{id=18}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.461543Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.464061Z  INFO server{id=0}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.401057Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:54.467930Z  INFO server{id=23}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.311831Z  INFO server{id=10}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.337153Z  INFO server{id=22}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.471664Z  INFO server{id=23}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.453823Z  INFO server{id=15}: librtbit::listen: Listening on TCP 127.0.0.1:15115 for incoming peer connections
[INFO] [stdout] 2026-10-06T19:24:54.473091Z  INFO server{id=22}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.473194Z  INFO server{id=22}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.474232Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.476189Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.286778Z  INFO server{id=11}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.479365Z  INFO server{id=10}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.479466Z  INFO server{id=10}: librtbit::tests::e2e: added torrent
[INFO] [stdout] test tests::cancel_init::test_session_shutdown_cancels_torrent_tokens ... ok
[INFO] [stdout] 2026-10-06T19:24:54.484256Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.485211Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.454235Z  INFO server{id=28}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.488020Z  INFO server{id=28}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.488304Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.453946Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.455663Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:54.399940Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.488815Z  INFO server{id=11}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.488941Z  INFO server{id=11}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.489196Z  WARN server{id=12}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.489452Z  INFO server{id=12}: librtbit::listen: Listening on UDP 127.0.0.1:15112 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.489526Z  WARN server{id=30}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.489984Z  INFO server{id=30}: librtbit::listen: Listening on UDP 127.0.0.1:15130 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.491094Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.491323Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.491830Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.492914Z  INFO server{id=19}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.493090Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.493626Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.494556Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.495330Z  INFO server{id=20}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:54.495630Z  INFO server{id=13}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:54.496298Z  INFO server{id=0}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.496310Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.455056Z  INFO server{id=20}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.459728Z  WARN server{id=28}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.500506Z  INFO server{id=28}: librtbit::listen: Listening on UDP 127.0.0.1:15128 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.471760Z  INFO server{id=23}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.401201Z  INFO server{id=3}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.500874Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.504486Z  INFO server{id=3}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.504571Z  INFO server{id=3}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.504679Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.507043Z  INFO server{id=0}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.509418Z  INFO server{id=19}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.509486Z  INFO server{id=19}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.509644Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.510144Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.511138Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.513597Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.513621Z  WARN server{id=31}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.513750Z  INFO server{id=31}: librtbit::listen: Listening on UDP 127.0.0.1:15131 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.522464Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.522712Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:54.525127Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.480329Z  WARN server{id=29}: librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:54.529494Z  INFO server{id=0}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:54.529925Z  INFO server{id=21}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:54.527554Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:54.453866Z  INFO server{id=14}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.543791Z  INFO server{id=14}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.530370Z  INFO server{id=29}: librtbit::listen: Listening on UDP 127.0.0.1:15129 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:54.523848Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.452248Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.601048Z  INFO server{id=17}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.632143Z  INFO server{id=21}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:54.644816Z  INFO server{id=5}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.650797Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:54.672363Z  INFO server{id=23}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.673002Z  INFO server{id=23}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.673122Z  INFO server{id=23}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.673289Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.682514Z  INFO server{id=3}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.685094Z  INFO server{id=10}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:54.653560Z  INFO server{id=13}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.698075Z  INFO server{id=26}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.737193Z  INFO server{id=8}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.737753Z  INFO server{id=8}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.737815Z  INFO server{id=8}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.746675Z  INFO server{id=26}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.747311Z  INFO server{id=26}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.747383Z  INFO server{id=26}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.747818Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.749157Z  INFO server{id=22}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.749501Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.749624Z  INFO server{id=22}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.749675Z  INFO server{id=22}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.749809Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.764367Z  INFO server{id=13}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.764686Z  INFO server{id=13}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.764612Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.768267Z  INFO server{id=20}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.768294Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.768530Z  INFO server{id=20}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.779152Z  INFO server{id=27}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.786426Z  INFO server{id=27}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.786502Z  INFO server{id=27}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.786753Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.796868Z  INFO server{id=17}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.797061Z  INFO server{id=17}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.797426Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.801259Z  INFO server{id=5}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.801362Z  INFO server{id=5}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.801440Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.801818Z  INFO server{id=3}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.801887Z  INFO server{id=3}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.801962Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.806802Z  INFO server{id=26}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.806887Z  INFO server{id=26}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.807070Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.811341Z  INFO server{id=25}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.815153Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:54.820941Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.826582Z  INFO server{id=25}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.826699Z  INFO server{id=25}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.836263Z  INFO server{id=29}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.836839Z  INFO server{id=29}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.837599Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:54.840843Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.844371Z  INFO server{id=8}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:54.846405Z  INFO server{id=12}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.856117Z  INFO server{id=29}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.868045Z  INFO server{id=30}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.869003Z  INFO server{id=30}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.869123Z  INFO server{id=30}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.869302Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.881281Z  INFO server{id=6}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.882066Z  INFO server{id=12}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.882159Z  INFO server{id=12}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.882242Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.882534Z  INFO server{id=6}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.882608Z  INFO server{id=6}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.882697Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.887284Z  INFO server{id=29}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.887864Z  INFO server{id=29}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.889326Z  INFO server{id=28}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.889824Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.889941Z  INFO server{id=28}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.890531Z  INFO server{id=28}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.890656Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.908278Z  INFO server{id=17}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:54.890469Z  INFO server{id=24}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.913328Z  INFO server{id=24}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.913452Z  INFO server{id=24}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.913593Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.924288Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:54.926646Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:54.930573Z  INFO server{id=29}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.930646Z  INFO server{id=11}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:54.931218Z  INFO server{id=15}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.931456Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:54.931767Z  INFO server{id=15}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.931828Z  INFO server{id=15}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.931888Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.932529Z  INFO server{id=31}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.933438Z  INFO server{id=31}: librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:54.933648Z  INFO server{id=31}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.933946Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.945294Z  INFO server{id=31}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.945874Z  INFO server{id=31}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.945928Z  INFO server{id=31}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.946116Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.988725Z  INFO server{id=30}: librtbit::tests::e2e: started session
[INFO] [stdout] 2026-10-06T19:24:54.993603Z  INFO server{id=30}: librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:54.993805Z  INFO server{id=30}: librtbit::tests::e2e: added torrent
[INFO] [stdout] 2026-10-06T19:24:54.995172Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:54.996095Z  INFO server{id=11}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:54.998454Z  INFO server{id=17}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.002142Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:54.994396Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.019449Z  INFO server{id=4}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.059933Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.076047Z  INFO server{id=22}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.105128Z  INFO server{id=28}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.134296Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.137313Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.140412Z  INFO server{id=1}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.151103Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.158043Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.165116Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.170357Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.177814Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.181554Z  INFO server{id=23}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.187517Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.190528Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.192216Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.202999Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.203789Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.205255Z  INFO server{id=3}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.214988Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.216466Z  INFO server{id=5}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.223064Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.234071Z  INFO server{id=25}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.246671Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.246860Z  INFO server{id=31}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.247074Z  INFO server{id=10}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.248545Z  INFO server{id=9}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.252465Z  INFO server{id=22}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.256065Z  INFO server{id=27}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.271351Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.272473Z  INFO server{id=12}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.272636Z  INFO server{id=13}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.272842Z  INFO server{id=20}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.277740Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.281400Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.282668Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.283715Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.285070Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.291556Z  INFO server{id=27}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.294058Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.294780Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.301834Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.311705Z  INFO server{id=30}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.312952Z  INFO server{id=16}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.315054Z  INFO server{id=24}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.332171Z  INFO server{id=15}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.343768Z  INFO server{id=6}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.345018Z  INFO server{id=14}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.345787Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.349144Z  INFO server{id=26}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.352070Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.355642Z  INFO server{id=4}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.363240Z  INFO server{id=7}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.369546Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.370867Z  INFO server{id=15}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.376587Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.386523Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.408273Z  INFO server{id=0}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.410374Z  INFO server{id=19}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.414795Z  INFO server{id=2}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.421878Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.433952Z  INFO server{id=18}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.438051Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.440776Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.444180Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.448300Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.456921Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.461227Z  INFO server{id=18}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.461521Z  INFO server{id=1}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.452846Z  INFO server{id=19}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.463895Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.453769Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.469871Z  INFO server{id=30}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.472125Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.486293Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.486621Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.492118Z  INFO server{id=28}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.492315Z  INFO server{id=2}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.501419Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.502734Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.514298Z  INFO server{id=24}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.518569Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.528050Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.528280Z  INFO server{id=25}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.543448Z  INFO server{id=5}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.549439Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.555077Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.566315Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.572939Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.575815Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.577183Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.602284Z  INFO server{id=3}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.604544Z  INFO server{id=9}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.631892Z  INFO server{id=14}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.632110Z  INFO server{id=29}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.634358Z  INFO server{id=31}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.636602Z  INFO server{id=7}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.638850Z  INFO server{id=8}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.682721Z  INFO server{id=12}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.684037Z  INFO server{id=6}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.684188Z  INFO librtbit::tests::e2e: started all servers, starting client
[INFO] [stdout] 2026-10-06T19:24:55.684605Z  WARN librqbit_utp::socket: couldn't set UDP rcv buf size to requested value. There might be packet loss, try increasing rmem_max or equivalent. prev=212992 current=8388608 expected=167772160
[INFO] [stdout] 2026-10-06T19:24:55.685114Z  INFO librtbit::listen: Listening on UDP 127.0.0.1:15099 for incoming uTP peer connections
[INFO] [stdout] 2026-10-06T19:24:55.720141Z  INFO librtbit::session: will use JSON database: "/tmp/rtbit_e2e_clientpO0eMU/session" for session persistence
[INFO] [stdout] 2026-10-06T19:24:55.720565Z  INFO librtbit::tests::e2e: started client session
[INFO] [stdout] 2026-10-06T19:24:55.754267Z  INFO server{id=16}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.757485Z  INFO server{id=29}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.781290Z  INFO server{id=23}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.807407Z  INFO server{id=26}: librtbit::tests::e2e: torrent is live
[INFO] [stdout] 2026-10-06T19:24:55.807545Z  INFO librtbit::tests::e2e: started all servers, starting client
[INFO] [stdout] 2026-10-06T19:24:55.864391Z  INFO librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:24:55.864490Z  INFO librtbit::tests::e2e: added handle
[INFO] [stdout] 2026-10-06T19:24:55.866232Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:55.869021Z  INFO librtbit::session: will use JSON database: "/tmp/rtbit_e2e_clientt9Uspf/session" for session persistence
[INFO] [stdout] 2026-10-06T19:24:55.869124Z  INFO librtbit::tests::e2e: started client session
[INFO] [stdout] 2026-10-06T19:24:55.897603Z  INFO librtbit::torrent_state::initializing: Initial check results: have 0, needed 61.0Mi, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:55.993652Z  INFO librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:24:55.993715Z  INFO librtbit::tests::e2e: added handle
[INFO] [stdout] 2026-10-06T19:24:55.994205Z  INFO librtbit::torrent_state::initializing: Doing initial checksum validation, this might take a while...
[INFO] [stdout] 2026-10-06T19:24:56.003730Z  INFO librtbit::torrent_state::initializing: Initial check results: have 0, needed 61.0Mi, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:24:56.105240Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] test read_buf::tests::can_read_long_metainfo_correctly ... ok
[INFO] [stdout] 2026-10-06T19:24:57.281734Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.304014Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.324807Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.337255Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.342631Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.356014Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.390242Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.409952Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.413544Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.429239Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.452662Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.471982Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.479399Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.489782Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.491891Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.513821Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.518938Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.525865Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.541748Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.592447Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.615821Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.667648Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.722919Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.05%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.767561Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.10%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.810933Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.10%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.825440Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.05%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.848984Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.15%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.878854Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.20%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.914619Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.05%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.931951Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.26%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:57.961473Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.36%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.022053Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.20%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.023954Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.36%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.076942Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.56%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.104095Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.67%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.111690Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.61%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.147125Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.77%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.185040Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.82%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.197911Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="2.15%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 19 }"
[INFO] [stdout] 2026-10-06T19:24:58.217762Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="0.92%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.233718Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="1.02%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.257961Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="1.13%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.266852Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="1.23%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.275467Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="1.28%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 0 }"
[INFO] [stdout] 2026-10-06T19:24:58.287442Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="1.38%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1 }"
[INFO] [stdout] 2026-10-06T19:24:58.301831Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="4.86%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 57 }"
[INFO] [stdout] 2026-10-06T19:24:58.365693Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="8.70%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:58.397826Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="7.73%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 91 }"
[INFO] [stdout] 2026-10-06T19:24:58.465806Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="13.47%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:58.497212Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="11.01%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 139 }"
[INFO] [stdout] test tests::mock_tracker::tests::live_tracker_worker_observes_announce_port_update ... ok
[INFO] [stdout] 2026-10-06T19:24:58.565957Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:58.595916Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="13.88%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 189 }"
[INFO] [stdout] 2026-10-06T19:24:58.665819Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:58.695099Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="16.44%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 239 }"
[INFO] [stdout] 2026-10-06T19:24:58.766074Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:58.797303Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="18.94%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 288 }"
[INFO] [stdout] 2026-10-06T19:24:58.866064Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:58.896506Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="21.50%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 338 }"
[INFO] [stdout] 2026-10-06T19:24:58.966124Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:58.995625Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="24.01%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 386 }"
[INFO] [stdout] 2026-10-06T19:24:59.066497Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:59.096335Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="26.42%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 434 }"
[INFO] [stdout] 2026-10-06T19:24:59.167884Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:59.201088Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="28.01%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 464 }"
[INFO] [stdout] 2026-10-06T19:24:59.266578Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:59.295897Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="30.05%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 504 }"
[INFO] [stdout] 2026-10-06T19:24:59.365842Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:59.395159Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="32.51%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 553 }"
[INFO] [stdout] 2026-10-06T19:24:59.465557Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:59.496740Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="35.48%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 611 }"
[INFO] [stdout] 2026-10-06T19:24:59.565926Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:59.596442Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="38.30%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 666 }"
[INFO] [stdout] 2026-10-06T19:24:59.666266Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:59.698312Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="40.81%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 716 }"
[INFO] [stdout] 2026-10-06T19:24:59.765785Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:59.796246Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="43.42%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 765 }"
[INFO] [stdout] 2026-10-06T19:24:59.866116Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:59.898305Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="46.08%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 818 }"
[INFO] [stdout] 2026-10-06T19:24:59.966859Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:24:59.997371Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="48.64%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 867 }"
[INFO] [stdout] 2026-10-06T19:25:00.066266Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:00.095827Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="51.15%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 918 }"
[INFO] [stdout] 2026-10-06T19:25:00.166582Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:00.197710Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="54.17%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 976 }"
[INFO] [stdout] 2026-10-06T19:25:00.266204Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:00.296641Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="57.24%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1037 }"
[INFO] [stdout] 2026-10-06T19:25:00.366354Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:00.396472Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="60.36%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1097 }"
[INFO] [stdout] 2026-10-06T19:25:00.467147Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:00.499037Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="62.92%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1149 }"
[INFO] [stdout] 2026-10-06T19:25:00.566570Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:00.598227Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="66.00%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1209 }"
[INFO] [stdout] 2026-10-06T19:25:00.666136Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:00.695990Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="69.28%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1270 }"
[INFO] [stdout] 2026-10-06T19:25:00.765998Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:00.797531Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="72.56%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1335 }"
[INFO] [stdout] 2026-10-06T19:25:00.869023Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:00.897704Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="75.48%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1394 }"
[INFO] [stdout] 2026-10-06T19:25:00.966530Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:00.994434Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="78.60%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1454 }"
[INFO] [stdout] 2026-10-06T19:25:01.075209Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:01.096391Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="82.18%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1525 }"
[INFO] [stdout] 2026-10-06T19:25:01.166045Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:01.194809Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="86.84%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1614 }"
[INFO] [stdout] 2026-10-06T19:25:01.265859Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:01.294669Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="90.37%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1678 }"
[INFO] [stdout] 2026-10-06T19:25:01.366021Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:01.394613Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="99.95%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 32, live_utp: 0, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1678 }"
[INFO] [stdout] 2026-10-06T19:25:01.423080Z  INFO librtbit::torrent_state::live: torrent finished downloading id=0 info_hash=81733b3f13a365b41dff412235c7cdbb2b0e5729
[INFO] [stdout] 2026-10-06T19:25:01.423574Z  INFO librtbit::tests::e2e: handle is completed
[INFO] [stdout] 2026-10-06T19:25:01.432555Z  INFO librtbit::session: deleted torrent id=0
[INFO] [stdout] 2026-10-06T19:25:01.432593Z  INFO librtbit::tests::e2e: deleted handle
[INFO] [stdout] 2026-10-06T19:25:01.435262Z  INFO librtbit::session: added torrent name="rtbit_e2eSjZ3Zb"
[INFO] [stdout] 2026-10-06T19:25:01.435356Z  INFO librtbit::tests::e2e: re-added handle
[INFO] [stdout] 2026-10-06T19:25:01.451111Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=0
[INFO] [stdout] 2026-10-06T19:25:01.466120Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:01.558334Z  INFO librtbit::session: deleted torrent id=0
[INFO] [stdout] 2026-10-06T19:25:01.558458Z  INFO librtbit::tests::e2e: all good
[INFO] [stdout] 2026-10-06T19:25:01.566505Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] test tests::e2e::test_e2e_download_tcp ... ok
[INFO] [stdout] 2026-10-06T19:25:01.666235Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:01.766027Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:01.866747Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:01.966372Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:02.066118Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:02.166338Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:02.266193Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:02.366001Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:02.466125Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:02.566347Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:02.666049Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:02.766536Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:02.866315Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:02.966428Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:03.066440Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:03.166777Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:03.266858Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 3 }"
[INFO] [stdout] 2026-10-06T19:25:03.375369Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.69%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 75 }"
[INFO] [stdout] 2026-10-06T19:25:03.477642Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="14.90%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 122 }"
[INFO] [stdout] 2026-10-06T19:25:03.573724Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="15.10%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 176 }"
[INFO] [stdout] 2026-10-06T19:25:03.679646Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="15.31%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 232 }"
[INFO] [stdout] 2026-10-06T19:25:03.774688Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="15.72%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 282 }"
[INFO] [stdout] 2026-10-06T19:25:03.866760Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="17.66%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 319 }"
[INFO] [stdout] 2026-10-06T19:25:03.968056Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="19.61%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 358 }"
[INFO] [stdout] 2026-10-06T19:25:04.066806Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="22.53%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 414 }"
[INFO] [stdout] 2026-10-06T19:25:04.167497Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="25.50%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 472 }"
[INFO] [stdout] 2026-10-06T19:25:04.270007Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="28.83%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 537 }"
[INFO] [stdout] 2026-10-06T19:25:04.367695Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="32.20%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 603 }"
[INFO] [stdout] 2026-10-06T19:25:04.465745Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="35.23%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 661 }"
[INFO] [stdout] 2026-10-06T19:25:04.568452Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="38.96%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 736 }"
[INFO] [stdout] 2026-10-06T19:25:04.667248Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="42.85%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 811 }"
[INFO] [stdout] 2026-10-06T19:25:04.766104Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="46.18%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 877 }"
[INFO] [stdout] 2026-10-06T19:25:04.866153Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="49.61%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 943 }"
[INFO] [stdout] 2026-10-06T19:25:04.967576Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="54.68%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1043 }"
[INFO] [stdout] 2026-10-06T19:25:05.066577Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="59.91%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1146 }"
[INFO] [stdout] 2026-10-06T19:25:05.166813Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="65.24%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1251 }"
[INFO] [stdout] 2026-10-06T19:25:05.267474Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="72.45%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1391 }"
[INFO] [stdout] 2026-10-06T19:25:05.366512Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="80.60%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1548 }"
[INFO] [stdout] 2026-10-06T19:25:05.467386Z  INFO stats_printer: librtbit::tests::e2e: progress_percent="92.27%" peers="AggregatePeerStats { queued: 0, connecting: 0, live: 32, live_tcp: 0, live_utp: 32, live_socks: 0, seen: 32, dead: 0, not_needed: 0, steals: 1670 }"
[INFO] [stdout] 2026-10-06T19:25:05.549370Z  INFO librtbit::torrent_state::live: torrent finished downloading id=0 info_hash=481feb78e692dfc330fe94033cb3dc391e8b7aa0
[INFO] [stdout] 2026-10-06T19:25:05.549533Z  INFO librtbit::tests::e2e: handle is completed
[INFO] [stdout] 2026-10-06T19:25:05.551931Z  INFO librtbit::session: deleted torrent id=0
[INFO] [stdout] 2026-10-06T19:25:05.552230Z  INFO librtbit::tests::e2e: deleted handle
[INFO] [stdout] 2026-10-06T19:25:05.555812Z  INFO librtbit::session: added torrent name="rtbit_e2evnGdnk"
[INFO] [stdout] 2026-10-06T19:25:05.555908Z  INFO librtbit::tests::e2e: re-added handle
[INFO] [stdout] 2026-10-06T19:25:05.564806Z  INFO librtbit::torrent_state::initializing: Initial check results: have 61.0Mi, needed 0, total selected 61.0Mi torrent=1
[INFO] [stdout] 2026-10-06T19:25:05.680579Z  INFO librtbit::session: deleted torrent id=1
[INFO] [stdout] 2026-10-06T19:25:05.680672Z  INFO librtbit::tests::e2e: all good
[INFO] [stdout] 2026-10-06T19:25:05.686799Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.689439Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.690488Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.693225Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.695604Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.697146Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.698198Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.699731Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.700863Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.702165Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.708299Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.709562Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.714568Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.718110Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] 2026-10-06T19:25:05.720653Z  WARN librtbit::session::network: error accepting: error accepting uTP: dispatcher dead
[INFO] [stdout] test tests::e2e::test_e2e_download_utp ... ok
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- ip_ranges::tests::test_list_from_plaintext_file stdout ----
[INFO] [stdout] Error: Read-only file system (os error 30)
[INFO] [stdout] 
[INFO] [stdout] Stack backtrace:
[INFO] [stdout]    0: <anyhow::Error as core::convert::From<core::io::error::Error>>::from
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/anyhow-1.0.102/src/backtrace.rs:10:14
[INFO] [stdout]    1: <core::result::Result<(), anyhow::Error> as core::ops::try_trait::FromResidual<core::result::Result<core::convert::Infallible, core::io::error::Error>>>::from_residual
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/result.rs:2193:27
[INFO] [stdout]    2: librtbit::ip_ranges::tests::test_list_from_plaintext_file::{closure#0}
[INFO] [stdout]              at ./src/ip_ranges.rs:224:29
[INFO] [stdout]    3: <core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>> as core::future::future::Future>::poll
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/future/future.rs:133:9
[INFO] [stdout]    4: <core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>> as core::future::future::Future>::poll
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/future/future.rs:133:9
[INFO] [stdout]    5: <tokio::runtime::scheduler::current_thread::CoreGuard>::block_on::<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}::{closure#0}::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/current_thread/mod.rs:778:70
[INFO] [stdout]    6: tokio::task::coop::with_budget::<core::task::poll::Poll<core::result::Result<(), anyhow::Error>>, <tokio::runtime::scheduler::current_thread::CoreGuard>::block_on<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}::{closure#0}::{closure#0}>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/task/coop/mod.rs:167:5
[INFO] [stdout]    7: tokio::task::coop::budget::<core::task::poll::Poll<core::result::Result<(), anyhow::Error>>, <tokio::runtime::scheduler::current_thread::CoreGuard>::block_on<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}::{closure#0}::{closure#0}>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/task/coop/mod.rs:133:5
[INFO] [stdout]    8: <tokio::runtime::scheduler::current_thread::CoreGuard>::block_on::<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/current_thread/mod.rs:778:25
[INFO] [stdout]    9: <tokio::runtime::scheduler::current_thread::Context>::enter::<core::task::poll::Poll<core::result::Result<(), anyhow::Error>>, <tokio::runtime::scheduler::current_thread::CoreGuard>::block_on<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}::{closure#0}>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/current_thread/mod.rs:451:19
[INFO] [stdout]   10: <tokio::runtime::scheduler::current_thread::CoreGuard>::block_on::<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/current_thread/mod.rs:777:44
[INFO] [stdout]   11: <tokio::runtime::scheduler::current_thread::CoreGuard>::enter::<<tokio::runtime::scheduler::current_thread::CoreGuard>::block_on<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}, core::option::Option<core::result::Result<(), anyhow::Error>>>::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/current_thread/mod.rs:865:68
[INFO] [stdout]   12: <tokio::runtime::context::scoped::Scoped<tokio::runtime::scheduler::Context>>::set::<<tokio::runtime::scheduler::current_thread::CoreGuard>::enter<<tokio::runtime::scheduler::current_thread::CoreGuard>::block_on<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}, core::option::Option<core::result::Result<(), anyhow::Error>>>::{closure#0}, (alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core>, core::option::Option<core::result::Result<(), anyhow::Error>>)>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context/scoped.rs:40:9
[INFO] [stdout]   13: tokio::runtime::context::set_scheduler::<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core>, core::option::Option<core::result::Result<(), anyhow::Error>>), <tokio::runtime::scheduler::current_thread::CoreGuard>::enter<<tokio::runtime::scheduler::current_thread::CoreGuard>::block_on<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}, core::option::Option<core::result::Result<(), anyhow::Error>>>::{closure#0}>::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context.rs:181:38
[INFO] [stdout]   14: <std::thread::local::LocalKey<tokio::runtime::context::Context>>::try_with::<tokio::runtime::context::set_scheduler<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core>, core::option::Option<core::result::Result<(), anyhow::Error>>), <tokio::runtime::scheduler::current_thread::CoreGuard>::enter<<tokio::runtime::scheduler::current_thread::CoreGuard>::block_on<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}, core::option::Option<core::result::Result<(), anyhow::Error>>>::{closure#0}>::{closure#0}, (alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core>, core::option::Option<core::result::Result<(), anyhow::Error>>)>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/thread/local.rs:463:12
[INFO] [stdout]   15: <std::thread::local::LocalKey<tokio::runtime::context::Context>>::with::<tokio::runtime::context::set_scheduler<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core>, core::option::Option<core::result::Result<(), anyhow::Error>>), <tokio::runtime::scheduler::current_thread::CoreGuard>::enter<<tokio::runtime::scheduler::current_thread::CoreGuard>::block_on<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}, core::option::Option<core::result::Result<(), anyhow::Error>>>::{closure#0}>::{closure#0}, (alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core>, core::option::Option<core::result::Result<(), anyhow::Error>>)>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/thread/local.rs:427:20
[INFO] [stdout]   16: tokio::runtime::context::set_scheduler::<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core>, core::option::Option<core::result::Result<(), anyhow::Error>>), <tokio::runtime::scheduler::current_thread::CoreGuard>::enter<<tokio::runtime::scheduler::current_thread::CoreGuard>::block_on<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}, core::option::Option<core::result::Result<(), anyhow::Error>>>::{closure#0}>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context.rs:181:17
[INFO] [stdout]   17: <tokio::runtime::scheduler::current_thread::CoreGuard>::enter::<<tokio::runtime::scheduler::current_thread::CoreGuard>::block_on<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>::{closure#0}, core::option::Option<core::result::Result<(), anyhow::Error>>>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/current_thread/mod.rs:865:27
[INFO] [stdout]   18: <tokio::runtime::scheduler::current_thread::CoreGuard>::block_on::<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/current_thread/mod.rs:765:24
[INFO] [stdout]   19: <tokio::runtime::scheduler::current_thread::CurrentThread>::block_on::<core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>::{closure#0}
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/current_thread/mod.rs:205:33
[INFO] [stdout]   20: tokio::runtime::context::runtime::enter_runtime::<<tokio::runtime::scheduler::current_thread::CurrentThread>::block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>::{closure#0}, core::result::Result<(), anyhow::Error>>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context/runtime.rs:65:16
[INFO] [stdout]   21: <tokio::runtime::scheduler::current_thread::CurrentThread>::block_on::<core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/current_thread/mod.rs:193:9
[INFO] [stdout]   22: <tokio::runtime::runtime::Runtime>::block_on_inner::<core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/runtime.rs:371:52
[INFO] [stdout]   23: <tokio::runtime::runtime::Runtime>::block_on::<core::pin::Pin<&mut dyn core::future::future::Future<Output = core::result::Result<(), anyhow::Error>>>>
[INFO] [stdout]              at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/runtime.rs:345:18
[INFO] [stdout]   24: librtbit::ip_ranges::tests::test_list_from_plaintext_file
[INFO] [stdout]              at ./src/ip_ranges.rs:240:11
[INFO] [stdout]   25: librtbit::ip_ranges::tests::test_list_from_plaintext_file::{closure#0}
[INFO] [stdout]              at ./src/ip_ranges.rs:222:49
[INFO] [stdout]   26: <librtbit::ip_ranges::tests::test_list_from_plaintext_file::{closure#0} as core::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   27: <fn() -> core::result::Result<(), alloc::string::String> as core::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   28: test::__rust_begin_short_backtrace::<core::result::Result<(), alloc::string::String>, fn() -> core::result::Result<(), alloc::string::String>>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/test/src/lib.rs:733:18
[INFO] [stdout]   29: test::run_test_in_process::{closure#0}
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/test/src/lib.rs:756:74
[INFO] [stdout]   30: <core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure#0}> as core::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   31: std::panicking::catch_unwind::do_call::<core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure#0}>, core::result::Result<(), alloc::string::String>>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:576:43
[INFO] [stdout]   32: std::panicking::catch_unwind::<core::result::Result<(), alloc::string::String>, core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure#0}>>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:544:19
[INFO] [stdout]   33: std::panic::catch_unwind::<core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure#0}>, core::result::Result<(), alloc::string::String>>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panic.rs:359:14
[INFO] [stdout]   34: test::run_test_in_process
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/test/src/lib.rs:756:27
[INFO] [stdout]   35: test::run_test::{closure#0}
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/test/src/lib.rs:677:43
[INFO] [stdout]   36: test::run_test::{closure#1}
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/test/src/lib.rs:707:41
[INFO] [stdout]   37: std::sys::backtrace::__rust_begin_short_backtrace::<test::run_test::{closure#1}, ()>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   38: std::thread::lifecycle::spawn_unchecked::<test::run_test::{closure#1}, ()>::{closure#1}::{closure#0}
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/thread/lifecycle.rs:70:13
[INFO] [stdout]   39: <core::panic::unwind_safe::AssertUnwindSafe<std::thread::lifecycle::spawn_unchecked<test::run_test::{closure#1}, ()>::{closure#1}::{closure#0}> as core::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   40: std::panicking::catch_unwind::do_call::<core::panic::unwind_safe::AssertUnwindSafe<std::thread::lifecycle::spawn_unchecked<test::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:576:43
[INFO] [stdout]   41: std::panicking::catch_unwind::<(), core::panic::unwind_safe::AssertUnwindSafe<std::thread::lifecycle::spawn_unchecked<test::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:544:19
[INFO] [stdout]   42: std::panic::catch_unwind::<core::panic::unwind_safe::AssertUnwindSafe<std::thread::lifecycle::spawn_unchecked<test::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panic.rs:359:14
[INFO] [stdout]   43: std::thread::lifecycle::spawn_unchecked::<test::run_test::{closure#1}, ()>::{closure#1}
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/thread/lifecycle.rs:68:26
[INFO] [stdout]   44: <std::thread::lifecycle::spawn_unchecked<test::run_test::{closure#1}, ()>::{closure#1} as core::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   45: <alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output = ()> + core::marker::Send> as core::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/alloc/src/boxed.rs:2320:9
[INFO] [stdout]   46: <std::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]              at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/sys/thread/unix.rs:123:17
[INFO] [stdout]   47: <unknown>
[INFO] [stdout]   48: clone
[INFO] [stdout] 
[INFO] [stdout] ---- session::tests::test_magnet_resolution_timeout stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'session::tests::test_magnet_resolution_timeout' (4225) panicked at src/session/mod.rs:1471:9:
[INFO] [stdout] error message should mention timeout, got: input address stream exhausted, no way to discover torrent metainfo
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x612956301051 - std[70759c8f55707aa4]::backtrace_rs::backtrace::libunwind::trace
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x612956301051 - std[70759c8f55707aa4]::backtrace_rs::backtrace::trace_unsynchronized::<std[70759c8f55707aa4]::sys::backtrace::_print_fmt::{closure#1}>
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x612956301051 - std[70759c8f55707aa4]::sys::backtrace::_print_fmt
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x612956301051 - <<std[70759c8f55707aa4]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[df12db4294e9bfd3]::fmt::Display>::fmt
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x61295631a2da - <core[df12db4294e9bfd3]::fmt::rt::Argument>::fmt
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x61295631a2da - core[df12db4294e9bfd3]::fmt::write
[INFO] [stdout]    6:     0x612956306a2c - core[df12db4294e9bfd3]::io::write::default_write_fmt::<alloc[2182bb758b4b3781]::vec::Vec<u8>>
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/io/write.rs:402:11
[INFO] [stdout]    7:     0x612956306a2c - <alloc[2182bb758b4b3781]::vec::Vec<u8> as core[df12db4294e9bfd3]::io::write::Write>::write_fmt
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/io/write.rs:335:13
[INFO] [stdout]    8:     0x6129562d6de6 - <std[70759c8f55707aa4]::sys::backtrace::BacktraceLock>::print
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x6129562d6de6 - std[70759c8f55707aa4]::panicking::default_hook::{closure#0}
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x6129562f62c9 - std[70759c8f55707aa4]::panicking::default_hook
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x61295589a980 - <alloc[2182bb758b4b3781]::boxed::Box<dyn for<'a, 'b> core[df12db4294e9bfd3]::ops::function::Fn<(&'a std[70759c8f55707aa4]::panic::PanicHookInfo<'b>,), Output = ()> + core[df12db4294e9bfd3]::marker::Send + core[df12db4294e9bfd3]::marker::Sync> as core[df12db4294e9bfd3]::ops::function::Fn<(&std[70759c8f55707aa4]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/alloc/src/boxed.rs:2334:9
[INFO] [stdout]   12:     0x61295589a980 - test[9d35eded1c95d3be]::test_main_inner::<test[9d35eded1c95d3be]::test_main_static::{closure#0}>::{closure#0}
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/test/src/lib.rs:155:21
[INFO] [stdout]   13:     0x6129562f65f2 - <alloc[2182bb758b4b3781]::boxed::Box<dyn for<'a, 'b> core[df12db4294e9bfd3]::ops::function::Fn<(&'a std[70759c8f55707aa4]::panic::PanicHookInfo<'b>,), Output = ()> + core[df12db4294e9bfd3]::marker::Send + core[df12db4294e9bfd3]::marker::Sync> as core[df12db4294e9bfd3]::ops::function::Fn<(&std[70759c8f55707aa4]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/alloc/src/boxed.rs:2334:9
[INFO] [stdout]   14:     0x6129562f65f2 - std[70759c8f55707aa4]::panicking::panic_with_hook
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:823:13
[INFO] [stdout]   15:     0x6129562d6e92 - std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:688:13
[INFO] [stdout]   16:     0x6129562cf009 - std[70759c8f55707aa4]::sys::backtrace::__rust_end_short_backtrace::<std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x6129562d800d - __rustc[8fa7c3cbc660c2b3]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:679:5
[INFO] [stdout]   18:     0x61295631ab7c - core[df12db4294e9bfd3]::panicking::panic_fmt
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x6129555587e6 - librtbit[7dd0771854cd495a]::session::tests::test_magnet_resolution_timeout::{closure#0}
[INFO] [stdout]                                at /opt/rustwide/workdir/src/session/mod.rs:1471:9
[INFO] [stdout]   20:     0x6129554320a2 - <core[df12db4294e9bfd3]::pin::Pin<&mut dyn core[df12db4294e9bfd3]::future::future::Future<Output = ()>> as core[df12db4294e9bfd3]::future::future::Future>::poll
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/future/future.rs:133:9
[INFO] [stdout]   21:     0x6129553d395d - <tokio[a954772de56ca90a]::runtime::park::CachedParkThread>::block_on::<core[df12db4294e9bfd3]::pin::Pin<&mut dyn core[df12db4294e9bfd3]::future::future::Future<Output = ()>>>::{closure#0}
[INFO] [stdout]                                at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/park.rs:284:71
[INFO] [stdout]   22:     0x61295539de0e - tokio[a954772de56ca90a]::task::coop::with_budget::<core[df12db4294e9bfd3]::task::poll::Poll<()>, <tokio[a954772de56ca90a]::runtime::park::CachedParkThread>::block_on<core[df12db4294e9bfd3]::pin::Pin<&mut dyn core[df12db4294e9bfd3]::future::future::Future<Output = ()>>>::{closure#0}>
[INFO] [stdout]                                at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/task/coop/mod.rs:167:5
[INFO] [stdout]   23:     0x61295539de0e - tokio[a954772de56ca90a]::task::coop::budget::<core[df12db4294e9bfd3]::task::poll::Poll<()>, <tokio[a954772de56ca90a]::runtime::park::CachedParkThread>::block_on<core[df12db4294e9bfd3]::pin::Pin<&mut dyn core[df12db4294e9bfd3]::future::future::Future<Output = ()>>>::{closure#0}>
[INFO] [stdout]                                at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/task/coop/mod.rs:133:5
[INFO] [stdout]   24:     0x61295539de0e - <tokio[a954772de56ca90a]::runtime::park::CachedParkThread>::block_on::<core[df12db4294e9bfd3]::pin::Pin<&mut dyn core[df12db4294e9bfd3]::future::future::Future<Output = ()>>>
[INFO] [stdout]                                at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/park.rs:284:31
[INFO] [stdout]   25:     0x61295570d9a6 - <tokio[a954772de56ca90a]::runtime::context::blocking::BlockingRegionGuard>::block_on::<core[df12db4294e9bfd3]::pin::Pin<&mut dyn core[df12db4294e9bfd3]::future::future::Future<Output = ()>>>
[INFO] [stdout]                                at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context/blocking.rs:66:14
[INFO] [stdout]   26:     0x6129555ca7f8 - <tokio[a954772de56ca90a]::runtime::scheduler::multi_thread::MultiThread>::block_on::<core[df12db4294e9bfd3]::pin::Pin<&mut dyn core[df12db4294e9bfd3]::future::future::Future<Output = ()>>>::{closure#0}
[INFO] [stdout]                                at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/mod.rs:92:22
[INFO] [stdout]   27:     0x6129557a0243 - tokio[a954772de56ca90a]::runtime::context::runtime::enter_runtime::<<tokio[a954772de56ca90a]::runtime::scheduler::multi_thread::MultiThread>::block_on<core[df12db4294e9bfd3]::pin::Pin<&mut dyn core[df12db4294e9bfd3]::future::future::Future<Output = ()>>>::{closure#0}, ()>
[INFO] [stdout]                                at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/context/runtime.rs:65:16
[INFO] [stdout]   28:     0x6129555bcd84 - <tokio[a954772de56ca90a]::runtime::scheduler::multi_thread::MultiThread>::block_on::<core[df12db4294e9bfd3]::pin::Pin<&mut dyn core[df12db4294e9bfd3]::future::future::Future<Output = ()>>>
[INFO] [stdout]                                at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/scheduler/multi_thread/mod.rs:91:9
[INFO] [stdout]   29:     0x61295570d43f - <tokio[a954772de56ca90a]::runtime::runtime::Runtime>::block_on_inner::<core[df12db4294e9bfd3]::pin::Pin<&mut dyn core[df12db4294e9bfd3]::future::future::Future<Output = ()>>>
[INFO] [stdout]                                at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/runtime.rs:373:50
[INFO] [stdout]   30:     0x61295570d75b - <tokio[a954772de56ca90a]::runtime::runtime::Runtime>::block_on::<core[df12db4294e9bfd3]::pin::Pin<&mut dyn core[df12db4294e9bfd3]::future::future::Future<Output = ()>>>
[INFO] [stdout]                                at /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.52.3/src/runtime/runtime.rs:345:18
[INFO] [stdout]   31:     0x61295556538e - librtbit[7dd0771854cd495a]::session::tests::test_magnet_resolution_timeout
[INFO] [stdout]                                at /opt/rustwide/workdir/src/session/mod.rs:1479:10
[INFO] [stdout]   32:     0x612955557357 - librtbit[7dd0771854cd495a]::session::tests::test_magnet_resolution_timeout::{closure#0}
[INFO] [stdout]                                at /opt/rustwide/workdir/src/session/mod.rs:1430:46
[INFO] [stdout]   33:     0x61295531fbf6 - <librtbit[7dd0771854cd495a]::session::tests::test_magnet_resolution_timeout::{closure#0} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   34:     0x61295588dc6b - <fn() -> core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String> as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   35:     0x61295588dc6b - test[9d35eded1c95d3be]::__rust_begin_short_backtrace::<core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>, fn() -> core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>>
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/test/src/lib.rs:733:18
[INFO] [stdout]   36:     0x61295589b2d5 - test[9d35eded1c95d3be]::run_test_in_process::{closure#0}
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/test/src/lib.rs:756:74
[INFO] [stdout]   37:     0x61295589b2d5 - <core[df12db4294e9bfd3]::panic::unwind_safe::AssertUnwindSafe<test[9d35eded1c95d3be]::run_test_in_process::{closure#0}> as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   38:     0x61295589b2d5 - std[70759c8f55707aa4]::panicking::catch_unwind::do_call::<core[df12db4294e9bfd3]::panic::unwind_safe::AssertUnwindSafe<test[9d35eded1c95d3be]::run_test_in_process::{closure#0}>, core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>>
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:576:43
[INFO] [stdout]   39:     0x61295589b2d5 - std[70759c8f55707aa4]::panicking::catch_unwind::<core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>, core[df12db4294e9bfd3]::panic::unwind_safe::AssertUnwindSafe<test[9d35eded1c95d3be]::run_test_in_process::{closure#0}>>
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:544:19
[INFO] [stdout]   40:     0x61295589b2d5 - std[70759c8f55707aa4]::panic::catch_unwind::<core[df12db4294e9bfd3]::panic::unwind_safe::AssertUnwindSafe<test[9d35eded1c95d3be]::run_test_in_process::{closure#0}>, core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>>
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panic.rs:359:14
[INFO] [stdout]   41:     0x61295589b2d5 - test[9d35eded1c95d3be]::run_test_in_process
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/test/src/lib.rs:756:27
[INFO] [stdout]   42:     0x61295589b2d5 - test[9d35eded1c95d3be]::run_test::{closure#0}
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/test/src/lib.rs:677:43
[INFO] [stdout]   43:     0x612955894b94 - test[9d35eded1c95d3be]::run_test::{closure#1}
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/test/src/lib.rs:707:41
[INFO] [stdout]   44:     0x612955894b94 - std[70759c8f55707aa4]::sys::backtrace::__rust_begin_short_backtrace::<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   45:     0x61295589e432 - std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked::<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/thread/lifecycle.rs:70:13
[INFO] [stdout]   46:     0x61295589e432 - <core[df12db4294e9bfd3]::panic::unwind_safe::AssertUnwindSafe<std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}> as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   47:     0x61295589e432 - std[70759c8f55707aa4]::panicking::catch_unwind::do_call::<core[df12db4294e9bfd3]::panic::unwind_safe::AssertUnwindSafe<std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:576:43
[INFO] [stdout]   48:     0x61295589e432 - std[70759c8f55707aa4]::panicking::catch_unwind::<(), core[df12db4294e9bfd3]::panic::unwind_safe::AssertUnwindSafe<std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>>
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panicking.rs:544:19
[INFO] [stdout]   49:     0x61295589e432 - std[70759c8f55707aa4]::panic::catch_unwind::<core[df12db4294e9bfd3]::panic::unwind_safe::AssertUnwindSafe<std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/panic.rs:359:14
[INFO] [stdout]   50:     0x61295589e432 - std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked::<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1}
[INFO] [stderr] error: test failed, to rerun pass `--lib`
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/thread/lifecycle.rs:68:26
[INFO] [stdout]   51:     0x61295589e432 - <std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   52:     0x6129562ff909 - <alloc[2182bb758b4b3781]::boxed::Box<dyn core[df12db4294e9bfd3]::ops::function::FnOnce<(), Output = ()> + core[df12db4294e9bfd3]::marker::Send> as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/alloc/src/boxed.rs:2320:9
[INFO] [stdout]   53:     0x6129562ff909 - <std[70759c8f55707aa4]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]                                at /rustc/dfb0accb7f508ae8be965d8629557221c889dd98/library/std/src/sys/thread/unix.rs:123:17
[INFO] [stdout]   54:     0x73565bc14dfa - <unknown>
[INFO] [stdout]   55:     0x73565bca83d4 - clone
[INFO] [stdout]   56:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     ip_ranges::tests::test_list_from_plaintext_file
[INFO] [stdout]     session::tests::test_magnet_resolution_timeout
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 112 passed; 2 failed; 5 ignored; 0 measured; 0 filtered out; finished in 12.64s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453", kill_on_drop: false }`
[INFO] [stdout] 0703b2f02b54fde62ef449d97acddb7be9a2fd8fb65a5ca7fd0bedd132a16453
