[INFO] cloning repository https://github.com/tomas-rampas/raft-consensus-poc
[INFO] running `Command { std: "git" "-c" "credential.helper=" "-c" "credential.helper=/workspace/cargo-home/bin/git-credential-null" "clone" "--bare" "https://github.com/tomas-rampas/raft-consensus-poc" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Ftomas-rampas%2Fraft-consensus-poc", kill_on_drop: false }`
[INFO] [stderr] Cloning into bare repository '/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Ftomas-rampas%2Fraft-consensus-poc'...
[INFO] running `Command { std: "git" "rev-parse" "HEAD", kill_on_drop: false }`
[INFO] [stdout] 4579047e815845c9493133ba0b6b4f46c54bb8d5
[INFO] testing tomas-rampas/raft-consensus-poc against master#cdb45c87e2cd43495379f7e867e3cc15dcee9f93 for pr-145838-1
[INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Ftomas-rampas%2Fraft-consensus-poc" "/workspace/builds/worker-0-tc1/source", kill_on_drop: false }`
[INFO] [stderr] Cloning into '/workspace/builds/worker-0-tc1/source'...
[INFO] [stderr] done.
[INFO] started tweaking git repo https://github.com/tomas-rampas/raft-consensus-poc
[INFO] finished tweaking git repo https://github.com/tomas-rampas/raft-consensus-poc
[INFO] tweaked toml for git repo https://github.com/tomas-rampas/raft-consensus-poc written to /workspace/builds/worker-0-tc1/source/Cargo.toml
[INFO] validating manifest of git repo https://github.com/tomas-rampas/raft-consensus-poc on toolchain cdb45c87e2cd43495379f7e867e3cc15dcee9f93
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate git repo https://github.com/tomas-rampas/raft-consensus-poc 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" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:7ad1b28ee6f5f7f699f6cf7015098d6ccdd96d6f2d78dd06228f5b4c9faf309c" "/opt/rustwide/cargo-home/bin/cargo" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] a42f9462d9ec364855855607f74efe75ffd5ab9a490bdb95a23620d5f964de74
[INFO] running `Command { std: "docker" "start" "-a" "a42f9462d9ec364855855607f74efe75ffd5ab9a490bdb95a23620d5f964de74", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "a42f9462d9ec364855855607f74efe75ffd5ab9a490bdb95a23620d5f964de74", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "a42f9462d9ec364855855607f74efe75ffd5ab9a490bdb95a23620d5f964de74", kill_on_drop: false }`
[INFO] [stdout] a42f9462d9ec364855855607f74efe75ffd5ab9a490bdb95a23620d5f964de74
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:7ad1b28ee6f5f7f699f6cf7015098d6ccdd96d6f2d78dd06228f5b4c9faf309c" "/opt/rustwide/cargo-home/bin/cargo" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 0d73b6eee13ed19d64d8cba380a1620e9e046b6b1b83ecd0cebc7db0ebd617e5
[INFO] running `Command { std: "docker" "start" "-a" "0d73b6eee13ed19d64d8cba380a1620e9e046b6b1b83ecd0cebc7db0ebd617e5", kill_on_drop: false }`
[INFO] [stderr]    Compiling smallvec v1.15.1
[INFO] [stderr]    Compiling bytes v1.10.1
[INFO] [stderr]    Compiling icu_properties_data v2.0.1
[INFO] [stderr]    Compiling lock_api v0.4.13
[INFO] [stderr]    Compiling parking_lot_core v0.9.11
[INFO] [stderr]    Compiling httparse v1.10.1
[INFO] [stderr]    Compiling slab v0.4.10
[INFO] [stderr]    Compiling syn v2.0.104
[INFO] [stderr]    Compiling icu_normalizer_data v2.0.0
[INFO] [stderr]    Compiling signal-hook-registry v1.4.6
[INFO] [stderr]    Compiling mio v1.0.4
[INFO] [stderr]    Compiling socket2 v0.6.0
[INFO] [stderr]    Compiling crypto-common v0.1.6
[INFO] [stderr]    Compiling tracing-core v0.1.34
[INFO] [stderr]    Compiling utf-8 v0.7.6
[INFO] [stderr]    Compiling data-encoding v2.9.0
[INFO] [stderr]    Compiling hashbrown v0.15.4
[INFO] [stderr]    Compiling num-traits v0.2.19
[INFO] [stderr]    Compiling digest v0.10.7
[INFO] [stderr]    Compiling multer v2.1.0
[INFO] [stderr]    Compiling regex-syntax v0.8.5
[INFO] [stderr]    Compiling sha1 v0.10.6
[INFO] [stderr]    Compiling serde_json v1.0.142
[INFO] [stderr]    Compiling memchr v2.7.5
[INFO] [stderr]    Compiling mime_guess v2.0.5
[INFO] [stderr]    Compiling socket2 v0.5.10
[INFO] [stderr]    Compiling encoding_rs v0.8.35
[INFO] [stderr]    Compiling spin v0.9.8
[INFO] [stderr]    Compiling indexmap v2.10.0
[INFO] [stderr]    Compiling http v0.2.12
[INFO] [stderr]    Compiling http v1.3.1
[INFO] [stderr]    Compiling parking_lot v0.12.4
[INFO] [stderr]    Compiling tracing-log v0.2.0
[INFO] [stderr]    Compiling thread_local v1.1.9
[INFO] [stderr]    Compiling iana-time-zone v0.1.63
[INFO] [stderr]    Compiling headers-core v0.2.0
[INFO] [stderr]    Compiling http-body v0.4.6
[INFO] [stderr]    Compiling headers v0.3.9
[INFO] [stderr]    Compiling regex-automata v0.4.9
[INFO] [stderr]    Compiling regex v1.11.1
[INFO] [stderr]    Compiling synstructure v0.13.2
[INFO] [stderr]    Compiling zerofrom-derive v0.1.6
[INFO] [stderr]    Compiling yoke-derive v0.8.0
[INFO] [stderr]    Compiling zerovec-derive v0.11.1
[INFO] [stderr]    Compiling displaydoc v0.2.5
[INFO] [stderr]    Compiling futures-macro v0.3.31
[INFO] [stderr]    Compiling tokio-macros v2.5.0
[INFO] [stderr]    Compiling thiserror-impl v1.0.69
[INFO] [stderr]    Compiling serde_derive v1.0.219
[INFO] [stderr]    Compiling tracing-attributes v0.1.30
[INFO] [stderr]    Compiling pin-project-internal v1.1.10
[INFO] [stderr]    Compiling tokio v1.47.1
[INFO] [stderr]    Compiling futures-util v0.3.31
[INFO] [stderr]    Compiling thiserror v1.0.69
[INFO] [stderr]    Compiling pin-project v1.1.10
[INFO] [stderr]    Compiling zerofrom v0.1.6
[INFO] [stderr]    Compiling yoke v0.8.0
[INFO] [stderr]    Compiling zerovec v0.11.3
[INFO] [stderr]    Compiling zerotrie v0.2.2
[INFO] [stderr]    Compiling tracing v0.1.41
[INFO] [stderr]    Compiling tracing-subscriber v0.3.19
[INFO] [stderr]    Compiling tinystr v0.8.1
[INFO] [stderr]    Compiling potential_utf v0.1.2
[INFO] [stderr]    Compiling icu_collections v2.0.0
[INFO] [stderr]    Compiling icu_locale_core v2.0.0
[INFO] [stderr]    Compiling icu_provider v2.0.0
[INFO] [stderr]    Compiling serde v1.0.219
[INFO] [stderr]    Compiling icu_normalizer v2.0.0
[INFO] [stderr]    Compiling icu_properties v2.0.1
[INFO] [stderr]    Compiling idna_adapter v1.2.1
[INFO] [stderr]    Compiling idna v1.0.3
[INFO] [stderr]    Compiling url v2.5.4
[INFO] [stderr]    Compiling tungstenite v0.21.0
[INFO] [stderr]    Compiling tungstenite v0.20.1
[INFO] [stderr]    Compiling tokio-util v0.7.16
[INFO] [stderr]    Compiling tokio-tungstenite v0.20.1
[INFO] [stderr]    Compiling tokio-tungstenite v0.21.0
[INFO] [stderr]    Compiling serde_urlencoded v0.7.1
[INFO] [stderr]    Compiling chrono v0.4.41
[INFO] [stderr]    Compiling h2 v0.3.27
[INFO] [stderr]    Compiling hyper v0.14.32
[INFO] [stderr]    Compiling warp v0.3.7
[INFO] [stderr]    Compiling raft-poc v0.1.0 (/opt/rustwide/workdir)
[INFO] [stdout] warning: field `last_applied` is never read
[INFO] [stdout]   --> src/raft/core.rs:81:9
[INFO] [stdout]    |
[INFO] [stdout] 77 | pub struct VolatileState {
[INFO] [stdout]    |            ------------- field in this struct
[INFO] [stdout] ...
[INFO] [stdout] 81 |     pub last_applied: u64,
[INFO] [stdout]    |         ^^^^^^^^^^^^
[INFO] [stdout]    |
[INFO] [stdout]    = note: `VolatileState` has derived impls for the traits `Clone` and `Debug`, but these are intentionally ignored during dead code analysis
[INFO] [stdout]    = note: `#[warn(dead_code)]` (part of `#[warn(unused)]`) on by default
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: fields `proposed_index` and `created_at` are never read
[INFO] [stdout]    --> src/raft/core.rs:104:9
[INFO] [stdout]     |
[INFO] [stdout] 102 | pub struct PendingProposal {
[INFO] [stdout]     |            --------------- fields in this struct
[INFO] [stdout] 103 |     /// The log index where this proposal would be placed if committed
[INFO] [stdout] 104 |     pub proposed_index: u64,
[INFO] [stdout]     |         ^^^^^^^^^^^^^^
[INFO] [stdout] ...
[INFO] [stdout] 112 |     pub created_at: Instant,
[INFO] [stdout]     |         ^^^^^^^^^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `PendingProposal` has derived impls for the traits `Clone` and `Debug`, but these are intentionally ignored during dead code analysis
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: method `set_election_timeout` is never used
[INFO] [stdout]    --> src/raft/core.rs:231:12
[INFO] [stdout]     |
[INFO] [stdout] 195 | impl Node {
[INFO] [stdout]     | --------- method in this implementation
[INFO] [stdout] ...
[INFO] [stdout] 231 |     pub fn set_election_timeout(&mut self, timeout_ms: u64) {
[INFO] [stdout]     |            ^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: method `get_pending_proposals` is never used
[INFO] [stdout]    --> src/raft/algorithm.rs:348:12
[INFO] [stdout]     |
[INFO] [stdout]  18 | impl Node {
[INFO] [stdout]     | --------- method in this implementation
[INFO] [stdout] ...
[INFO] [stdout] 348 |     pub fn get_pending_proposals(&self) -> Vec<(u64, &crate::raft::core::PendingProposal)> {
[INFO] [stdout]     |            ^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: field `to` is never read
[INFO] [stdout]    --> src/raft/rpc.rs:134:9
[INFO] [stdout]     |
[INFO] [stdout] 130 |     AppendEntriesResponse {
[INFO] [stdout]     |     --------------------- field in this variant
[INFO] [stdout] ...
[INFO] [stdout] 134 |         to: NodeId,
[INFO] [stdout]     |         ^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `RpcMessage` has derived impls for the traits `Clone` and `Debug`, but these are intentionally ignored during dead code analysis
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: field `to` is never read
[INFO] [stdout]    --> src/raft/rpc.rs:152:9
[INFO] [stdout]     |
[INFO] [stdout] 148 |     RequestVoteResponse {
[INFO] [stdout]     |     ------------------- field in this variant
[INFO] [stdout] ...
[INFO] [stdout] 152 |         to: NodeId,
[INFO] [stdout]     |         ^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `RpcMessage` has derived impls for the traits `Clone` and `Debug`, but these are intentionally ignored during dead code analysis
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: field `from` is never read
[INFO] [stdout]    --> src/raft/rpc.rs:159:9
[INFO] [stdout]     |
[INFO] [stdout] 157 |     ClientCommand {
[INFO] [stdout]     |     ------------- field in this variant
[INFO] [stdout] 158 |         /// ID of the client (or simulation controller)
[INFO] [stdout] 159 |         from: NodeId,
[INFO] [stdout]     |         ^^^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `RpcMessage` has derived impls for the traits `Clone` and `Debug`, but these are intentionally ignored during dead code analysis
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: methods `from`, `to`, and `message_type` are never used
[INFO] [stdout]    --> src/raft/rpc.rs:198:12
[INFO] [stdout]     |
[INFO] [stdout] 167 | impl RpcMessage {
[INFO] [stdout]     | --------------- methods in this implementation
[INFO] [stdout] ...
[INFO] [stdout] 198 |     pub fn from(&self) -> NodeId {
[INFO] [stdout]     |            ^^^^
[INFO] [stdout] ...
[INFO] [stdout] 209 |     pub fn to(&self) -> NodeId {
[INFO] [stdout]     |            ^^
[INFO] [stdout] ...
[INFO] [stdout] 220 |     pub fn message_type(&self) -> &'static str {
[INFO] [stdout]     |            ^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: struct `NodeHandle` is never constructed
[INFO] [stdout]   --> src/raft/simulation.rs:14:12
[INFO] [stdout]    |
[INFO] [stdout] 14 | pub struct NodeHandle {
[INFO] [stdout]    |            ^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: associated items `new`, `send`, and `create_pair` are never used
[INFO] [stdout]   --> src/raft/simulation.rs:25:12
[INFO] [stdout]    |
[INFO] [stdout] 23 | impl NodeHandle {
[INFO] [stdout]    | --------------- associated items in this implementation
[INFO] [stdout] 24 |     /// Creates a new NodeHandle with unbounded channels
[INFO] [stdout] 25 |     pub fn new(node_id: NodeId) -> Self {
[INFO] [stdout]    |            ^^^
[INFO] [stdout] ...
[INFO] [stdout] 35 |     pub fn send(&self, message: RpcMessage) -> Result<(), mpsc::error::SendError<RpcMessage>> {
[INFO] [stdout]    |            ^^^^
[INFO] [stdout] ...
[INFO] [stdout] 40 |     pub fn create_pair(node_id1: NodeId, node_id2: NodeId) -> (Self, Self) {
[INFO] [stdout]    |            ^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: method `all_node_ids` is never used
[INFO] [stdout]    --> src/raft/simulation.rs:116:12
[INFO] [stdout]     |
[INFO] [stdout]  56 | impl ClusterChannels {
[INFO] [stdout]     | -------------------- method in this implementation
[INFO] [stdout] ...
[INFO] [stdout] 116 |     pub fn all_node_ids(&self) -> Vec<NodeId> {
[INFO] [stdout]     |            ^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: methods `receiver_count` and `get_stats` are never used
[INFO] [stdout]    --> src/raft/events.rs:619:12
[INFO] [stdout]     |
[INFO] [stdout] 502 | impl EventBroadcaster {
[INFO] [stdout]     | --------------------- methods in this implementation
[INFO] [stdout] ...
[INFO] [stdout] 619 |     pub fn receiver_count(&self) -> usize {
[INFO] [stdout]     |            ^^^^^^^^^^^^^^
[INFO] [stdout] ...
[INFO] [stdout] 624 |     pub fn get_stats(&self) -> EventBroadcasterStats {
[INFO] [stdout]     |            ^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: struct `EventBroadcasterStats` is never constructed
[INFO] [stdout]    --> src/raft/events.rs:641:12
[INFO] [stdout]     |
[INFO] [stdout] 641 | pub struct EventBroadcasterStats {
[INFO] [stdout]     |            ^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: function `spawn_websocket_server` is never used
[INFO] [stdout]    --> src/raft/websocket.rs:558:14
[INFO] [stdout]     |
[INFO] [stdout] 558 | pub async fn spawn_websocket_server(
[INFO] [stdout]     |              ^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 1m 06s
[INFO] running `Command { std: "docker" "inspect" "0d73b6eee13ed19d64d8cba380a1620e9e046b6b1b83ecd0cebc7db0ebd617e5", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "0d73b6eee13ed19d64d8cba380a1620e9e046b6b1b83ecd0cebc7db0ebd617e5", kill_on_drop: false }`
[INFO] [stdout] 0d73b6eee13ed19d64d8cba380a1620e9e046b6b1b83ecd0cebc7db0ebd617e5
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:7ad1b28ee6f5f7f699f6cf7015098d6ccdd96d6f2d78dd06228f5b4c9faf309c" "/opt/rustwide/cargo-home/bin/cargo" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] d40dd812cc5563915011b80baff744812694cbafb2f71efd3c17900126bb6805
[INFO] running `Command { std: "docker" "start" "-a" "d40dd812cc5563915011b80baff744812694cbafb2f71efd3c17900126bb6805", kill_on_drop: false }`
[INFO] [stderr]    Compiling raft-poc v0.1.0 (/opt/rustwide/workdir)
[INFO] [stdout] warning: unused imports: `EventBroadcaster` and `RaftEventType`
[INFO] [stdout]    --> src/raft/websocket.rs:603:31
[INFO] [stdout]     |
[INFO] [stdout] 603 |     use crate::raft::events::{EventBroadcaster, RaftEventType};
[INFO] [stdout]     |                               ^^^^^^^^^^^^^^^^  ^^^^^^^^^^^^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `#[warn(unused_imports)]` (part of `#[warn(unused)]`) on by default
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: unused imports: `LogEntry` and `NodeId`
[INFO] [stdout]    --> src/raft/tests.rs:214:30
[INFO] [stdout]     |
[INFO] [stdout] 214 |     use super::super::core::{LogEntry, NodeId};
[INFO] [stdout]     |                              ^^^^^^^^  ^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: unused import: `super::super::rpc::*`
[INFO] [stdout]    --> src/raft/tests.rs:376:9
[INFO] [stdout]     |
[INFO] [stdout] 376 |     use super::super::rpc::*;
[INFO] [stdout]     |         ^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: unused import: `tokio::time::Duration`
[INFO] [stdout]    --> src/raft/tests.rs:378:9
[INFO] [stdout]     |
[INFO] [stdout] 378 |     use tokio::time::Duration;
[INFO] [stdout]     |         ^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: unused import: `super::super::events::EventBroadcaster`
[INFO] [stdout]  --> src/raft/integration_tests.rs:4:9
[INFO] [stdout]   |
[INFO] [stdout] 4 |     use super::super::events::EventBroadcaster;
[INFO] [stdout]   |         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: unused import: `std::collections::HashMap`
[INFO] [stdout]  --> src/raft/integration_tests.rs:7:9
[INFO] [stdout]   |
[INFO] [stdout] 7 |     use std::collections::HashMap;
[INFO] [stdout]   |         ^^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: unused import: `timeout`
[INFO] [stdout]  --> src/raft/integration_tests.rs:8:40
[INFO] [stdout]   |
[INFO] [stdout] 8 |     use tokio::time::{Duration, sleep, timeout};
[INFO] [stdout]   |                                        ^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: unused variable: `cluster_channels`
[INFO] [stdout]    --> src/raft/integration_tests.rs:324:14
[INFO] [stdout]     |
[INFO] [stdout] 324 |         let (cluster_channels, _event_broadcaster, join_handles) =
[INFO] [stdout]     |              ^^^^^^^^^^^^^^^^ help: if this is intentional, prefix it with an underscore: `_cluster_channels`
[INFO] [stdout]     |
[INFO] [stdout]     = note: `#[warn(unused_variables)]` (part of `#[warn(unused)]`) on by default
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: unused variable: `cluster_channels`
[INFO] [stdout]    --> src/raft/integration_tests.rs:353:14
[INFO] [stdout]     |
[INFO] [stdout] 353 |         let (cluster_channels, _event_broadcaster, join_handles) =
[INFO] [stdout]     |              ^^^^^^^^^^^^^^^^ help: if this is intentional, prefix it with an underscore: `_cluster_channels`
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: unused variable: `cluster_channels`
[INFO] [stdout]    --> src/raft/integration_tests.rs:574:14
[INFO] [stdout]     |
[INFO] [stdout] 574 |         let (cluster_channels, _event_broadcaster, join_handles) =
[INFO] [stdout]     |              ^^^^^^^^^^^^^^^^ help: if this is intentional, prefix it with an underscore: `_cluster_channels`
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: field `created_at` is never read
[INFO] [stdout]    --> src/raft/core.rs:112:9
[INFO] [stdout]     |
[INFO] [stdout] 102 | pub struct PendingProposal {
[INFO] [stdout]     |            --------------- field in this struct
[INFO] [stdout] ...
[INFO] [stdout] 112 |     pub created_at: Instant,
[INFO] [stdout]     |         ^^^^^^^^^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `PendingProposal` has derived impls for the traits `Clone` and `Debug`, but these are intentionally ignored during dead code analysis
[INFO] [stdout]     = note: `#[warn(dead_code)]` (part of `#[warn(unused)]`) on by default
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: method `set_election_timeout` is never used
[INFO] [stdout]    --> src/raft/core.rs:231:12
[INFO] [stdout]     |
[INFO] [stdout] 195 | impl Node {
[INFO] [stdout]     | --------- method in this implementation
[INFO] [stdout] ...
[INFO] [stdout] 231 |     pub fn set_election_timeout(&mut self, timeout_ms: u64) {
[INFO] [stdout]     |            ^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: method `get_pending_proposals` is never used
[INFO] [stdout]    --> src/raft/algorithm.rs:348:12
[INFO] [stdout]     |
[INFO] [stdout]  18 | impl Node {
[INFO] [stdout]     | --------- method in this implementation
[INFO] [stdout] ...
[INFO] [stdout] 348 |     pub fn get_pending_proposals(&self) -> Vec<(u64, &crate::raft::core::PendingProposal)> {
[INFO] [stdout]     |            ^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: struct `NodeHandle` is never constructed
[INFO] [stdout]   --> src/raft/simulation.rs:14:12
[INFO] [stdout]    |
[INFO] [stdout] 14 | pub struct NodeHandle {
[INFO] [stdout]    |            ^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: associated items `new`, `send`, and `create_pair` are never used
[INFO] [stdout]   --> src/raft/simulation.rs:25:12
[INFO] [stdout]    |
[INFO] [stdout] 23 | impl NodeHandle {
[INFO] [stdout]    | --------------- associated items in this implementation
[INFO] [stdout] 24 |     /// Creates a new NodeHandle with unbounded channels
[INFO] [stdout] 25 |     pub fn new(node_id: NodeId) -> Self {
[INFO] [stdout]    |            ^^^
[INFO] [stdout] ...
[INFO] [stdout] 35 |     pub fn send(&self, message: RpcMessage) -> Result<(), mpsc::error::SendError<RpcMessage>> {
[INFO] [stdout]    |            ^^^^
[INFO] [stdout] ...
[INFO] [stdout] 40 |     pub fn create_pair(node_id1: NodeId, node_id2: NodeId) -> (Self, Self) {
[INFO] [stdout]    |            ^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: methods `receiver_count` and `get_stats` are never used
[INFO] [stdout]    --> src/raft/events.rs:619:12
[INFO] [stdout]     |
[INFO] [stdout] 502 | impl EventBroadcaster {
[INFO] [stdout]     | --------------------- methods in this implementation
[INFO] [stdout] ...
[INFO] [stdout] 619 |     pub fn receiver_count(&self) -> usize {
[INFO] [stdout]     |            ^^^^^^^^^^^^^^
[INFO] [stdout] ...
[INFO] [stdout] 624 |     pub fn get_stats(&self) -> EventBroadcasterStats {
[INFO] [stdout]     |            ^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: struct `EventBroadcasterStats` is never constructed
[INFO] [stdout]    --> src/raft/events.rs:641:12
[INFO] [stdout]     |
[INFO] [stdout] 641 | pub struct EventBroadcasterStats {
[INFO] [stdout]     |            ^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: function `spawn_websocket_server` is never used
[INFO] [stdout]    --> src/raft/websocket.rs:558:14
[INFO] [stdout]     |
[INFO] [stdout] 558 | pub async fn spawn_websocket_server(
[INFO] [stdout]     |              ^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: function `wait_for_leader_election` is never used
[INFO] [stdout]   --> src/raft/integration_tests.rs:12:14
[INFO] [stdout]    |
[INFO] [stdout] 12 |     async fn wait_for_leader_election(
[INFO] [stdout]    |              ^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 8.14s
[INFO] running `Command { std: "docker" "inspect" "d40dd812cc5563915011b80baff744812694cbafb2f71efd3c17900126bb6805", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "d40dd812cc5563915011b80baff744812694cbafb2f71efd3c17900126bb6805", kill_on_drop: false }`
[INFO] [stdout] d40dd812cc5563915011b80baff744812694cbafb2f71efd3c17900126bb6805
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:7ad1b28ee6f5f7f699f6cf7015098d6ccdd96d6f2d78dd06228f5b4c9faf309c" "/opt/rustwide/cargo-home/bin/cargo" "+cdb45c87e2cd43495379f7e867e3cc15dcee9f93" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] 610992f1b8064d3c7cf94e7fb339ab7a05d599c26b64b61d9a84b48dfefc2a7e
[INFO] running `Command { std: "docker" "start" "-a" "610992f1b8064d3c7cf94e7fb339ab7a05d599c26b64b61d9a84b48dfefc2a7e", kill_on_drop: false }`
[INFO] [stderr] warning: unused imports: `EventBroadcaster` and `RaftEventType`
[INFO] [stderr]    --> src/raft/websocket.rs:603:31
[INFO] [stderr]     |
[INFO] [stderr] 603 |     use crate::raft::events::{EventBroadcaster, RaftEventType};
[INFO] [stderr]     |                               ^^^^^^^^^^^^^^^^  ^^^^^^^^^^^^^
[INFO] [stderr]     |
[INFO] [stderr]     = note: `#[warn(unused_imports)]` (part of `#[warn(unused)]`) on by default
[INFO] [stderr] 
[INFO] [stderr] warning: unused imports: `LogEntry` and `NodeId`
[INFO] [stderr]    --> src/raft/tests.rs:214:30
[INFO] [stderr]     |
[INFO] [stderr] 214 |     use super::super::core::{LogEntry, NodeId};
[INFO] [stderr]     |                              ^^^^^^^^  ^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: unused import: `super::super::rpc::*`
[INFO] [stderr]    --> src/raft/tests.rs:376:9
[INFO] [stderr]     |
[INFO] [stderr] 376 |     use super::super::rpc::*;
[INFO] [stderr]     |         ^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: unused import: `tokio::time::Duration`
[INFO] [stderr]    --> src/raft/tests.rs:378:9
[INFO] [stderr]     |
[INFO] [stderr] 378 |     use tokio::time::Duration;
[INFO] [stderr]     |         ^^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: unused import: `super::super::events::EventBroadcaster`
[INFO] [stderr]  --> src/raft/integration_tests.rs:4:9
[INFO] [stderr]   |
[INFO] [stderr] 4 |     use super::super::events::EventBroadcaster;
[INFO] [stderr]   |         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: unused import: `std::collections::HashMap`
[INFO] [stderr]  --> src/raft/integration_tests.rs:7:9
[INFO] [stderr]   |
[INFO] [stderr] 7 |     use std::collections::HashMap;
[INFO] [stderr]   |         ^^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: unused import: `timeout`
[INFO] [stderr]  --> src/raft/integration_tests.rs:8:40
[INFO] [stderr]   |
[INFO] [stderr] 8 |     use tokio::time::{Duration, sleep, timeout};
[INFO] [stderr]   |                                        ^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: unused variable: `cluster_channels`
[INFO] [stderr]    --> src/raft/integration_tests.rs:324:14
[INFO] [stderr]     |
[INFO] [stderr] 324 |         let (cluster_channels, _event_broadcaster, join_handles) =
[INFO] [stderr]     |              ^^^^^^^^^^^^^^^^ help: if this is intentional, prefix it with an underscore: `_cluster_channels`
[INFO] [stderr]     |
[INFO] [stderr]     = note: `#[warn(unused_variables)]` (part of `#[warn(unused)]`) on by default
[INFO] [stderr] 
[INFO] [stderr] warning: unused variable: `cluster_channels`
[INFO] [stderr]    --> src/raft/integration_tests.rs:353:14
[INFO] [stderr]     |
[INFO] [stderr] 353 |         let (cluster_channels, _event_broadcaster, join_handles) =
[INFO] [stderr]     |              ^^^^^^^^^^^^^^^^ help: if this is intentional, prefix it with an underscore: `_cluster_channels`
[INFO] [stderr] 
[INFO] [stderr] warning: unused variable: `cluster_channels`
[INFO] [stderr]    --> src/raft/integration_tests.rs:574:14
[INFO] [stderr]     |
[INFO] [stderr] 574 |         let (cluster_channels, _event_broadcaster, join_handles) =
[INFO] [stderr]     |              ^^^^^^^^^^^^^^^^ help: if this is intentional, prefix it with an underscore: `_cluster_channels`
[INFO] [stderr] 
[INFO] [stderr] warning: field `created_at` is never read
[INFO] [stderr]    --> src/raft/core.rs:112:9
[INFO] [stderr]     |
[INFO] [stderr] 102 | pub struct PendingProposal {
[INFO] [stderr]     |            --------------- field in this struct
[INFO] [stderr] ...
[INFO] [stderr] 112 |     pub created_at: Instant,
[INFO] [stderr]     |         ^^^^^^^^^^
[INFO] [stderr]     |
[INFO] [stderr]     = note: `PendingProposal` has derived impls for the traits `Clone` and `Debug`, but these are intentionally ignored during dead code analysis
[INFO] [stderr]     = note: `#[warn(dead_code)]` (part of `#[warn(unused)]`) on by default
[INFO] [stderr] 
[INFO] [stderr] warning: method `set_election_timeout` is never used
[INFO] [stderr]    --> src/raft/core.rs:231:12
[INFO] [stderr]     |
[INFO] [stderr] 195 | impl Node {
[INFO] [stderr]     | --------- method in this implementation
[INFO] [stderr] ...
[INFO] [stderr] 231 |     pub fn set_election_timeout(&mut self, timeout_ms: u64) {
[INFO] [stderr]     |            ^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: method `get_pending_proposals` is never used
[INFO] [stderr]    --> src/raft/algorithm.rs:348:12
[INFO] [stderr]     |
[INFO] [stderr]  18 | impl Node {
[INFO] [stderr]     | --------- method in this implementation
[INFO] [stderr] ...
[INFO] [stderr] 348 |     pub fn get_pending_proposals(&self) -> Vec<(u64, &crate::raft::core::PendingProposal)> {
[INFO] [stderr]     |            ^^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: struct `NodeHandle` is never constructed
[INFO] [stderr]   --> src/raft/simulation.rs:14:12
[INFO] [stderr]    |
[INFO] [stderr] 14 | pub struct NodeHandle {
[INFO] [stderr]    |            ^^^^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: associated items `new`, `send`, and `create_pair` are never used
[INFO] [stderr]   --> src/raft/simulation.rs:25:12
[INFO] [stderr]    |
[INFO] [stderr] 23 | impl NodeHandle {
[INFO] [stderr]    | --------------- associated items in this implementation
[INFO] [stderr] 24 |     /// Creates a new NodeHandle with unbounded channels
[INFO] [stderr] 25 |     pub fn new(node_id: NodeId) -> Self {
[INFO] [stderr]    |            ^^^
[INFO] [stderr] ...
[INFO] [stderr] 35 |     pub fn send(&self, message: RpcMessage) -> Result<(), mpsc::error::SendError<RpcMessage>> {
[INFO] [stderr]    |            ^^^^
[INFO] [stderr] ...
[INFO] [stderr] 40 |     pub fn create_pair(node_id1: NodeId, node_id2: NodeId) -> (Self, Self) {
[INFO] [stderr]    |            ^^^^^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: methods `receiver_count` and `get_stats` are never used
[INFO] [stderr]    --> src/raft/events.rs:619:12
[INFO] [stderr]     |
[INFO] [stderr] 502 | impl EventBroadcaster {
[INFO] [stderr]     | --------------------- methods in this implementation
[INFO] [stderr] ...
[INFO] [stderr] 619 |     pub fn receiver_count(&self) -> usize {
[INFO] [stderr]     |            ^^^^^^^^^^^^^^
[INFO] [stderr] ...
[INFO] [stderr] 624 |     pub fn get_stats(&self) -> EventBroadcasterStats {
[INFO] [stderr]     |            ^^^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: struct `EventBroadcasterStats` is never constructed
[INFO] [stderr]    --> src/raft/events.rs:641:12
[INFO] [stderr]     |
[INFO] [stderr] 641 | pub struct EventBroadcasterStats {
[INFO] [stderr]     |            ^^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: function `spawn_websocket_server` is never used
[INFO] [stderr]    --> src/raft/websocket.rs:558:14
[INFO] [stderr]     |
[INFO] [stderr] 558 | pub async fn spawn_websocket_server(
[INFO] [stderr]     |              ^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: function `wait_for_leader_election` is never used
[INFO] [stderr]   --> src/raft/integration_tests.rs:12:14
[INFO] [stderr]    |
[INFO] [stderr] 12 |     async fn wait_for_leader_election(
[INFO] [stderr]    |              ^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: `raft-poc` (bin "raft-poc" test) generated 19 warnings (run `cargo fix --bin "raft-poc" --tests` to apply 7 suggestions)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.24s
[INFO] [stderr]      Running unittests src/main.rs (/opt/rustwide/target/debug/deps/raft_poc-a295aac823063056)
[INFO] [stdout] 
[INFO] [stdout] running 48 tests
[INFO] [stdout] 2025-09-01T06:30:10.962329Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting concurrent proposals test
[INFO] [stdout] 2025-09-01T06:30:10.962440Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 3 nodes
[INFO] [stdout] 2025-09-01T06:30:10.962541Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting commit index advancement test
[INFO] [stdout] 2025-09-01T06:30:10.962610Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 5 nodes
[INFO] [stdout] 2025-09-01T06:30:10.962681Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting detailed election process test for visualization
[INFO] [stdout] 2025-09-01T06:30:10.962763Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 3 nodes
[INFO] [stdout] 2025-09-01T06:30:10.964539Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting heartbeat failure detection test
[INFO] [stdout] 2025-09-01T06:30:10.964597Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 3 nodes
[INFO] [stdout] 2025-09-01T06:30:10.964787Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting leader forwarding test
[INFO] [stdout] 2025-09-01T06:30:10.964816Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 5 nodes
[INFO] [stdout] 2025-09-01T06:30:10.964925Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting heartbeat maintenance test
[INFO] [stdout] 2025-09-01T06:30:10.964940Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.964949Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 3 nodes
[INFO] [stdout] 2025-09-01T06:30:10.964997Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.965012Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:10.965026Z  INFO raft_poc::raft::simulation: ✅ All 3 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.965036Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Cluster spawned, waiting for stable leadership
[INFO] [stdout] 2025-09-01T06:30:10.965077Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:10.965131Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.965134Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.965156Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.965170Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.965184Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:10.965194Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 3
[INFO] [stdout] 2025-09-01T06:30:10.965205Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 4
[INFO] [stdout] 2025-09-01T06:30:10.965218Z  INFO raft_poc::raft::simulation: ✅ All 5 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.965232Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ 5-node cluster spawned, waiting for leader election
[INFO] [stdout] 2025-09-01T06:30:10.965240Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.965268Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:10.965271Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.965286Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:10.965361Z  INFO raft_poc::raft::simulation: ✅ All 3 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.965304Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.965507Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.965563Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Cluster spawned, waiting for leader election and heartbeat establishment
[INFO] [stdout] 2025-09-01T06:30:10.965632Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:10.965915Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.966028Z  INFO raft_poc::raft::simulation: 🟢 Node 3 started as Follower node_id=3
[INFO] [stdout] 2025-09-01T06:30:10.966067Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.966142Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.966203Z  INFO raft_poc::raft::simulation: 🟢 Node 4 started as Follower node_id=4
[INFO] [stdout] test raft::events::tests::test_event_creation ... ok
[INFO] [stdout] 2025-09-01T06:30:10.966794Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.967140Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:10.966907Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting log replication test
[INFO] [stdout] 2025-09-01T06:30:10.967250Z  INFO raft_poc::raft::simulation: ✅ All 3 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.967350Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Cluster spawned, waiting for leader election
[INFO] [stdout] test raft::events::tests::test_event_broadcaster ... ok
[INFO] [stdout] test raft::events::tests::test_event_deduplication_time_window ... ok
[INFO] [stdout] 2025-09-01T06:30:10.967291Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 3 nodes
[INFO] [stdout] 2025-09-01T06:30:10.967468Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting normal cluster operation test
[INFO] [stdout] 2025-09-01T06:30:10.966844Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting election timeout ranges test
[INFO] [stdout] 2025-09-01T06:30:10.966635Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.967855Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 3 nodes
[INFO] [stdout] 2025-09-01T06:30:10.967892Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.967911Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] test raft::events::tests::test_event_deduplication ... 2025-09-01T06:30:10.967922Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 3
[INFO] [stdout] ok
[INFO] [stdout] 2025-09-01T06:30:10.967934Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 4
[INFO] [stdout] 2025-09-01T06:30:10.967948Z  INFO raft_poc::raft::simulation: ✅ All 5 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.967994Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] test raft::events::tests::test_event_serialization ... ok
[INFO] [stdout] 2025-09-01T06:30:10.968030Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.968054Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.968074Z  INFO raft_poc::raft::simulation: 🟢 Node 3 started as Follower node_id=3
[INFO] [stdout] 2025-09-01T06:30:10.968080Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:10.968096Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.968097Z  INFO raft_poc::raft::simulation: 🟢 Node 4 started as Follower node_id=4
[INFO] [stdout] 2025-09-01T06:30:10.968119Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.968122Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.968130Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:10.968141Z  INFO raft_poc::raft::simulation: ✅ All 3 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.968148Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.968152Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Cluster spawned for timeout testing
[INFO] [stdout] 2025-09-01T06:30:10.968182Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:10.968218Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.968237Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.968276Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 3 nodes
[INFO] [stdout] 2025-09-01T06:30:10.968436Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting split vote resolution test
[INFO] [stdout] 2025-09-01T06:30:10.968455Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 4 nodes
[INFO] [stdout] 2025-09-01T06:30:10.968473Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.968492Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.968502Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:10.968510Z  INFO raft_poc::raft::simulation: ✅ All 3 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.968527Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:10.968560Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.968579Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.968711Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.968748Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.968761Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:10.966769Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.968790Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 3
[INFO] [stdout] 2025-09-01T06:30:10.968807Z  INFO raft_poc::raft::simulation: ✅ All 4 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.968829Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ 4-node cluster spawned
[INFO] [stdout] 2025-09-01T06:30:10.968833Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.968847Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:10.968877Z  INFO raft_poc::raft::simulation: ✅ All 3 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.969015Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Cluster spawned, waiting for natural election
[INFO] [stdout] 2025-09-01T06:30:10.969084Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:10.970657Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting proposal consensus flow test for visualization
[INFO] [stdout] 2025-09-01T06:30:10.970699Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 3 nodes
[INFO] [stdout] 2025-09-01T06:30:10.970849Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.970988Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.971006Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.971031Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.971043Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:10.971032Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.971091Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:10.971104Z  INFO raft_poc::raft::simulation: ✅ All 3 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.971158Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:10.971192Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.971217Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.971407Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting split vote test with 4 nodes
[INFO] [stdout] 2025-09-01T06:30:10.971425Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 4 nodes
[INFO] [stdout] 2025-09-01T06:30:10.971657Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.971678Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.971687Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:10.971695Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 3
[INFO] [stdout] 2025-09-01T06:30:10.971704Z  INFO raft_poc::raft::simulation: ✅ All 4 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.971723Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:10.971748Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.971765Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.971781Z  INFO raft_poc::raft::simulation: 🟢 Node 3 started as Follower node_id=3
[INFO] [stdout] 2025-09-01T06:30:10.970989Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.972056Z  INFO raft_poc::raft::simulation: ✅ All 3 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.972079Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Cluster spawned, waiting for leader election
[INFO] [stdout] 2025-09-01T06:30:10.972099Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:10.972126Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.972146Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.980702Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting leader election test with 3 nodes
[INFO] [stdout] 2025-09-01T06:30:10.980761Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 3 nodes
[INFO] [stdout] 2025-09-01T06:30:10.981067Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:10.981114Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:10.981127Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:10.981140Z  INFO raft_poc::raft::simulation: ✅ All 3 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:10.981193Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:10.981253Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.981289Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.968853Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:10.985172Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:10.985261Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:10.985311Z  INFO raft_poc::raft::simulation: 🟢 Node 3 started as Follower node_id=3
[INFO] [stdout] 2025-09-01T06:30:11.014456Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting proposal rejection cases test
[INFO] [stdout] 2025-09-01T06:30:11.014503Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 3 nodes
[INFO] [stdout] 2025-09-01T06:30:11.014753Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:11.014781Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:11.014791Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:11.014801Z  INFO raft_poc::raft::simulation: ✅ All 3 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:11.014811Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Cluster spawned, waiting for leader election
[INFO] [stdout] 2025-09-01T06:30:11.014856Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:11.014893Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:11.014913Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:11.028402Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting network partition recovery test
[INFO] [stdout] 2025-09-01T06:30:11.028453Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 5 nodes
[INFO] [stdout] 2025-09-01T06:30:11.028729Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:11.029055Z  INFO raft_poc::raft::integration_tests::integration_tests: 🧪 Starting leader election test with 5 nodes
[INFO] [stdout] 2025-09-01T06:30:11.029093Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 5 nodes
[INFO] [stdout] 2025-09-01T06:30:11.029317Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:11.029349Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:11.029360Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:11.029369Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 3
[INFO] [stdout] 2025-09-01T06:30:11.029379Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 4
[INFO] [stdout] 2025-09-01T06:30:11.029391Z  INFO raft_poc::raft::simulation: ✅ All 5 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:11.029430Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:11.029473Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:11.029499Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:11.029522Z  INFO raft_poc::raft::simulation: 🟢 Node 3 started as Follower node_id=3
[INFO] [stdout] 2025-09-01T06:30:11.029547Z  INFO raft_poc::raft::simulation: 🟢 Node 4 started as Follower node_id=4
[INFO] [stdout] 2025-09-01T06:30:11.029624Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:11.029640Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:11.029650Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 3
[INFO] [stdout] 2025-09-01T06:30:11.029659Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 4
[INFO] [stdout] 2025-09-01T06:30:11.029669Z  INFO raft_poc::raft::simulation: ✅ All 5 nodes spawned successfully
[INFO] [stdout] 2025-09-01T06:30:11.029681Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ 5-node cluster spawned, establishing stable leadership
[INFO] [stdout] 2025-09-01T06:30:11.029701Z  INFO raft_poc::raft::simulation: 🟢 Node 0 started as Follower node_id=0
[INFO] [stdout] 2025-09-01T06:30:11.029728Z  INFO raft_poc::raft::simulation: 🟢 Node 1 started as Follower node_id=1
[INFO] [stdout] 2025-09-01T06:30:11.029747Z  INFO raft_poc::raft::simulation: 🟢 Node 2 started as Follower node_id=2
[INFO] [stdout] 2025-09-01T06:30:11.029767Z  INFO raft_poc::raft::simulation: 🟢 Node 3 started as Follower node_id=3
[INFO] [stdout] 2025-09-01T06:30:11.029792Z  INFO raft_poc::raft::simulation: 🟢 Node 4 started as Follower node_id=4
[INFO] [stdout] 2025-09-01T06:30:12.968317Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'test_commit_0' by Follower 0 (WILL REJECT) node_id=0
[INFO] [stdout] 2025-09-01T06:30:12.972364Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'command1' by Follower 0 (WILL REJECT) node_id=0
[INFO] [stdout] 2025-09-01T06:30:12.972456Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'command2' by Follower 1 (WILL REJECT) node_id=1
[INFO] [stdout] 2025-09-01T06:30:12.972502Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'command3' by Follower 2 (WILL REJECT) node_id=2
[INFO] [stdout] 2025-09-01T06:30:12.982248Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Election period completed, checking for leader
[INFO] [stdout] 2025-09-01T06:30:12.982305Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Leader election test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_leader_election_3_nodes ... ok
[INFO] [stdout] 2025-09-01T06:30:12.983368Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:12.983542Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/2 votes) node_id=1
[INFO] [stdout] test raft::tests::algorithm_tests::test_become_candidate ... ok
[INFO] [stdout] 2025-09-01T06:30:12.984225Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 0 with majority votes! node_id=1
[INFO] [stdout] 2025-09-01T06:30:12.984299Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 2 followers node_id=1
[INFO] [stdout] test raft::tests::algorithm_tests::test_become_leader ... ok
[INFO] [stdout] 2025-09-01T06:30:12.985947Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 0 with majority votes! node_id=1
[INFO] [stdout] 2025-09-01T06:30:12.986103Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 2 followers node_id=1
[INFO] [stdout] 2025-09-01T06:30:12.986166Z  INFO raft_poc::raft::algorithm: 📋 STEP 1/4 - PROPOSAL CREATED: Command 'cmd1' → pending proposal at index 1 (term 0) | Need 2/3 acks for consensus node_id=1
[INFO] [stdout] 2025-09-01T06:30:12.986220Z  INFO raft_poc::raft::algorithm: 🎯 STEP 4/4 - COMMITTING: Proposal 1 achieved consensus → moving to committed log node_id=1
[INFO] [stdout] 2025-09-01T06:30:12.986253Z  INFO raft_poc::raft::algorithm: ✅ CONSENSUS FLOW COMPLETE: Command 'cmd1' committed to log at index 1 (term 0) | Acknowledged by: [1] node_id=1
[INFO] [stdout] test raft::tests::algorithm_tests::test_client_submit ... ok
[INFO] [stdout] 2025-09-01T06:30:12.987307Z  INFO raft_poc::raft::algorithm: Updating term from 0 to 1 due to AppendEntries from leader 0 node_id=1
[INFO] [stdout] test raft::tests::algorithm_tests::test_handle_append_entries_basic ... ok
[INFO] [stdout] test raft::tests::algorithm_tests::test_handle_request_vote_basic ... ok
[INFO] [stdout] test raft::tests::core_tests::test_client_submit_as_follower ... ok
[INFO] [stdout] 2025-09-01T06:30:12.988192Z  INFO raft_poc::raft::algorithm: 📋 STEP 1/4 - PROPOSAL CREATED: Command 'test command' → pending proposal at index 1 (term 0) | Need 2/3 acks for consensus node_id=0
[INFO] [stdout] test raft::tests::core_tests::test_client_submit_as_leader ... ok
[INFO] [stdout] 2025-09-01T06:30:12.988508Z  INFO raft_poc::raft::algorithm: 📋 STEP 1/4 - PROPOSAL CREATED: Command 'test command' → pending proposal at index 1 (term 1) | Need 2/3 acks for consensus node_id=0
[INFO] [stdout] 2025-09-01T06:30:12.988612Z  INFO raft_poc::raft::algorithm: 🎯 STEP 4/4 - COMMITTING: Proposal 1 achieved consensus → moving to committed log node_id=0
[INFO] [stdout] 2025-09-01T06:30:12.988654Z  INFO raft_poc::raft::algorithm: ✅ CONSENSUS FLOW COMPLETE: Command 'test command' committed to log at index 1 (term 1) | Acknowledged by: [0] node_id=0
[INFO] [stdout] test raft::tests::core_tests::test_commit_proposal ... ok
[INFO] [stdout] test raft::tests::core_tests::test_election_timeout ... ok
[INFO] [stdout] 2025-09-01T06:30:12.994583Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 0 with majority votes! node_id=0
[INFO] [stdout] 2025-09-01T06:30:12.994700Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 2 followers node_id=0
[INFO] [stdout] test raft::tests::core_tests::test_heartbeat_timing ... ok
[INFO] [stdout] test raft::tests::core_tests::test_last_log_index_and_term ... ok
[INFO] [stdout] test raft::tests::core_tests::test_leader_volatile_state_initialization ... ok
[INFO] [stdout] test raft::tests::core_tests::test_log_entry_creation ... ok
[INFO] [stdout] test raft::tests::core_tests::test_log_term_retrieval ... ok
[INFO] [stdout] test raft::tests::core_tests::test_node_creation ... ok
[INFO] [stdout] test raft::tests::core_tests::test_pending_proposal_acknowledgments ... ok
[INFO] [stdout] test raft::tests::core_tests::test_pending_proposal_creation ... ok
[INFO] [stdout] test raft::tests::core_tests::test_persistent_state_default ... ok
[INFO] [stdout] test raft::tests::core_tests::test_volatile_state_default ... ok
[INFO] [stdout] test raft::tests::rpc_tests::test_append_entries_request_creation ... ok
[INFO] [stdout] test raft::tests::rpc_tests::test_request_vote_request_creation ... ok
[INFO] [stdout] test raft::tests::rpc_tests::test_rpc_message_append_entries_request ... ok
[INFO] [stdout] test raft::tests::rpc_tests::test_rpc_message_client_command ... ok
[INFO] [stdout] test raft::tests::simulation_tests::test_cluster_channels_creation ... ok
[INFO] [stdout] 2025-09-01T06:30:13.013435Z  INFO raft_poc::raft::simulation: 🎆 Creating cluster with 3 nodes
[INFO] [stdout] 2025-09-01T06:30:13.013847Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 0
[INFO] [stdout] 2025-09-01T06:30:13.013896Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 1
[INFO] [stdout] 2025-09-01T06:30:13.013918Z  INFO raft_poc::raft::simulation: 🚀 Spawning node 2
[INFO] [stdout] 2025-09-01T06:30:13.013936Z  INFO raft_poc::raft::simulation: ✅ All 3 nodes spawned successfully
[INFO] [stdout] test raft::tests::simulation_tests::test_spawn_cluster ... ok
[INFO] [stdout] test raft::websocket::tests::test_event_serialization ... ok
[INFO] [stdout] test raft::websocket::tests::test_websocket_config ... ok
[INFO] [stdout] 2025-09-01T06:30:13.069907Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'test_commit_1' by Follower 0 (WILL REJECT) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.170520Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'test_commit_2' by Follower 0 (WILL REJECT) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.272793Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'test_commit_3' by Follower 0 (WILL REJECT) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.374330Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'test_commit_4' by Follower 0 (WILL REJECT) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.481263Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.481352Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.481378Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/2 votes) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.481415Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 0 requesting votes from 2 nodes for term 1 (need 2/3 votes) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.481466Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 2 nodes for election term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.501270Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=3
[INFO] [stdout] 2025-09-01T06:30:13.501357Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=3
[INFO] [stdout] 2025-09-01T06:30:13.501381Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/3 votes) node_id=3
[INFO] [stdout] 2025-09-01T06:30:13.501404Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 3 requesting votes from 4 nodes for term 1 (need 3/5 votes) node_id=3
[INFO] [stdout] 2025-09-01T06:30:13.501447Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 4 nodes for election term 1 node_id=3
[INFO] [stdout] 2025-09-01T06:30:13.539238Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.539321Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.539347Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/3 votes) node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.539619Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 1 requesting votes from 4 nodes for term 1 (need 3/5 votes) node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.539696Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 4 nodes for election term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.546218Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.546307Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.546330Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/2 votes) node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.546352Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 2 requesting votes from 2 nodes for term 1 (need 2/3 votes) node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.546393Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 2 nodes for election term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.553937Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.554040Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.554065Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/2 votes) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.554090Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 0 requesting votes from 2 nodes for term 1 (need 2/3 votes) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.554139Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 2 nodes for election term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.556229Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=3
[INFO] [stdout] 2025-09-01T06:30:13.556316Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=3
[INFO] [stdout] 2025-09-01T06:30:13.556344Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/3 votes) node_id=3
[INFO] [stdout] 2025-09-01T06:30:13.556388Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 3 requesting votes from 3 nodes for term 1 (need 3/4 votes) node_id=3
[INFO] [stdout] 2025-09-01T06:30:13.556434Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 3 nodes for election term 1 node_id=3
[INFO] [stdout] 2025-09-01T06:30:13.584340Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.584527Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.584652Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/2 votes) node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.584731Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 2 requesting votes from 2 nodes for term 1 (need 2/3 votes) node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.584830Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 2 nodes for election term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.633230Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.633308Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.633332Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/3 votes) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.633359Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 0 requesting votes from 4 nodes for term 1 (need 3/5 votes) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.633394Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 4 nodes for election term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.786212Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.786302Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.786328Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/3 votes) node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.786355Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 2 requesting votes from 4 nodes for term 1 (need 3/5 votes) node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.786398Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 4 nodes for election term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.803102Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.803200Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.803227Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/2 votes) node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.803252Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 1 requesting votes from 2 nodes for term 1 (need 2/3 votes) node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.803293Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 2 nodes for election term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.857611Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.857922Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.858045Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/2 votes) node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.858157Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 1 requesting votes from 2 nodes for term 1 (need 2/3 votes) node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.858284Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 2 nodes for election term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.902207Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.902290Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.902317Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/2 votes) node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.902342Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 2 requesting votes from 2 nodes for term 1 (need 2/3 votes) node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.902380Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 2 nodes for election term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:13.965798Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Simulating leader failure to test heartbeat failure detection
[INFO] [stdout] 2025-09-01T06:30:13.965978Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'SIMULATE_LEADER_FAILURE' by Candidate 1 (WILL REJECT) node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.966009Z  INFO raft_poc::raft::simulation: 👑 Received leader failure simulation command, state: Candidate node_id=1
[INFO] [stdout] 2025-09-01T06:30:13.966227Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Observing heartbeat patterns
[INFO] [stdout] 2025-09-01T06:30:13.966331Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Testing systematic forwarding from each node
[INFO] [stdout] 2025-09-01T06:30:13.966379Z  INFO raft_poc::raft::integration_tests::integration_tests: 📤 Submitted 'FORWARDING_FROM_NODE_0' to node 0
[INFO] [stdout] 2025-09-01T06:30:13.966452Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'FORWARDING_FROM_NODE_0' by Candidate 0 (WILL REJECT) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.969566Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 First election completed, triggering manual election
[INFO] [stdout] 2025-09-01T06:30:13.970125Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Submitting multiple concurrent proposals
[INFO] [stdout] 2025-09-01T06:30:13.970387Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'CONCURRENT_PROPOSAL_0' by Follower 0 (WILL REJECT) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.973191Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Submitting test proposal for consensus flow visualization
[INFO] [stdout] 2025-09-01T06:30:13.973308Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'TEST_PROPOSAL_FOR_VISUALIZATION' by Candidate 0 (WILL REJECT) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.979676Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.979802Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.979883Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/2 votes) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.980094Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 0 requesting votes from 2 nodes for term 1 (need 2/3 votes) node_id=0
[INFO] [stdout] 2025-09-01T06:30:13.980187Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 2 nodes for election term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.015937Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Testing proposal submission to follower (should forward)
[INFO] [stdout] 2025-09-01T06:30:14.016220Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'FORWARDING_TEST_0' by Candidate 0 (WILL REJECT) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.033127Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Election period completed for 5-node cluster
[INFO] [stdout] 2025-09-01T06:30:14.033184Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ 5-node leader election test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_leader_election_5_nodes ... ok
[INFO] [stdout] 2025-09-01T06:30:14.033648Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Testing cluster behavior under stress (simulating partition scenarios)
[INFO] [stdout] 2025-09-01T06:30:14.127710Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'CONCURRENT_PROPOSAL_3' by Candidate 0 (WILL REJECT) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.241167Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'SIMULATE_PARTITION' by Candidate 2 (WILL REJECT) node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.370096Z  INFO raft_poc::raft::integration_tests::integration_tests: 📤 Submitted 'FORWARDING_FROM_NODE_1' to node 1
[INFO] [stdout] 2025-09-01T06:30:14.407234Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.407378Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.407426Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/3 votes) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.407469Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 1 requesting votes from 3 nodes for term 1 (need 3/4 votes) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.407520Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 3 nodes for election term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.434258Z  WARN raft_poc::raft::simulation: ⏰ Election timeout! Current state: Follower, term: 0 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.434357Z  INFO raft_poc::raft::algorithm: 🗳️  Starting election for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.434385Z  INFO raft_poc::raft::algorithm: 🎯 Became candidate for term 1, voted for self (1/2 votes) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.434409Z  INFO raft_poc::raft::simulation: 🗳️ ELECTION STARTED: Candidate 0 requesting votes from 2 nodes for term 1 (need 2/3 votes) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.434438Z  INFO raft_poc::raft::simulation: 📤 VOTE REQUESTS SENT: RequestVote broadcasted to 2 nodes for election term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.483140Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 2 granted vote to candidate 0 for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.483245Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 1 granted vote to candidate 0 for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.483276Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 2! Now have 2/2 votes for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.483296Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 1 with majority votes! node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.483310Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 2 followers node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.483321Z  INFO raft_poc::raft::simulation: 🚨 LEADER ELECTION SUCCESS: Node 0 transitioning Candidate → Leader (term 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.483345Z  INFO raft_poc::raft::simulation: 📡 EVENTS EMITTED: LeaderElected + StateChange events sent for new leader 0 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.502292Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 4 granted vote to candidate 3 for term 1 node_id=4
[INFO] [stdout] 2025-09-01T06:30:14.502380Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 2 granted vote to candidate 3 for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.502411Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 0 granted vote to candidate 3 for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.502438Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 1 granted vote to candidate 3 for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.502469Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 4! Now have 2/3 votes for term 1 node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.502496Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 2! Now have 3/3 votes for term 1 node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.502506Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 1 with majority votes! node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.502520Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 4 followers node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.502530Z  INFO raft_poc::raft::simulation: 🚨 LEADER ELECTION SUCCESS: Node 3 transitioning Candidate → Leader (term 1) node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.502551Z  INFO raft_poc::raft::simulation: 📡 EVENTS EMITTED: LeaderElected + StateChange events sent for new leader 3 node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.547144Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 0 granted vote to candidate 2 for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.547265Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 1 granted vote to candidate 2 for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.547297Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 0! Now have 2/2 votes for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.547316Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 1 with majority votes! node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.547332Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 2 followers node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.547341Z  INFO raft_poc::raft::simulation: 🚨 LEADER ELECTION SUCCESS: Node 2 transitioning Candidate → Leader (term 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.547363Z  INFO raft_poc::raft::simulation: 📡 EVENTS EMITTED: LeaderElected + StateChange events sent for new leader 2 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.555746Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 2 granted vote to candidate 0 for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.555845Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 1 granted vote to candidate 0 for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.556557Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'FORWARDING_TEST_1' by Follower 1 (WILL REJECT) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.556891Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 2! Now have 2/2 votes for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.556933Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 1 with majority votes! node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.556950Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 2 followers node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.557023Z  INFO raft_poc::raft::simulation: 🚨 LEADER ELECTION SUCCESS: Node 0 transitioning Candidate → Leader (term 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.557061Z  INFO raft_poc::raft::simulation: 📡 EVENTS EMITTED: LeaderElected + StateChange events sent for new leader 0 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.559149Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 0 granted vote to candidate 3 for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.559240Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 1 granted vote to candidate 3 for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.559269Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 2 granted vote to candidate 3 for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.559296Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 0! Now have 2/3 votes for term 1 node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.559313Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 1! Now have 3/3 votes for term 1 node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.559322Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 1 with majority votes! node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.559337Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 3 followers node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.559345Z  INFO raft_poc::raft::simulation: 🚨 LEADER ELECTION SUCCESS: Node 3 transitioning Candidate → Leader (term 1) node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.559363Z  INFO raft_poc::raft::simulation: 📡 EVENTS EMITTED: LeaderElected + StateChange events sent for new leader 3 node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.586282Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 0 granted vote to candidate 2 for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.586379Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 1 granted vote to candidate 2 for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.586404Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'SIMULATE_ELECTION_TIMEOUT' by Follower 1 (WILL REJECT) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.586437Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 0! Now have 2/2 votes for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.586453Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 1 with majority votes! node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.586467Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 2 followers node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.586476Z  INFO raft_poc::raft::simulation: 🚨 LEADER ELECTION SUCCESS: Node 2 transitioning Candidate → Leader (term 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.586493Z  INFO raft_poc::raft::simulation: 📡 EVENTS EMITTED: LeaderElected + StateChange events sent for new leader 2 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.621401Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'FORWARDING_TEST_2' by Follower 2 (WILL REJECT) node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.621465Z  INFO raft_poc::raft::simulation: 📤 FORWARDING: Command 'FORWARDING_TEST_2' from follower 2 to leader 0 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.621517Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'FORWARDING_TEST_2' by Leader 0 (WILL PROCESS) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621536Z  INFO raft_poc::raft::algorithm: 📋 STEP 1/4 - PROPOSAL CREATED: Command 'FORWARDING_TEST_2' → pending proposal at index 1 (term 1) | Need 2/3 acks for consensus node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621574Z  INFO raft_poc::raft::simulation: 🔄 CONSENSUS FLOW START: Client command 'FORWARDING_TEST_2' accepted as pending proposal at index 1 (term 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621595Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: LogEntryProposed for proposal 1 (awaiting consensus) - STEP 2/4 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621605Z  INFO raft_poc::raft::simulation: 📤 STEP 2/4 - REPLICATING: Broadcasting AppendEntries with proposal 1 to 2 followers node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621620Z  INFO raft_poc::raft::simulation: 📤 → Follower 1: Sending AppendEntries with 1 entries (0 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621644Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 0 → follower 1 (1 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621659Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 1 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621668Z  INFO raft_poc::raft::simulation: 📤 → Follower 2: Sending AppendEntries with 1 entries (0 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621678Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 0 → follower 2 (1 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621687Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 2 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621709Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 1 entries (term: 1) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.621731Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.621756Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 1 entries (term: 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.621767Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.621798Z  INFO raft_poc::raft::algorithm: 📝 STEP 3/4 - ACK RECEIVED: Follower 1 acknowledged proposal 1 → 2/2 acks (CONSENSUS ACHIEVED!) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621814Z  INFO raft_poc::raft::algorithm: 🎯 CONSENSUS DETECTED: Proposal 1 has 2/2 acks - ready to commit! node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621824Z  INFO raft_poc::raft::algorithm: 🎯 STEP 4/4 - COMMITTING: Proposal 1 achieved consensus → moving to committed log node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.621840Z  INFO raft_poc::raft::algorithm: ✅ CONSENSUS FLOW COMPLETE: Command 'FORWARDING_TEST_2' committed to log at index 1 (term 1) | Acknowledged by: [0, 1] node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.637674Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 2 granted vote to candidate 0 for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.637776Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 1 granted vote to candidate 0 for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.637808Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'FORWARDING_FROM_NODE_1' by Follower 1 (WILL REJECT) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.637861Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 4 granted vote to candidate 0 for term 1 node_id=4
[INFO] [stdout] 2025-09-01T06:30:14.637907Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 3 granted vote to candidate 0 for term 1 node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.637939Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 2! Now have 2/3 votes for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.637986Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 1! Now have 3/3 votes for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.637996Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 1 with majority votes! node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.638008Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 4 followers node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.638017Z  INFO raft_poc::raft::simulation: 🚨 LEADER ELECTION SUCCESS: Node 0 transitioning Candidate → Leader (term 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.638034Z  INFO raft_poc::raft::simulation: 📡 EVENTS EMITTED: LeaderElected + StateChange events sent for new leader 0 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771130Z  INFO raft_poc::raft::integration_tests::integration_tests: 📤 Submitted 'FORWARDING_FROM_NODE_2' to node 2
[INFO] [stdout] 2025-09-01T06:30:14.771230Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'FORWARDING_FROM_NODE_2' by Follower 2 (WILL REJECT) node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.771250Z  INFO raft_poc::raft::simulation: 📤 FORWARDING: Command 'FORWARDING_FROM_NODE_2' from follower 2 to leader 0 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.771289Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'FORWARDING_FROM_NODE_2' by Leader 0 (WILL PROCESS) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771311Z  INFO raft_poc::raft::algorithm: 📋 STEP 1/4 - PROPOSAL CREATED: Command 'FORWARDING_FROM_NODE_2' → pending proposal at index 1 (term 1) | Need 3/5 acks for consensus node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771333Z  INFO raft_poc::raft::simulation: 🔄 CONSENSUS FLOW START: Client command 'FORWARDING_FROM_NODE_2' accepted as pending proposal at index 1 (term 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771363Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: LogEntryProposed for proposal 1 (awaiting consensus) - STEP 2/4 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771372Z  INFO raft_poc::raft::simulation: 📤 STEP 2/4 - REPLICATING: Broadcasting AppendEntries with proposal 1 to 4 followers node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771387Z  INFO raft_poc::raft::simulation: 📤 → Follower 1: Sending AppendEntries with 1 entries (0 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771413Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 0 → follower 1 (1 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771429Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 1 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771438Z  INFO raft_poc::raft::simulation: 📤 → Follower 2: Sending AppendEntries with 1 entries (0 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771450Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 0 → follower 2 (1 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771461Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 2 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771469Z  INFO raft_poc::raft::simulation: 📤 → Follower 3: Sending AppendEntries with 1 entries (0 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771480Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 0 → follower 3 (1 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771492Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 3 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771500Z  INFO raft_poc::raft::simulation: 📤 → Follower 4: Sending AppendEntries with 1 entries (0 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771510Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 0 → follower 4 (1 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771520Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 4 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.771549Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 1 entries (term: 1) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.771578Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.771620Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 1 entries (term: 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.771643Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.771676Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 1 entries (term: 1) node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.771691Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.771732Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 1 entries (term: 1) node_id=4
[INFO] [stdout] 2025-09-01T06:30:14.771748Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=4
[INFO] [stdout] 2025-09-01T06:30:14.771790Z  INFO raft_poc::raft::algorithm: 📝 STEP 3/4 - ACK RECEIVED: Follower 1 acknowledged proposal 1 → 2/3 acks (waiting for more...) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.787739Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 1 granted vote to candidate 2 for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.787835Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'SIMULATE_PARTITION' by Follower 1 (WILL REJECT) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.787886Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 4 granted vote to candidate 2 for term 1 node_id=4
[INFO] [stdout] 2025-09-01T06:30:14.787919Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 0 granted vote to candidate 2 for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.787990Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 3 granted vote to candidate 2 for term 1 node_id=3
[INFO] [stdout] 2025-09-01T06:30:14.788022Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 1! Now have 2/3 votes for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.788050Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 4! Now have 3/3 votes for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.788059Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 1 with majority votes! node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.788073Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 4 followers node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.788081Z  INFO raft_poc::raft::simulation: 🚨 LEADER ELECTION SUCCESS: Node 2 transitioning Candidate → Leader (term 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.788100Z  INFO raft_poc::raft::simulation: 📡 EVENTS EMITTED: LeaderElected + StateChange events sent for new leader 2 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.806095Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 0 granted vote to candidate 1 for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.806209Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 2 granted vote to candidate 1 for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.806253Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 0! Now have 2/2 votes for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.806343Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 1 with majority votes! node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.806489Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 2 followers node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.806652Z  INFO raft_poc::raft::simulation: 🚨 LEADER ELECTION SUCCESS: Node 1 transitioning Candidate → Leader (term 1) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.806778Z  INFO raft_poc::raft::simulation: 📡 EVENTS EMITTED: LeaderElected + StateChange events sent for new leader 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.859249Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 0 granted vote to candidate 1 for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.859364Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 2 granted vote to candidate 1 for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.859402Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 0! Now have 2/2 votes for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.859425Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 1 with majority votes! node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.859440Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 2 followers node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.859449Z  INFO raft_poc::raft::simulation: 🚨 LEADER ELECTION SUCCESS: Node 1 transitioning Candidate → Leader (term 1) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.859471Z  INFO raft_poc::raft::simulation: 📡 EVENTS EMITTED: LeaderElected + StateChange events sent for new leader 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.904277Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 0 granted vote to candidate 2 for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.904384Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 1 granted vote to candidate 2 for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.904416Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 0! Now have 2/2 votes for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.904438Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 1 with majority votes! node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.904452Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 2 followers node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.904460Z  INFO raft_poc::raft::simulation: 🚨 LEADER ELECTION SUCCESS: Node 2 transitioning Candidate → Leader (term 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.904483Z  INFO raft_poc::raft::simulation: 📡 EVENTS EMITTED: LeaderElected + StateChange events sent for new leader 2 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.923202Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Proposal rejection testing completed
[INFO] [stdout] 2025-09-01T06:30:14.973234Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Split vote scenario test period completed
[INFO] [stdout] 2025-09-01T06:30:14.973286Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Split vote scenario test completed
[INFO] [stdout] 2025-09-01T06:30:14.974218Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Log replication test completed
[INFO] [stdout] 2025-09-01T06:30:14.974248Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Log replication test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_split_vote_scenario ... ok
[INFO] [stdout] test raft::integration_tests::integration_tests::test_log_replication ... ok
[INFO] [stdout] 2025-09-01T06:30:14.982130Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 1 granted vote to candidate 0 for term 1 node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.982221Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'CONCURRENT_PROPOSAL_1' by Follower 1 (WILL REJECT) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.982251Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'CONCURRENT_PROPOSAL_4' by Follower 1 (WILL REJECT) node_id=1
[INFO] [stdout] 2025-09-01T06:30:14.982288Z  INFO raft_poc::raft::simulation: ✅ VOTE GRANTED: Node 2 granted vote to candidate 0 for term 1 node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.982310Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'CONCURRENT_PROPOSAL_2' by Follower 2 (WILL REJECT) node_id=2
[INFO] [stdout] 2025-09-01T06:30:14.982340Z  INFO raft_poc::raft::algorithm: ✅ Vote granted from Node 1! Now have 2/2 votes for term 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.982364Z  INFO raft_poc::raft::algorithm: 👑 Became LEADER for term 1 with majority votes! node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.982379Z  INFO raft_poc::raft::algorithm: ❤️  Starting to send heartbeats to 2 followers node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.982388Z  INFO raft_poc::raft::simulation: 🚨 LEADER ELECTION SUCCESS: Node 0 transitioning Candidate → Leader (term 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:14.982415Z  INFO raft_poc::raft::simulation: 📡 EVENTS EMITTED: LeaderElected + StateChange events sent for new leader 0 node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.172360Z  INFO raft_poc::raft::integration_tests::integration_tests: 📤 Submitted 'FORWARDING_FROM_NODE_3' to node 3
[INFO] [stdout] 2025-09-01T06:30:15.172468Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'FORWARDING_FROM_NODE_3' by Follower 3 (WILL REJECT) node_id=3
[INFO] [stdout] 2025-09-01T06:30:15.172491Z  INFO raft_poc::raft::simulation: 📤 FORWARDING: Command 'FORWARDING_FROM_NODE_3' from follower 3 to leader 0 node_id=3
[INFO] [stdout] 2025-09-01T06:30:15.573113Z  INFO raft_poc::raft::integration_tests::integration_tests: 📤 Submitted 'FORWARDING_FROM_NODE_4' to node 4
[INFO] [stdout] 2025-09-01T06:30:15.573228Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'FORWARDING_FROM_NODE_4' by Follower 4 (WILL REJECT) node_id=4
[INFO] [stdout] 2025-09-01T06:30:15.573247Z  INFO raft_poc::raft::simulation: 📤 FORWARDING: Command 'FORWARDING_FROM_NODE_4' from follower 4 to leader 0 node_id=4
[INFO] [stdout] 2025-09-01T06:30:15.628175Z  INFO raft_poc::raft::simulation: 📊 Found 1 consensus ACK(s) to emit for follower 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.628250Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ConsensusAckReceived from follower 1 → leader 0 for proposal 1 (2/2 acks, consensus: true) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.628269Z  INFO raft_poc::raft::simulation: 🎉 PROPOSALS COMMITTED: 1 new entries added to committed log (index 1 → 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.628297Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ReplicationCompleted for 1 entries achieving consensus node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.778136Z  INFO raft_poc::raft::simulation: 📊 Found 1 consensus ACK(s) to emit for follower 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.778213Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ConsensusAckReceived from follower 1 → leader 0 for proposal 1 (2/3 acks, consensus: false) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.778259Z  INFO raft_poc::raft::algorithm: 📝 STEP 3/4 - ACK RECEIVED: Follower 2 acknowledged proposal 1 → 3/3 acks (CONSENSUS ACHIEVED!) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.778278Z  INFO raft_poc::raft::algorithm: 🎯 CONSENSUS DETECTED: Proposal 1 has 3/3 acks - ready to commit! node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.778296Z  INFO raft_poc::raft::algorithm: 🎯 STEP 4/4 - COMMITTING: Proposal 1 achieved consensus → moving to committed log node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.778307Z  INFO raft_poc::raft::algorithm: ✅ CONSENSUS FLOW COMPLETE: Command 'FORWARDING_FROM_NODE_2' committed to log at index 1 (term 1) | Acknowledged by: [0, 1, 2] node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.969669Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Split vote resolution test period completed
[INFO] [stdout] 2025-09-01T06:30:15.969720Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Split vote scenario test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_split_vote_resolution ... ok
[INFO] [stdout] 2025-09-01T06:30:15.970179Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'normal_op_0' by Follower 0 (WILL REJECT) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.970215Z  INFO raft_poc::raft::simulation: 📤 FORWARDING: Command 'normal_op_0' from follower 0 to leader 2 node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.970253Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'normal_op_0' by Leader 2 (WILL PROCESS) node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970288Z  INFO raft_poc::raft::algorithm: 📋 STEP 1/4 - PROPOSAL CREATED: Command 'normal_op_0' → pending proposal at index 1 (term 1) | Need 2/3 acks for consensus node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970301Z  INFO raft_poc::raft::simulation: 🔄 CONSENSUS FLOW START: Client command 'normal_op_0' accepted as pending proposal at index 1 (term 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970317Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: LogEntryProposed for proposal 1 (awaiting consensus) - STEP 2/4 node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970326Z  INFO raft_poc::raft::simulation: 📤 STEP 2/4 - REPLICATING: Broadcasting AppendEntries with proposal 1 to 2 followers node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970339Z  INFO raft_poc::raft::simulation: 📤 → Follower 0: Sending AppendEntries with 1 entries (0 committed + 1 pending) node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970363Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 2 → follower 0 (1 entries) node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970378Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 0 successfully node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970387Z  INFO raft_poc::raft::simulation: 📤 → Follower 1: Sending AppendEntries with 1 entries (0 committed + 1 pending) node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970399Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 2 → follower 1 (1 entries) node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970409Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 1 successfully node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970437Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 2 with 1 entries (term: 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.970459Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 2 → SUCCESS (ACK) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.970492Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 2 with 1 entries (term: 1) node_id=1
[INFO] [stdout] 2025-09-01T06:30:15.970505Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 2 → SUCCESS (ACK) node_id=1
[INFO] [stdout] 2025-09-01T06:30:15.970542Z  INFO raft_poc::raft::algorithm: 📝 STEP 3/4 - ACK RECEIVED: Follower 0 acknowledged proposal 1 → 2/2 acks (CONSENSUS ACHIEVED!) node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970582Z  INFO raft_poc::raft::algorithm: 🎯 CONSENSUS DETECTED: Proposal 1 has 2/2 acks - ready to commit! node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970607Z  INFO raft_poc::raft::algorithm: 🎯 STEP 4/4 - COMMITTING: Proposal 1 achieved consensus → moving to committed log node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970618Z  INFO raft_poc::raft::algorithm: ✅ CONSENSUS FLOW COMPLETE: Command 'normal_op_0' committed to log at index 1 (term 1) | Acknowledged by: [2, 0] node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.970992Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Manual election completed
[INFO] [stdout] 2025-09-01T06:30:15.971038Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Detailed election process test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_election_process_detailed ... ok
[INFO] [stdout] 2025-09-01T06:30:15.980091Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 First proposal completed, submitting to different node
[INFO] [stdout] 2025-09-01T06:30:15.980208Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'TEST_FORWARDING_PROPOSAL' by Follower 1 (WILL REJECT) node_id=1
[INFO] [stdout] 2025-09-01T06:30:15.980234Z  INFO raft_poc::raft::simulation: 📤 FORWARDING: Command 'TEST_FORWARDING_PROPOSAL' from follower 1 to leader 0 node_id=1
[INFO] [stdout] 2025-09-01T06:30:15.980266Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'TEST_FORWARDING_PROPOSAL' by Leader 0 (WILL PROCESS) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980293Z  INFO raft_poc::raft::algorithm: 📋 STEP 1/4 - PROPOSAL CREATED: Command 'TEST_FORWARDING_PROPOSAL' → pending proposal at index 1 (term 1) | Need 2/3 acks for consensus node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980304Z  INFO raft_poc::raft::simulation: 🔄 CONSENSUS FLOW START: Client command 'TEST_FORWARDING_PROPOSAL' accepted as pending proposal at index 1 (term 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980320Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: LogEntryProposed for proposal 1 (awaiting consensus) - STEP 2/4 node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980328Z  INFO raft_poc::raft::simulation: 📤 STEP 2/4 - REPLICATING: Broadcasting AppendEntries with proposal 1 to 2 followers node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980342Z  INFO raft_poc::raft::simulation: 📤 → Follower 1: Sending AppendEntries with 1 entries (0 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980373Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 0 → follower 1 (1 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980393Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 1 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980406Z  INFO raft_poc::raft::simulation: 📤 → Follower 2: Sending AppendEntries with 1 entries (0 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980418Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 0 → follower 2 (1 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980439Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 2 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980461Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 1 entries (term: 1) node_id=1
[INFO] [stdout] 2025-09-01T06:30:15.980481Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=1
[INFO] [stdout] 2025-09-01T06:30:15.980522Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 1 entries (term: 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.980544Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=2
[INFO] [stdout] 2025-09-01T06:30:15.980587Z  INFO raft_poc::raft::algorithm: 📝 STEP 3/4 - ACK RECEIVED: Follower 1 acknowledged proposal 1 → 2/2 acks (CONSENSUS ACHIEVED!) node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980614Z  INFO raft_poc::raft::algorithm: 🎯 CONSENSUS DETECTED: Proposal 1 has 2/2 acks - ready to commit! node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980625Z  INFO raft_poc::raft::algorithm: 🎯 STEP 4/4 - COMMITTING: Proposal 1 achieved consensus → moving to committed log node_id=0
[INFO] [stdout] 2025-09-01T06:30:15.980634Z  INFO raft_poc::raft::algorithm: ✅ CONSENSUS FLOW COMPLETE: Command 'TEST_FORWARDING_PROPOSAL' committed to log at index 1 (term 1) | Acknowledged by: [0, 1] node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.171159Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'normal_op_1' by Follower 1 (WILL REJECT) node_id=1
[INFO] [stdout] 2025-09-01T06:30:16.171215Z  INFO raft_poc::raft::simulation: 📤 FORWARDING: Command 'normal_op_1' from follower 1 to leader 2 node_id=1
[INFO] [stdout] 2025-09-01T06:30:16.484126Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Commit index advancement test completed
[INFO] [stdout] 2025-09-01T06:30:16.484185Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Commit index advancement test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_commit_index_advancement ... ok
[INFO] [stdout] 2025-09-01T06:30:16.779280Z  INFO raft_poc::raft::simulation: 📊 Found 1 consensus ACK(s) to emit for follower 2 node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779360Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ConsensusAckReceived from follower 2 → leader 0 for proposal 1 (3/3 acks, consensus: true) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779376Z  INFO raft_poc::raft::simulation: 🎉 PROPOSALS COMMITTED: 1 new entries added to committed log (index 1 → 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779402Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ReplicationCompleted for 1 entries achieving consensus node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779485Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'FORWARDING_FROM_NODE_3' by Leader 0 (WILL PROCESS) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779516Z  INFO raft_poc::raft::algorithm: 📋 STEP 1/4 - PROPOSAL CREATED: Command 'FORWARDING_FROM_NODE_3' → pending proposal at index 2 (term 1) | Need 3/5 acks for consensus node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779529Z  INFO raft_poc::raft::simulation: 🔄 CONSENSUS FLOW START: Client command 'FORWARDING_FROM_NODE_3' accepted as pending proposal at index 2 (term 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779546Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: LogEntryProposed for proposal 2 (awaiting consensus) - STEP 2/4 node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779561Z  INFO raft_poc::raft::simulation: 📤 STEP 2/4 - REPLICATING: Broadcasting AppendEntries with proposal 2 to 4 followers node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779577Z  INFO raft_poc::raft::simulation: 📤 → Follower 1: Sending AppendEntries with 2 entries (1 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779613Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 2 LogEntryProposed events from leader 0 → follower 1 (2 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779636Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 1 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779647Z  INFO raft_poc::raft::simulation: 📤 → Follower 2: Sending AppendEntries with 2 entries (1 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779670Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 2 LogEntryProposed events from leader 0 → follower 2 (2 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779693Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 2 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779702Z  INFO raft_poc::raft::simulation: 📤 → Follower 3: Sending AppendEntries with 1 entries (1 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779714Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 0 → follower 3 (1 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779724Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 3 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779733Z  INFO raft_poc::raft::simulation: 📤 → Follower 4: Sending AppendEntries with 1 entries (1 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779743Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 0 → follower 4 (1 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779753Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 4 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779780Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'FORWARDING_FROM_NODE_4' by Leader 0 (WILL PROCESS) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779810Z  INFO raft_poc::raft::algorithm: 📋 STEP 1/4 - PROPOSAL CREATED: Command 'FORWARDING_FROM_NODE_4' → pending proposal at index 2 (term 1) | Need 3/5 acks for consensus node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779819Z  INFO raft_poc::raft::simulation: 🔄 CONSENSUS FLOW START: Client command 'FORWARDING_FROM_NODE_4' accepted as pending proposal at index 2 (term 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779833Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: LogEntryProposed for proposal 2 (awaiting consensus) - STEP 2/4 node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779841Z  INFO raft_poc::raft::simulation: 📤 STEP 2/4 - REPLICATING: Broadcasting AppendEntries with proposal 2 to 4 followers node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779861Z  INFO raft_poc::raft::simulation: 📤 → Follower 1: Sending AppendEntries with 2 entries (1 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779876Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 2 LogEntryProposed events from leader 0 → follower 1 (2 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779897Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 1 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779906Z  INFO raft_poc::raft::simulation: 📤 → Follower 2: Sending AppendEntries with 2 entries (1 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779935Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 2 LogEntryProposed events from leader 0 → follower 2 (2 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779944Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 2 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779971Z  INFO raft_poc::raft::simulation: 📤 → Follower 3: Sending AppendEntries with 1 entries (1 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779986Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 0 → follower 3 (1 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.779995Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 3 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.780011Z  INFO raft_poc::raft::simulation: 📤 → Follower 4: Sending AppendEntries with 1 entries (1 committed + 1 pending) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.780023Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 0 → follower 4 (1 entries) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.780032Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 4 successfully node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.780072Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 2 entries (term: 1) node_id=1
[INFO] [stdout] 2025-09-01T06:30:16.780102Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=1
[INFO] [stdout] 2025-09-01T06:30:16.780128Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 2 entries (term: 1) node_id=1
[INFO] [stdout] 2025-09-01T06:30:16.780139Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=1
[INFO] [stdout] 2025-09-01T06:30:16.780166Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 2 entries (term: 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.780189Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.780208Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 2 entries (term: 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.780230Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.780255Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 1 entries (term: 1) node_id=3
[INFO] [stdout] 2025-09-01T06:30:16.780327Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=3
[INFO] [stdout] 2025-09-01T06:30:16.780361Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 1 entries (term: 1) node_id=3
[INFO] [stdout] 2025-09-01T06:30:16.780372Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=3
[INFO] [stdout] 2025-09-01T06:30:16.780399Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 1 entries (term: 1) node_id=4
[INFO] [stdout] 2025-09-01T06:30:16.780422Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=4
[INFO] [stdout] 2025-09-01T06:30:16.780443Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 0 with 1 entries (term: 1) node_id=4
[INFO] [stdout] 2025-09-01T06:30:16.780453Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 0 → SUCCESS (ACK) node_id=4
[INFO] [stdout] 2025-09-01T06:30:16.780485Z  INFO raft_poc::raft::algorithm: 📝 STEP 3/4 - ACK RECEIVED: Follower 1 acknowledged proposal 2 → 2/3 acks (waiting for more...) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.924794Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Proposal rejection cases test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_proposal_rejection_cases ... ok
[INFO] [stdout] 2025-09-01T06:30:16.972096Z  INFO raft_poc::raft::integration_tests::integration_tests: ⏱️ Election occurred within 6 seconds
[INFO] [stdout] 2025-09-01T06:30:16.972151Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Election timeout ranges test completed
[INFO] [stdout] 2025-09-01T06:30:16.972623Z  INFO raft_poc::raft::simulation: 📊 Found 1 consensus ACK(s) to emit for follower 0 node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972664Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ConsensusAckReceived from follower 0 → leader 2 for proposal 1 (2/2 acks, consensus: true) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972679Z  INFO raft_poc::raft::simulation: 🎉 PROPOSALS COMMITTED: 1 new entries added to committed log (index 1 → 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972710Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ReplicationCompleted for 1 entries achieving consensus node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972773Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'normal_op_1' by Leader 2 (WILL PROCESS) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972795Z  INFO raft_poc::raft::algorithm: 📋 STEP 1/4 - PROPOSAL CREATED: Command 'normal_op_1' → pending proposal at index 2 (term 1) | Need 2/3 acks for consensus node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972808Z  INFO raft_poc::raft::simulation: 🔄 CONSENSUS FLOW START: Client command 'normal_op_1' accepted as pending proposal at index 2 (term 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972826Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: LogEntryProposed for proposal 2 (awaiting consensus) - STEP 2/4 node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972836Z  INFO raft_poc::raft::simulation: 📤 STEP 2/4 - REPLICATING: Broadcasting AppendEntries with proposal 2 to 2 followers node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972851Z  INFO raft_poc::raft::simulation: 📤 → Follower 0: Sending AppendEntries with 2 entries (1 committed + 1 pending) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972872Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 2 LogEntryProposed events from leader 2 → follower 0 (2 entries) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972895Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 0 successfully node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972907Z  INFO raft_poc::raft::simulation: 📤 → Follower 1: Sending AppendEntries with 1 entries (1 committed + 1 pending) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972920Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 2 → follower 1 (1 entries) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972932Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 1 successfully node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972973Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ClientCommandReceived 'normal_op_2' by Leader 2 (WILL PROCESS) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972988Z  INFO raft_poc::raft::algorithm: 📋 STEP 1/4 - PROPOSAL CREATED: Command 'normal_op_2' → pending proposal at index 2 (term 1) | Need 2/3 acks for consensus node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.972997Z  INFO raft_poc::raft::simulation: 🔄 CONSENSUS FLOW START: Client command 'normal_op_2' accepted as pending proposal at index 2 (term 1) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.973013Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: LogEntryProposed for proposal 2 (awaiting consensus) - STEP 2/4 node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.973021Z  INFO raft_poc::raft::simulation: 📤 STEP 2/4 - REPLICATING: Broadcasting AppendEntries with proposal 2 to 2 followers node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.973033Z  INFO raft_poc::raft::simulation: 📤 → Follower 0: Sending AppendEntries with 2 entries (1 committed + 1 pending) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.973049Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 2 LogEntryProposed events from leader 2 → follower 0 (2 entries) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.973061Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 0 successfully node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.973073Z  INFO raft_poc::raft::simulation: 📤 → Follower 1: Sending AppendEntries with 1 entries (1 committed + 1 pending) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.973086Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: 1 LogEntryProposed events from leader 2 → follower 1 (1 entries) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.973114Z  INFO raft_poc::raft::simulation: ✅ AppendEntries sent to follower 1 successfully node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.973152Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 2 with 2 entries (term: 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.973171Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 2 → SUCCESS (ACK) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.973199Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 2 with 2 entries (term: 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.973212Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 2 → SUCCESS (ACK) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.973244Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 2 with 1 entries (term: 1) node_id=1
[INFO] [stdout] 2025-09-01T06:30:16.973260Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 2 → SUCCESS (ACK) node_id=1
[INFO] [stdout] 2025-09-01T06:30:16.973299Z  INFO raft_poc::raft::simulation: 📥 RECEIVED: AppendEntries from leader 2 with 1 entries (term: 1) node_id=1
[INFO] [stdout] 2025-09-01T06:30:16.973312Z  INFO raft_poc::raft::simulation: 📤 RESPONDING: AppendEntries response to leader 2 → SUCCESS (ACK) node_id=1
[INFO] [stdout] 2025-09-01T06:30:16.973358Z  INFO raft_poc::raft::algorithm: 📝 STEP 3/4 - ACK RECEIVED: Follower 0 acknowledged proposal 2 → 2/2 acks (CONSENSUS ACHIEVED!) node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.973380Z  INFO raft_poc::raft::algorithm: 🎯 CONSENSUS DETECTED: Proposal 2 has 2/2 acks - ready to commit! node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.973391Z  INFO raft_poc::raft::algorithm: 🎯 STEP 4/4 - COMMITTING: Proposal 2 achieved consensus → moving to committed log node_id=2
[INFO] [stdout] 2025-09-01T06:30:16.973401Z  INFO raft_poc::raft::algorithm: ✅ CONSENSUS FLOW COMPLETE: Command 'normal_op_2' committed to log at index 2 (term 1) | Acknowledged by: [2, 0] node_id=2
[INFO] [stdout] test raft::integration_tests::integration_tests::test_election_timeout_ranges ... ok
[INFO] [stdout] 2025-09-01T06:30:16.982244Z  INFO raft_poc::raft::simulation: 📊 Found 1 consensus ACK(s) to emit for follower 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.982310Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ConsensusAckReceived from follower 1 → leader 0 for proposal 1 (2/2 acks, consensus: true) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.982327Z  INFO raft_poc::raft::simulation: 🎉 PROPOSALS COMMITTED: 1 new entries added to committed log (index 1 → 1) node_id=0
[INFO] [stdout] 2025-09-01T06:30:16.982353Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ReplicationCompleted for 1 entries achieving consensus node_id=0
[INFO] [stdout] 2025-09-01T06:30:17.781287Z  INFO raft_poc::raft::simulation: 📊 Found 1 consensus ACK(s) to emit for follower 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:17.781354Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ConsensusAckReceived from follower 1 → leader 0 for proposal 2 (2/3 acks, consensus: false) node_id=0
[INFO] [stdout] 2025-09-01T06:30:17.781402Z  INFO raft_poc::raft::algorithm: 📝 STEP 3/4 - ACK RECEIVED: Follower 1 acknowledged proposal 2 → 2/3 acks (waiting for more...) node_id=0
[INFO] [stdout] 2025-09-01T06:30:17.975308Z  INFO raft_poc::raft::simulation: 📊 Found 1 consensus ACK(s) to emit for follower 0 node_id=2
[INFO] [stdout] 2025-09-01T06:30:17.975374Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ConsensusAckReceived from follower 0 → leader 2 for proposal 2 (2/2 acks, consensus: true) node_id=2
[INFO] [stdout] 2025-09-01T06:30:17.975389Z  INFO raft_poc::raft::simulation: 🎉 PROPOSALS COMMITTED: 1 new entries added to committed log (index 2 → 2) node_id=2
[INFO] [stdout] 2025-09-01T06:30:17.975413Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ReplicationCompleted for 1 entries achieving consensus node_id=2
[INFO] [stdout] 2025-09-01T06:30:17.994463Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Proposal consensus flow test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_proposal_consensus_flow ... ok
[INFO] [stdout] 2025-09-01T06:30:18.231923Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Concurrent proposals test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_concurrent_proposals ... ok
[INFO] [stdout] 2025-09-01T06:30:18.442889Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Partition simulation completed, observing recovery
[INFO] [stdout] 2025-09-01T06:30:18.578790Z  INFO raft_poc::raft::integration_tests::integration_tests: 🔍 Normal operation test completed
[INFO] [stdout] 2025-09-01T06:30:18.578846Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Normal cluster operation test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_normal_cluster_operation ... ok
[INFO] [stdout] 2025-09-01T06:30:18.782266Z  INFO raft_poc::raft::simulation: 📊 Found 1 consensus ACK(s) to emit for follower 1 node_id=0
[INFO] [stdout] 2025-09-01T06:30:18.782327Z  INFO raft_poc::raft::simulation: 📡 EVENT EMITTED: ConsensusAckReceived from follower 1 → leader 0 for proposal 2 (2/3 acks, consensus: false) node_id=0
[INFO] [stdout] 2025-09-01T06:30:18.782370Z  INFO raft_poc::raft::algorithm: 📝 STEP 3/4 - ACK RECEIVED: Follower 2 acknowledged proposal 2 → 3/3 acks (CONSENSUS ACHIEVED!) node_id=0
[INFO] [stdout] 2025-09-01T06:30:18.782387Z  INFO raft_poc::raft::algorithm: 🎯 CONSENSUS DETECTED: Proposal 2 has 3/3 acks - ready to commit! node_id=0
[INFO] [stdout] 2025-09-01T06:30:18.782402Z  INFO raft_poc::raft::algorithm: 🎯 STEP 4/4 - COMMITTING: Proposal 2 achieved consensus → moving to committed log node_id=0
[INFO] [stdout] 2025-09-01T06:30:18.782412Z  INFO raft_poc::raft::algorithm: ✅ CONSENSUS FLOW COMPLETE: Command 'FORWARDING_FROM_NODE_4' committed to log at index 2 (term 1) | Acknowledged by: [0, 1, 2] node_id=0
[INFO] [stdout] 2025-09-01T06:30:18.966929Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Heartbeat maintenance test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_heartbeat_maintenance ... ok
[INFO] [stdout] 2025-09-01T06:30:18.974948Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Leader forwarding test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_leader_forwarding ... ok
[INFO] [stdout] 2025-09-01T06:30:19.966577Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Heartbeat failure detection test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_heartbeat_failure_detection ... ok
[INFO] [stdout] 2025-09-01T06:30:21.443860Z  INFO raft_poc::raft::integration_tests::integration_tests: ✅ Network partition recovery test completed
[INFO] [stdout] test raft::integration_tests::integration_tests::test_network_partition_recovery ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 48 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 10.48s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "610992f1b8064d3c7cf94e7fb339ab7a05d599c26b64b61d9a84b48dfefc2a7e", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "610992f1b8064d3c7cf94e7fb339ab7a05d599c26b64b61d9a84b48dfefc2a7e", kill_on_drop: false }`
[INFO] [stdout] 610992f1b8064d3c7cf94e7fb339ab7a05d599c26b64b61d9a84b48dfefc2a7e