search

JDRaftKeeper / RaftKeeper

RaftKeeper is a high-performance distributed consensus service.
Apache License 2.0
141 stars 37 forks source link

RaftKeeper cluster configuration on a single machine #18

Closed Hooollin closed 1 year ago

Hooollin commented 1 year ago

System: MacOS Ventura 13.2.1 Build Version: the lastest commit bf5f6c1

I built RaftKeeper on my machine following the instruction in README. Then I modified the configuration file conf/config.xml to set up a 3 nodes Raft cluster:

<?xml version="1.0"?>
<raftkeeper>
    <!-- System timezone, default is empty, will use OS default timezone. -->
    <!-- <timezone></timezone>-->
    <logger>
        <!-- Valid values are: fatal, error, warning, information, debug, trace -->
        <!-- <level>information</level> -->
        <!-- Logger file path, default is empty string. If is empty string will not log to file -->
        <path>./log/raftkeeper.log</path>
        <!-- Error logger file path, default is empty string. If is empty string will not log to file -->
        <err_log_path>./log/raftkeeper.err.log</err_log_path>
        <!-- Log file size limit, when reached will create another file, default is 100M. -->
        <!-- <size>100M</size> -->
        <!-- How many log file to keep, default is 10. -->
        <!-- <count>10</count> -->
        <!-- Whether compress log, default is true. -->
        <!-- <compress>true</compress> -->
        <!-- Whether print log to console, default is false-->
        <!-- <log_to_console>false</log_to_console> -->
    </logger>

    <!-- <core_dump> -->
        <!-- 1 GiB by default. If more - it writes to disk too long. -->
        <!-- <size_limit>1073741824</size_limit> -->
    <!-- </core_dump> -->

    <keeper>
        <!-- My id in cluster. -->
        <my_id>1</my_id>

        <!-- Binging host, default is "0.0.0.0." -->
        <!-- <host>0.0.0.0</host> -->

        <!-- Port for user request and 4lw command -->
        <!-- <port>8101</port> -->

        <!-- Port for follower forward write request and session info to leader. -->
        <!-- <forwarding_port>8102</forwarding_port> -->

        <!-- Port for Raft internal usage: heartbeat, log replicate, leader selection etc. -->
        <!-- <internal_port>8103</internal_port> -->

        <!-- Raft log store directory -->
        <log_dir>./data/log</log_dir>

        <!-- Raft snapshot store directory -->
        <snapshot_dir>./data/snapshot</snapshot_dir>

        <!-- Max snapshot interval in second. -->
        <!-- <snapshot_create_interval>3600</snapshot_create_interval> -->

        <!-- Processor thread count, default is 16. -->
        <!-- <thread_count>16</thread_count> -->

        <!-- 4lwd command white list, default "conf,cons,crst,envi,ruok,srst,srvr,stat,wchs,dirs,mntr,isro,lgif,rqld" -->
        <!-- <four_letter_word_white_list></four_letter_word_white_list> -->

        <!-- Super digest for root user, default is empty string.
            See https://zookeeper.apache.org/doc/r3.5.2-alpha/zookeeperAdmin.html  -->
        <!-- <super_digest></super_digest> -->

        <!-- NuRaft related settings -->
        <raft_settings>
            <!-- User session timeout in millisecond, default is 30000. -->
            <!-- <session_timeout_ms>30000</session_timeout_ms> -->

            <!-- User operation timeout in millisecond, default is 20000. -->
            <!-- <operation_timeout_ms>20000</operation_timeout_ms> -->

            <!-- Leader will check whether session is dead in this period, default is 1000. -->
            <!-- <dead_session_check_period_ms>100</dead_session_check_period_ms> -->

            <!-- NuRaft heart beat interval in millisecond, default is 500. -->
            <!-- <heart_beat_interval_ms>500</heart_beat_interval_ms> -->

            <!-- NuRaft election timeout lower bound, default is 10s. -->
            <!-- <election_timeout_lower_bound_ms>10000</election_timeout_lower_bound_ms> -->

            <!-- NuRaft election timeout upper bound, default is 20s. -->
            <!-- <election_timeout_upper_bound_ms>20000</election_timeout_upper_bound_ms> -->

            <!-- Keeper will keep at least this log item, default 1_000_000. -->
            <!-- <reserved_log_items>1000000</reserved_log_items> -->

            <!-- Create snapshot in this log size, default is 3_000_000. -->
            <!-- <snapshot_distance>3000000</snapshot_distance> -->

            <!-- How many snapshot to keep, default is 5. -->
            <!-- <max_stored_snapshots>5</max_stored_snapshots> -->

            <!-- Startup time in millisecond, default is 6000000ms. Because will load data, should set to a big value. -->
            <!-- <startup_timeout>6000000</startup_timeout> -->

            <!-- Shutdown time in millisecond, default is 5000ms. -->
            <!-- <shutdown_timeout>5000</shutdown_timeout> -->

            <!-- NuRaft log level, default is information. -->
            <!-- <raft_logs_level>information</raft_logs_level> -->

            <!-- NuRaft thread pool size, default is 32. -->
            <!-- <nuraft_thread_size>32</nuraft_thread_size> -->

            <!-- Log gap (compared to the leader's latest log) for treating this node as fresh, default is 200. -->
            <!-- <fresh_log_gap>200</fresh_log_gap> -->

            <!-- Auto update configuration retry times, default is 30. -->
            <!-- <configuration_change_tries_count>30</configuration_change_tries_count> -->

            <!-- NuRaft append entries max batch size, default is 1000. -->
            <!-- <max_batch_size>1000</max_batch_size> -->

            <!-- Raft log fsync mode:
                    fsync_parallel : The leader can do log replication and log persisting in parallel,
                        thus it can reduce the latency of write operation path. In this mode data is safety.
                    fsync : The leader and follower do log persisting synchronously. In this mode data is safety.
                    fsync_batch : The leader and follower do log persisting asynchronously and in batch.
                        In this mode data is less safety.
            -->
            <!-- <log_fsync_mode>fsync_parallel</log_fsync_mode> -->

            <!-- If log_fsync_mode is fsync_batch, will fsync log after x appending entries, default value is 1000. -->
            <!-- <log_fsync_interval>1000</log_fsync_interval> -->
        </raft_settings>

        <!-- If you want a RaftKeeper cluster, you can uncomment this and configure it carefully -->
        <cluster>
            <server>
                <id>1</id>
                <host>127.0.0.1</host>
                <!-- <internal_port>8103</internal_port> -->
                <!-- <forwarding_port>8102</forwarding_port> -->
                <!-- `true` if this node is learner. Learner will not initiate or participate in leader election. -->
                <!-- <learner>false</learner> -->
                <!-- Priority of this server, default is 1 and if is 0 the server will never be leader. -->
                <!-- <priority>1</priority> -->
            </server>
            <server>
                <id>2</id>
                <host>127.0.0.1</host>
            </server>
            <server>
                <id>3</id>
                <host>127.0.0.1</host>
            </server>
        </cluster>
    </keeper>
</raftkeeper>

With that configuration and I run RaftKeeper with command ./lib/raftkeeper server --config=conf/config.xml, got the logs below:

2023.03.24 02:56:29.806859 [ 2836175 ] {} <Information> : Starting RaftKeeper v2.0.1, no build id, PID 35071
2023.03.24 02:56:29.914603 [ 2836175 ] {} <Information> LogSegmentStore: Create LogSegmentStore ./data/log.
2023.03.24 02:56:29.914748 [ 2836175 ] {} <Information> LogSegmentStore: Begin init log segment store, max log size 1048576000 bytes, max segment count 50.
2023.03.24 02:56:29.916808 [ 2836175 ] {} <Information> LogSegment: Created new segment ./data/log/log_1_open_20230324025629, seg_fd 7, first index 1
2023.03.24 02:56:29.917013 [ 2836175 ] {} <Information> FileLogStore: Init file log store, last log index 0, log dir ./data/log
2023.03.24 02:56:29.917144 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102
2023.03.24 02:56:29.917217 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 0, 0x10a154018
2023.03.24 02:56:29.917256 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 1, 0x10a1541d8
2023.03.24 02:56:29.917289 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 2, 0x10a154398
2023.03.24 02:56:29.917322 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 3, 0x10a154558
2023.03.24 02:56:29.917355 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 4, 0x10a154718
2023.03.24 02:56:29.917387 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 5, 0x10a1548d8
2023.03.24 02:56:29.917551 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 6, 0x10a154a98
2023.03.24 02:56:29.917640 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 7, 0x10a154c58
2023.03.24 02:56:29.917688 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 8, 0x10a154e18
2023.03.24 02:56:29.917772 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 9, 0x10a154fd8
2023.03.24 02:56:29.917815 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 10, 0x10a155198
2023.03.24 02:56:29.918262 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 11, 0x10a155358
2023.03.24 02:56:29.918348 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 12, 0x10a155518
2023.03.24 02:56:29.918385 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 13, 0x10a1556d8
2023.03.24 02:56:29.918417 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 14, 0x10a155898
2023.03.24 02:56:29.918449 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 15, 0x10a155a58
2023.03.24 02:56:29.918537 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102
2023.03.24 02:56:29.918583 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 0, 0x10a155c18
2023.03.24 02:56:29.918616 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 1, 0x10a155dd8
2023.03.24 02:56:29.918653 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 2, 0x10a155f98
2023.03.24 02:56:29.918687 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 3, 0x10a156158
2023.03.24 02:56:29.918719 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 4, 0x10a156318
2023.03.24 02:56:29.918751 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 5, 0x10a1564d8
2023.03.24 02:56:29.918852 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 6, 0x10a156698
2023.03.24 02:56:29.918880 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 7, 0x10a156858
2023.03.24 02:56:29.919076 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 8, 0x10a156a18
2023.03.24 02:56:29.919154 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 9, 0x10a156bd8
2023.03.24 02:56:29.919186 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 10, 0x10a156d98
2023.03.24 02:56:29.919237 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 11, 0x10a156f58
2023.03.24 02:56:29.919268 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 12, 0x10a157118
2023.03.24 02:56:29.919326 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 13, 0x10a1572d8
2023.03.24 02:56:29.919349 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 14, 0x10a157498
2023.03.24 02:56:29.919374 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 15, 0x10a157658
2023.03.24 02:56:29.919397 [ 2836175 ] {} <Information> NuRaftStateManager: raft cluster config :  127.0.0.1:8103 127.0.0.1:8103 127.0.0.1:8103
2023.03.24 02:56:29.919628 [ 2836175 ] {} <Information> KeeperStateMachine: begin init state machine, snapshot directory ./data/snapshot
2023.03.24 02:56:29.920045 [ 2836175 ] {} <Information> RaftTaskManager: Open task for task, fd 8, path ./data/snapshot/committed.task
2023.03.24 02:56:29.920127 [ 2836175 ] {} <Warning> RaftTaskManager: Read last committed index failed -1
2023.03.24 02:56:29.920322 [ 2836201 ] {} <Information> RaftTaskManager: try schedule, shut down false
2023.03.24 02:56:29.920464 [ 2836175 ] {} <Information> KeeperSnapshotManager: Skip no snapshot file committed.task
2023.03.24 02:56:29.920503 [ 2836175 ] {} <Information> KeeperSnapshotManager: Load snapshot metas 0 from snapshot directory ./data/snapshot
2023.03.24 02:56:29.920529 [ 2836175 ] {} <Information> KeeperSnapshotManager: Get last snapshot, snapshot size 0
2023.03.24 02:56:29.920551 [ 2836175 ] {} <Information> KeeperStateMachine: Load snapshot meta size 0, last log index 0 in snapshot
2023.03.24 02:56:29.920580 [ 2836175 ] {} <Information> KeeperStateMachine: Begin replay log, first log index 1 and last log index 0 in log file ( prev index 0, log index 0 )
2023.03.24 02:56:29.920719 [ 2836175 ] {} <Information> KeeperStateMachine: Apply log done, ephemeral sessions 0 nodes 0
2023.03.24 02:56:29.920881 [ 2836175 ] {} <Information> KeeperStateMachine: Replay last committed index 0 in log store
2023.03.24 02:56:29.920958 [ 2836175 ] {} <Information> KeeperStateMachine: Starting background creating snapshot thread.
2023.03.24 02:56:29.921993 [ 2836175 ] {} <Information> NuRaft: Raft ASIO listener initiated, UNSECURED
2023.03.24 02:56:29.922135 [ 2836175 ] {} <Warning> NuRaftStateManager: Raft srv_state file not exist, maybe this is the first startup.
2023.03.24 02:56:29.922204 [ 2836175 ] {} <Information> NuRaftStateManager: load config with initial cluster config.
2023.03.24 02:56:29.922232 [ 2836175 ] {} <Information> KeeperStateMachine: last_snapshot invoke
2023.03.24 02:56:29.922256 [ 2836175 ] {} <Information> KeeperSnapshotManager: Get last snapshot, snapshot size 0
2023.03.24 02:56:29.922292 [ 2836175 ] {} <Information> NuRaft: parameters: timeout 10000 - 20000, heartbeat 500, leadership expiry 10000, max batch 100, backoff 50, snapshot distance 3000000, enable randomized snapshot creation NO, log sync stop gap 99999, reserved logs 1000000, client timeout 20000, auto forwarding ON, API call type BLOCKING, custom commit quorum size 0, custom election quorum size 0, snapshot receiver INCLUDED, leadership transfer wait time 0, grace period of lagging state machine 0, snapshot IO: BLOCKING, parallel log appending: ON
2023.03.24 02:56:29.922349 [ 2836175 ] {} <Information> NuRaft: new timeout range: 10000 -- 20000
2023.03.24 02:56:29.922385 [ 2836175 ] {} <Information> NuRaft:    === INIT RAFT SERVER ===
commit index 0
term 0
election timer allowed
log store start 1, end 0
config log idx 0, prev log idx 0
2023.03.24 02:56:29.922453 [ 2836175 ] {} <Information> NuRaft: peer 1: DC ID 0, 127.0.0.1:8103, voting member, 1
peer 2: DC ID 0, 127.0.0.1:8103, voting member, 1
peer 3: DC ID 0, 127.0.0.1:8103, voting member, 1
my id: 1, voting_member
num peers: 2
2023.03.24 02:56:29.922483 [ 2836175 ] {} <Information> NuRaft: global manager does not exist. will use local thread for commit and append
2023.03.24 02:56:29.922563 [ 2836175 ] {} <Information> NuRaft: wait for HB, for 50 + [10000, 20000] ms
2023.03.24 02:56:29.922924 [ 2836236 ] {} <Information> NuRaft: bg append_entries thread initiated
2023.03.24 02:56:48.868253 [ 2836203 ] {} <Warning> NuRaft: Election timeout, initiate leader election
2023.03.24 02:56:48.868621 [ 2836203 ] {} <Information> NuRaft: [PRIORITY] decay, target 1 -> 1, mine 1
2023.03.24 02:56:48.868767 [ 2836203 ] {} <Information> NuRaft: [ELECTION TIMEOUT] current role: follower, log last term 0, state term 0, target p 1, my p 1, hb dead, pre-vote NOT done
2023.03.24 02:56:48.868882 [ 2836203 ] {} <Information> NuRaft: [PRE-VOTE INIT] my id 1, my role candidate, term 0, log idx 0, log term 0, priority (target 1 / mine 1)
2023.03.24 02:56:48.872425 [ 2836205 ] {} <Information> NuRaft: 0x108ff0f18 connected to 127.0.0.1:8103 (as a client)
2023.03.24 02:56:48.872691 [ 2836209 ] {} <Information> NuRaft: 0x108ff0d98 connected to 127.0.0.1:8103 (as a client)
2023.03.24 02:56:48.872968 [ 2836211 ] {} <Information> NuRaft: receive a incoming rpc connection
2023.03.24 02:56:48.873312 [ 2836211 ] {} <Information> NuRaft: session 1 got connection from 127.0.0.1:56195 (as a server)
2023.03.24 02:56:48.873502 [ 2836211 ] {} <Information> NuRaft: receive a incoming rpc connection
2023.03.24 02:56:48.873588 [ 2836211 ] {} <Information> NuRaft: session 2 got connection from 127.0.0.1:56194 (as a server)
2023.03.24 02:56:48.873852 [ 2836214 ] {} <Information> NuRaft: [PRE-VOTE REQ] my role candidate, from peer 1, log term: req 0 / mine 0
last idx: req 0 / mine 0, term: req 0 / mine 0
HB dead
2023.03.24 02:56:48.874075 [ 2836214 ] {} <Information> NuRaft: pre-vote decision: O (grant)
2023.03.24 02:56:48.874449 [ 2836216 ] {} <Information> NuRaft: [PRE-VOTE REQ] my role candidate, from peer 1, log term: req 0 / mine 0
last idx: req 0 / mine 0, term: req 0 / mine 0
HB dead
2023.03.24 02:56:48.874617 [ 2836216 ] {} <Information> NuRaft: pre-vote decision: O (grant)
2023.03.24 02:56:48.874854 [ 2836210 ] {} <Information> NuRaft: [PRE-VOTE RESP] peer 1 (O), term 0, resp term 0, my role candidate, dead 2, live 0, abandoned 0, num voting members 3, quorum 2
2023.03.24 02:56:48.875092 [ 2836210 ] {} <Information> NuRaft: [PRE-VOTE DONE] SUCCESS, term 0
2023.03.24 02:56:48.875158 [ 2836210 ] {} <Information> NuRaft: [PRE-VOTE DONE] initiate actual vote
2023.03.24 02:56:48.875774 [ 2836210 ] {} <Information> NuRaftStateManager: save srv_state with term 1 and vote_for 1
2023.03.24 02:56:48.875842 [ 2836210 ] {} <Information> NuRaft: [VOTE INIT] my id 1, my role candidate, term 1, log idx 0, log term 0, priority (target 1 / mine 1)
2023.03.24 02:56:48.876186 [ 2836219 ] {} <Information> NuRaft: [PRE-VOTE RESP] peer 1 (O), term 0, resp term 0, my role candidate, dead 3, live 0, abandoned 0, num voting members 3, quorum 2
2023.03.24 02:56:48.876394 [ 2836219 ] {} <Information> NuRaft: [PRE-VOTE DONE] SUCCESS, term 0
2023.03.24 02:56:48.876487 [ 2836219 ] {} <Information> NuRaft: [PRE-VOTE DONE] actual vote is already initiated, do nothing
2023.03.24 02:56:48.876777 [ 2836225 ] {} <Information> NuRaft: [VOTE REQ] my role candidate, from peer 1, log term: req 0 / mine 0
last idx: req 0 / mine 0, term: req 1 / mine 1
priority: target 1 / mine 1, voted_for 1
2023.03.24 02:56:48.877009 [ 2836225 ] {} <Information> NuRaft: decision: O (grant), voted_for 1, term 1
2023.03.24 02:56:48.877643 [ 2836225 ] {} <Information> NuRaftStateManager: save srv_state with term 1 and vote_for 1
2023.03.24 02:56:48.877916 [ 2836220 ] {} <Information> NuRaft: [VOTE REQ] my role candidate, from peer 1, log term: req 0 / mine 0
last idx: req 0 / mine 0, term: req 1 / mine 1
priority: target 1 / mine 1, voted_for 1
2023.03.24 02:56:48.878016 [ 2836220 ] {} <Information> NuRaft: decision: O (grant), voted_for 1, term 1
2023.03.24 02:56:48.878363 [ 2836220 ] {} <Information> NuRaftStateManager: save srv_state with term 1 and vote_for 1
2023.03.24 02:56:48.878579 [ 2836226 ] {} <Information> NuRaft: [VOTE RESP] peer 1 (O), resp term 1, my role candidate, granted 2, responded 2, num voting members 3, quorum 2
2023.03.24 02:56:48.878686 [ 2836226 ] {} <Information> NuRaft: Server is elected as leader for term 1
2023.03.24 02:56:48.878764 [ 2836226 ] {} <Information> NuRaft: number of pending commit elements: 0
2023.03.24 02:56:48.878801 [ 2836226 ] {} <Information> NuRaft: state machine commit index 0, precommit index 0, last log index 0
2023.03.24 02:56:48.878901 [ 2836226 ] {} <Information> NuRaft: [BECOME LEADER] appended new config at 1
2023.03.24 02:56:48.879411 [ 2836226 ] {} <Information> NuRaft:   === LEADER (term 1) ===
2023.03.24 02:56:48.879552 [ 2836228 ] {} <Information> NuRaft: Election completed, will ignore the voting result from this server
2023.03.24 02:56:48.880097 [ 2836204 ] {} <Warning> NuRaft: Receive AppendEntriesRequest from another leader (1) with same term, there must be a bug. Ignore it instead of exit.
2023.03.24 02:56:48.880311 [ 2836204 ] {} <Warning> NuRaft: no response is returned from raft message handler
2023.03.24 02:56:48.880517 [ 2836229 ] {} <Warning> NuRaft: Receive AppendEntriesRequest from another leader (1) with same term, there must be a bug. Ignore it instead of exit.
2023.03.24 02:56:48.880820 [ 2836229 ] {} <Warning> NuRaft: no response is returned from raft message handler
2023.03.24 02:56:48.881062 [ 2836203 ] {} <Warning> NuRaft: peer (2) response error: failed to read response to peer 2, 127.0.0.1:8103, error 2, End of file
2023.03.24 02:56:48.881765 [ 2836213 ] {} <Warning> NuRaft: peer (3) response error: failed to read response to peer 3, 127.0.0.1:8103, error 2, End of file
2023.03.24 02:56:48.883992 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102
2023.03.24 02:56:48.884147 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 0, 0x10a154018
2023.03.24 02:56:48.884199 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 1, 0x10a1541d8
2023.03.24 02:56:48.884232 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 2, 0x10a154398
2023.03.24 02:56:48.884260 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 3, 0x10a154558
2023.03.24 02:56:48.884531 [ 2836565 ] {} <Information> KeeperDispatcher: start session clear task
2023.03.24 02:56:48.884681 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 4, 0x10a154718
2023.03.24 02:56:48.884737 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 5, 0x10a1548d8
2023.03.24 02:56:48.884758 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 6, 0x10a154a98
2023.03.24 02:56:48.884779 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 7, 0x10a154c58
2023.03.24 02:56:48.884799 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 8, 0x10a154e18
2023.03.24 02:56:48.884847 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 9, 0x10a154fd8
2023.03.24 02:56:48.884867 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 10, 0x10a155198
2023.03.24 02:56:48.884885 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 11, 0x10a155358
2023.03.24 02:56:48.885017 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 12, 0x10a155518
2023.03.24 02:56:48.885062 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 13, 0x10a1556d8
2023.03.24 02:56:48.885088 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 14, 0x10a155898
2023.03.24 02:56:48.885125 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 15, 0x10a155a58
2023.03.24 02:56:48.885171 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102
2023.03.24 02:56:48.885201 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 0, 0x10a155c18
2023.03.24 02:56:48.885231 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 1, 0x10a155dd8
2023.03.24 02:56:48.885261 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 2, 0x10a155f98
2023.03.24 02:56:48.885290 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 3, 0x10a156158
2023.03.24 02:56:48.885461 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 4, 0x10a156318
2023.03.24 02:56:48.885499 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 5, 0x10a1564d8
2023.03.24 02:56:48.885519 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 6, 0x10a156698
2023.03.24 02:56:48.885538 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 7, 0x10a156858
2023.03.24 02:56:48.885557 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 8, 0x10a156a18
2023.03.24 02:56:48.885646 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 9, 0x10a156bd8
2023.03.24 02:56:48.885684 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 10, 0x10a156d98
2023.03.24 02:56:48.885714 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 11, 0x10a156f58
2023.03.24 02:56:48.885735 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 12, 0x10a157118
2023.03.24 02:56:48.885824 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 13, 0x10a1572d8
2023.03.24 02:56:48.885868 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 14, 0x10a157498
2023.03.24 02:56:48.885898 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 15, 0x10a157658
2023.03.24 02:56:48.885923 [ 2836175 ] {} <Information> NuRaftStateManager: raft cluster config :  127.0.0.1:8103 127.0.0.1:8103 127.0.0.1:8103
2023.03.24 02:56:48.885971 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command ruok
2023.03.24 02:56:48.886006 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command mntr
2023.03.24 02:56:48.886036 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command conf
2023.03.24 02:56:48.886101 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command cons
2023.03.24 02:56:48.886132 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command wchs
2023.03.24 02:56:48.886171 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command dirs
2023.03.24 02:56:48.886201 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command dump
2023.03.24 02:56:48.886230 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command envi
2023.03.24 02:56:48.886257 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command isro
2023.03.24 02:56:48.886284 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command crst
2023.03.24 02:56:48.886372 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command srvr
2023.03.24 02:56:48.886405 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command stat
2023.03.24 02:56:48.886431 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command srst
2023.03.24 02:56:48.886455 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command wchp
2023.03.24 02:56:48.886473 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command wchc
2023.03.24 02:56:48.886492 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command csnp
2023.03.24 02:56:48.886510 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command lgif
2023.03.24 02:56:48.886528 [ 2836175 ] {} <Information> FourLetterCommandFactory: Register four letter command rqld
2023.03.24 02:56:48.887211 [ 2836175 ] {} <Information> Application: Listening for user connections on 0.0.0.0:8101
2023.03.24 02:56:48.887800 [ 2836175 ] {} <Information> Application: Listening for forwarding connections on 0.0.0.0:8102
2023.03.24 02:56:48.892659 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102
2023.03.24 02:56:48.892759 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 0, 0x10a154018
2023.03.24 02:56:48.892811 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 1, 0x10a1541d8
2023.03.24 02:56:48.892830 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 2, 0x10a154398
2023.03.24 02:56:48.892847 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 3, 0x10a154558
2023.03.24 02:56:48.892863 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 4, 0x10a154718
2023.03.24 02:56:48.892944 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 5, 0x10a1548d8
2023.03.24 02:56:48.892985 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 6, 0x10a154a98
2023.03.24 02:56:48.893008 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 7, 0x10a154c58
2023.03.24 02:56:48.893026 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 8, 0x10a154e18
2023.03.24 02:56:48.893043 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 9, 0x10a154fd8
2023.03.24 02:56:48.893350 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 10, 0x10a155198
2023.03.24 02:56:48.893389 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 11, 0x10a155358
2023.03.24 02:56:48.893407 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 12, 0x10a155518
2023.03.24 02:56:48.893425 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 13, 0x10a1556d8
2023.03.24 02:56:48.893478 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 14, 0x10a155898
2023.03.24 02:56:48.893495 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 2, 127.0.0.1:8102, thread 15, 0x10a155a58
2023.03.24 02:56:48.893526 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102
2023.03.24 02:56:48.893545 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 0, 0x10a155c18
2023.03.24 02:56:48.893561 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 1, 0x10a155dd8
2023.03.24 02:56:48.893577 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 2, 0x10a155f98
2023.03.24 02:56:48.893592 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 3, 0x10a156158
2023.03.24 02:56:48.893609 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 4, 0x10a156318
2023.03.24 02:56:48.893905 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 5, 0x10a1564d8
2023.03.24 02:56:48.893958 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 6, 0x10a156698
2023.03.24 02:56:48.893990 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 7, 0x10a156858
2023.03.24 02:56:48.894015 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 8, 0x10a156a18
2023.03.24 02:56:48.894045 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 9, 0x10a156bd8
2023.03.24 02:56:48.894180 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 10, 0x10a156d98
2023.03.24 02:56:48.894234 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 11, 0x10a156f58
2023.03.24 02:56:48.894264 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 12, 0x10a157118
2023.03.24 02:56:48.894284 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 13, 0x10a1572d8
2023.03.24 02:56:48.894475 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 14, 0x10a157498
2023.03.24 02:56:48.894520 [ 2836175 ] {} <Information> NuRaftStateManager: Create ForwardingConnection for 3, 127.0.0.1:8102, thread 15, 0x10a157658
2023.03.24 02:56:48.894542 [ 2836175 ] {} <Information> NuRaftStateManager: raft cluster config :  127.0.0.1:8103 127.0.0.1:8103 127.0.0.1:8103
2023.03.24 02:56:48.895306 [ 2836175 ] {} <Information> Application: RaftKeeper started!
2023.03.24 02:56:49.380312 [ 2836205 ] {} <Error> NuRaft: 2 nodes (out of 3, 3 including learners) are not responding longer than 10000 ms, at least 2 nodes (including leader) should be alive to proceed commit
2023.03.24 02:56:49.380554 [ 2836205 ] {} <Error> NuRaft: will yield the leadership of this node
2023.03.24 02:56:49.380652 [ 2836205 ] {} <Information> NuRaft: got immediate re-elect request, resign now
2023.03.24 02:56:49.380711 [ 2836205 ] {} <Information> NuRaft: [BECOME FOLLOWER] term 1
2023.03.24 02:57:02.777243 [ 2836209 ] {} <Warning> NuRaft: Election timeout, initiate leader election
2023.03.24 02:57:02.777575 [ 2836209 ] {} <Information> NuRaft: [PRIORITY] decay, target 1 -> 1, mine 1
2023.03.24 02:57:02.777650 [ 2836209 ] {} <Information> NuRaft: [ELECTION TIMEOUT] current role: follower, log last term 1, state term 1, target p 1, my p 1, hb dead, pre-vote done
2023.03.24 02:57:02.777751 [ 2836209 ] {} <Information> NuRaft: pre-vote term (0) is different, reset it to 1
2023.03.24 02:57:02.777945 [ 2836209 ] {} <Information> NuRaft: reset RPC client for peer 3
2023.03.24 02:57:02.778021 [ 2836209 ] {} <Information> NuRaft: reset RPC client for peer 2
2023.03.24 02:57:02.778086 [ 2836209 ] {} <Information> NuRaft: [PRE-VOTE INIT] my id 1, my role candidate, term 1, log idx 1, log term 1, priority (target 1 / mine 1)
2023.03.24 02:57:02.779086 [ 2836214 ] {} <Information> NuRaft: 0x10baf1198 connected to 127.0.0.1:8103 (as a client)
2023.03.24 02:57:02.779289 [ 2836216 ] {} <Information> NuRaft: receive a incoming rpc connection
2023.03.24 02:57:02.779572 [ 2836215 ] {} <Information> NuRaft: 0x10baf1018 connected to 127.0.0.1:8103 (as a client)
2023.03.24 02:57:02.779808 [ 2836216 ] {} <Information> NuRaft: session 3 got connection from 127.0.0.1:56231 (as a server)
2023.03.24 02:57:02.780257 [ 2836216 ] {} <Information> NuRaft: receive a incoming rpc connection
2023.03.24 02:57:02.780443 [ 2836216 ] {} <Information> NuRaft: session 4 got connection from 127.0.0.1:56232 (as a server)
2023.03.24 02:57:02.780538 [ 2836221 ] {} <Information> NuRaft: [PRE-VOTE REQ] my role candidate, from peer 1, log term: req 1 / mine 1
last idx: req 1 / mine 1, term: req 1 / mine 1
HB dead
2023.03.24 02:57:02.780838 [ 2836221 ] {} <Information> NuRaft: pre-vote decision: O (grant)
2023.03.24 02:57:02.781200 [ 2836227 ] {} <Information> NuRaft: [PRE-VOTE REQ] my role candidate, from peer 1, log term: req 1 / mine 1
last idx: req 1 / mine 1, term: req 1 / mine 1
HB dead
2023.03.24 02:57:02.781514 [ 2836227 ] {} <Information> NuRaft: pre-vote decision: O (grant)
2023.03.24 02:57:02.781712 [ 2836214 ] {} <Information> NuRaft: [PRE-VOTE RESP] peer 1 (O), term 1, resp term 1, my role candidate, dead 2, live 0, abandoned 0, num voting members 3, quorum 2
2023.03.24 02:57:02.781841 [ 2836214 ] {} <Information> NuRaft: [PRE-VOTE DONE] SUCCESS, term 1
2023.03.24 02:57:02.781892 [ 2836214 ] {} <Information> NuRaft: [PRE-VOTE DONE] initiate actual vote
2023.03.24 02:57:02.782531 [ 2836214 ] {} <Information> NuRaftStateManager: save srv_state with term 2 and vote_for 1
2023.03.24 02:57:02.782598 [ 2836214 ] {} <Information> NuRaft: [VOTE INIT] my id 1, my role candidate, term 2, log idx 1, log term 1, priority (target 1 / mine 1)
2023.03.24 02:57:02.782855 [ 2836230 ] {} <Information> NuRaft: [PRE-VOTE RESP] peer 1 (O), term 1, resp term 1, my role candidate, dead 3, live 0, abandoned 0, num voting members 3, quorum 2
2023.03.24 02:57:02.783007 [ 2836230 ] {} <Information> NuRaft: [PRE-VOTE DONE] SUCCESS, term 1
2023.03.24 02:57:02.783056 [ 2836230 ] {} <Information> NuRaft: [PRE-VOTE DONE] actual vote is already initiated, do nothing
2023.03.24 02:57:02.783182 [ 2836206 ] {} <Information> NuRaft: [VOTE REQ] my role candidate, from peer 1, log term: req 1 / mine 1
last idx: req 1 / mine 1, term: req 2 / mine 2
priority: target 1 / mine 1, voted_for 1
2023.03.24 02:57:02.783352 [ 2836206 ] {} <Information> NuRaft: decision: O (grant), voted_for 1, term 2
2023.03.24 02:57:02.784033 [ 2836206 ] {} <Information> NuRaftStateManager: save srv_state with term 2 and vote_for 1
2023.03.24 02:57:02.784347 [ 2836234 ] {} <Information> NuRaft: [VOTE REQ] my role candidate, from peer 1, log term: req 1 / mine 1
last idx: req 1 / mine 1, term: req 2 / mine 2
priority: target 1 / mine 1, voted_for 1
2023.03.24 02:57:02.784493 [ 2836234 ] {} <Information> NuRaft: decision: O (grant), voted_for 1, term 2
2023.03.24 02:57:02.785071 [ 2836234 ] {} <Information> NuRaftStateManager: save srv_state with term 2 and vote_for 1
2023.03.24 02:57:02.785358 [ 2836207 ] {} <Information> NuRaft: [VOTE RESP] peer 1 (O), resp term 2, my role candidate, granted 2, responded 2, num voting members 3, quorum 2
2023.03.24 02:57:02.785504 [ 2836207 ] {} <Information> NuRaft: Server is elected as leader for term 2
2023.03.24 02:57:02.785567 [ 2836207 ] {} <Information> NuRaft: number of pending commit elements: 0
2023.03.24 02:57:02.785609 [ 2836207 ] {} <Information> NuRaft: state machine commit index 0, precommit index 1, last log index 1
2023.03.24 02:57:02.785763 [ 2836207 ] {} <Information> NuRaft: found uncommitted config at 1, size 112
2023.03.24 02:57:02.785826 [ 2836207 ] {} <Information> NuRaft: [BECOME LEADER] appended new config at 2
2023.03.24 02:57:02.786372 [ 2836207 ] {} <Information> NuRaft:   === LEADER (term 2) ===
2023.03.24 02:57:02.786486 [ 2836207 ] {} <Warning> NuRaft: Receive AppendEntriesRequest from another leader (1) with same term, there must be a bug. Ignore it instead of exit.
2023.03.24 02:57:02.786585 [ 2836207 ] {} <Warning> NuRaft: no response is returned from raft message handler
2023.03.24 02:57:02.786668 [ 2836213 ] {} <Warning> NuRaft: Receive AppendEntriesRequest from another leader (1) with same term, there must be a bug. Ignore it instead of exit.
2023.03.24 02:57:02.786824 [ 2836229 ] {} <Information> NuRaft: Election completed, will ignore the voting result from this server
2023.03.24 02:57:02.786969 [ 2836213 ] {} <Warning> NuRaft: no response is returned from raft message handler
2023.03.24 02:57:02.787115 [ 2836217 ] {} <Warning> NuRaft: peer (3) response error: failed to read response to peer 3, 127.0.0.1:8103, error 2, End of file
2023.03.24 02:57:02.787410 [ 2836222 ] {} <Warning> NuRaft: peer (2) response error: failed to read response to peer 2, 127.0.0.1:8103, error 2, End of file
2023.03.24 02:57:03.287074 [ 2836219 ] {} <Error> NuRaft: 2 nodes (out of 3, 3 including learners) are not responding longer than 10000 ms, at least 2 nodes (including leader) should be alive to proceed commit
2023.03.24 02:57:03.287236 [ 2836219 ] {} <Error> NuRaft: will yield the leadership of this node
2023.03.24 02:57:03.287287 [ 2836219 ] {} <Information> NuRaft: got immediate re-elect request, resign now
2023.03.24 02:57:03.287318 [ 2836219 ] {} <Information> NuRaft: [BECOME FOLLOWER] term 2
2023.03.24 02:57:18.602044 [ 2836225 ] {} <Warning> NuRaft: Election timeout, initiate leader election
2023.03.24 02:57:18.602360 [ 2836225 ] {} <Information> NuRaft: [PRIORITY] decay, target 1 -> 1, mine 1
2023.03.24 02:57:18.602388 [ 2836225 ] {} <Information> NuRaft: [ELECTION TIMEOUT] current role: follower, log last term 2, state term 2, target p 1, my p 1, hb dead, pre-vote done
2023.03.24 02:57:18.602439 [ 2836225 ] {} <Information> NuRaft: pre-vote term (1) is different, reset it to 2
2023.03.24 02:57:18.602467 [ 2836225 ] {} <Information> NuRaft: reset RPC client for peer 3
2023.03.24 02:57:18.602491 [ 2836225 ] {} <Information> NuRaft: reset RPC client for peer 2
2023.03.24 02:57:18.602514 [ 2836225 ] {} <Information> NuRaft: [PRE-VOTE INIT] my id 1, my role candidate, term 2, log idx 2, log term 2, priority (target 1 / mine 1)
2023.03.24 02:57:18.603561 [ 2836221 ] {} <Information> NuRaft: 0x10d2a2018 connected to 127.0.0.1:8103 (as a client)
2023.03.24 02:57:18.603720 [ 2836214 ] {} <Information> NuRaft: receive a incoming rpc connection
2023.03.24 02:57:18.603833 [ 2836228 ] {} <Information> NuRaft: 0x10d2a2198 connected to 127.0.0.1:8103 (as a client)
2023.03.24 02:57:18.604073 [ 2836214 ] {} <Information> NuRaft: session 5 got connection from 127.0.0.1:56269 (as a server)
2023.03.24 02:57:18.604259 [ 2836226 ] {} <Information> NuRaft: [PRE-VOTE REQ] my role candidate, from peer 1, log term: req 2 / mine 2
last idx: req 2 / mine 2, term: req 2 / mine 2
HB dead
2023.03.24 02:57:18.604393 [ 2836226 ] {} <Information> NuRaft: pre-vote decision: O (grant)
2023.03.24 02:57:18.604460 [ 2836214 ] {} <Information> NuRaft: receive a incoming rpc connection
2023.03.24 02:57:18.604554 [ 2836214 ] {} <Information> NuRaft: session 6 got connection from 127.0.0.1:56270 (as a server)
2023.03.24 02:57:18.604663 [ 2836233 ] {} <Information> NuRaft: [PRE-VOTE RESP] peer 1 (O), term 2, resp term 2, my role candidate, dead 2, live 0, abandoned 0, num voting members 3, quorum 2
2023.03.24 02:57:18.604754 [ 2836233 ] {} <Information> NuRaft: [PRE-VOTE DONE] SUCCESS, term 2
2023.03.24 02:57:18.604784 [ 2836233 ] {} <Information> NuRaft: [PRE-VOTE DONE] initiate actual vote
2023.03.24 02:57:18.605431 [ 2836233 ] {} <Information> NuRaftStateManager: save srv_state with term 3 and vote_for 1
2023.03.24 02:57:18.605560 [ 2836233 ] {} <Information> NuRaft: [VOTE INIT] my id 1, my role candidate, term 3, log idx 2, log term 2, priority (target 1 / mine 1)
2023.03.24 02:57:18.605705 [ 2836233 ] {} <Warning> NuRaft: failed to send vote request: peer 2 (127.0.0.1:8103) is busy
2023.03.24 02:57:18.605869 [ 2836214 ] {} <Information> NuRaft: [PRE-VOTE REQ] my role candidate, from peer 1, log term: req 2 / mine 2
last idx: req 2 / mine 2, term: req 2 / mine 3
HB dead
2023.03.24 02:57:18.605950 [ 2836214 ] {} <Information> NuRaft: pre-vote decision: O (grant)
2023.03.24 02:57:18.606024 [ 2836206 ] {} <Information> NuRaft: [VOTE REQ] my role candidate, from peer 1, log term: req 2 / mine 2
last idx: req 2 / mine 2, term: req 3 / mine 3
priority: target 1 / mine 1, voted_for 1
2023.03.24 02:57:18.606085 [ 2836206 ] {} <Information> NuRaft: decision: O (grant), voted_for 1, term 3
2023.03.24 02:57:18.606459 [ 2836206 ] {} <Information> NuRaftStateManager: save srv_state with term 3 and vote_for 1
2023.03.24 02:57:18.606540 [ 2836205 ] {} <Information> NuRaft: [PRE-VOTE RESP] peer 1 (O), term 2, resp term 2, my role candidate, dead 3, live 0, abandoned 0, num voting members 3, quorum 2
2023.03.24 02:57:18.606600 [ 2836205 ] {} <Information> NuRaft: [PRE-VOTE DONE] SUCCESS, term 2
2023.03.24 02:57:18.606622 [ 2836205 ] {} <Information> NuRaft: [PRE-VOTE DONE] actual vote is already initiated, do nothing
2023.03.24 02:57:18.606759 [ 2836211 ] {} <Information> NuRaft: [VOTE RESP] peer 1 (O), resp term 3, my role candidate, granted 2, responded 2, num voting members 3, quorum 2
2023.03.24 02:57:18.606809 [ 2836211 ] {} <Information> NuRaft: Server is elected as leader for term 3
2023.03.24 02:57:18.606836 [ 2836211 ] {} <Information> NuRaft: number of pending commit elements: 0
2023.03.24 02:57:18.606857 [ 2836211 ] {} <Information> NuRaft: state machine commit index 0, precommit index 2, last log index 2
2023.03.24 02:57:18.606889 [ 2836211 ] {} <Information> NuRaft: found uncommitted config at 1, size 112
2023.03.24 02:57:18.606945 [ 2836211 ] {} <Information> NuRaft: found uncommitted config at 2, size 112
2023.03.24 02:57:18.607033 [ 2836211 ] {} <Information> NuRaft: [BECOME LEADER] appended new config at 3
2023.03.24 02:57:18.607445 [ 2836211 ] {} <Information> NuRaft:   === LEADER (term 3) ===
2023.03.24 02:57:18.607616 [ 2836207 ] {} <Warning> NuRaft: Receive AppendEntriesRequest from another leader (1) with same term, there must be a bug. Ignore it instead of exit.
2023.03.24 02:57:18.607679 [ 2836207 ] {} <Warning> NuRaft: no response is returned from raft message handler
2023.03.24 02:57:18.607728 [ 2836224 ] {} <Warning> NuRaft: Receive AppendEntriesRequest from another leader (1) with same term, there must be a bug. Ignore it instead of exit.
2023.03.24 02:57:18.607863 [ 2836224 ] {} <Warning> NuRaft: no response is returned from raft message handler
2023.03.24 02:57:18.608018 [ 2836213 ] {} <Warning> NuRaft: peer (2) response error: failed to read response to peer 2, 127.0.0.1:8103, error 2, End of file
2023.03.24 02:57:18.608200 [ 2836215 ] {} <Warning> NuRaft: peer (3) response error: failed to read response to peer 3, 127.0.0.1:8103, error 2, End of file
2023.03.24 02:57:19.108176 [ 2836225 ] {} <Error> NuRaft: 2 nodes (out of 3, 3 including learners) are not responding longer than 10000 ms, at least 2 nodes (including leader) should be alive to proceed commit
2023.03.24 02:57:19.108486 [ 2836225 ] {} <Error> NuRaft: will yield the leadership of this node
2023.03.24 02:57:19.108568 [ 2836225 ] {} <Information> NuRaft: got immediate re-elect request, resign now
2023.03.24 02:57:19.108620 [ 2836225 ] {} <Information> NuRaft: [BECOME FOLLOWER] term 3
2023.03.24 02:57:34.068779 [ 2836227 ] {} <Warning> NuRaft: Election timeout, initiate leader election
2023.03.24 02:57:34.069064 [ 2836227 ] {} <Information> NuRaft: [PRIORITY] decay, target 1 -> 1, mine 1
2023.03.24 02:57:34.069137 [ 2836227 ] {} <Information> NuRaft: [ELECTION TIMEOUT] current role: follower, log last term 3, state term 3, target p 1, my p 1, hb dead, pre-vote done
2023.03.24 02:57:34.069300 [ 2836227 ] {} <Information> NuRaft: pre-vote term (2) is different, reset it to 3
2023.03.24 02:57:34.069357 [ 2836227 ] {} <Information> NuRaft: reset RPC client for peer 3
2023.03.24 02:57:34.069411 [ 2836227 ] {} <Information> NuRaft: reset RPC client for peer 2
2023.03.24 02:57:34.069465 [ 2836227 ] {} <Information> NuRaft: [PRE-VOTE INIT] my id 1, my role candidate, term 3, log idx 3, log term 3, priority (target 1 / mine 1)
2023.03.24 02:57:34.070591 [ 2836220 ] {} <Information> NuRaft: 0x10f209198 connected to 127.0.0.1:8103 (as a client)
2023.03.24 02:57:34.070789 [ 2836228 ] {} <Information> NuRaft: 0x10f209018 connected to 127.0.0.1:8103 (as a client)
2023.03.24 02:57:34.070943 [ 2836230 ] {} <Information> NuRaft: receive a incoming rpc connection
2023.03.24 02:57:34.071057 [ 2836230 ] {} <Information> NuRaft: session 7 got connection from 127.0.0.1:56309 (as a server)
2023.03.24 02:57:34.071271 [ 2836234 ] {} <Information> NuRaft: [PRE-VOTE REQ] my role candidate, from peer 1, log term: req 3 / mine 3
last idx: req 3 / mine 3, term: req 3 / mine 3
HB dead
2023.03.24 02:57:34.071452 [ 2836234 ] {} <Information> NuRaft: pre-vote decision: O (grant)
2023.03.24 02:57:34.071574 [ 2836230 ] {} <Information> NuRaft: receive a incoming rpc connection
2023.03.24 02:57:34.071738 [ 2836230 ] {} <Information> NuRaft: session 8 got connection from 127.0.0.1:56310 (as a server)
2023.03.24 02:57:34.071829 [ 2836226 ] {} <Information> NuRaft: [PRE-VOTE RESP] peer 1 (O), term 3, resp term 3, my role candidate, dead 2, live 0, abandoned 0, num voting members 3, quorum 2
2023.03.24 02:57:34.071968 [ 2836226 ] {} <Information> NuRaft: [PRE-VOTE DONE] SUCCESS, term 3
2023.03.24 02:57:34.072015 [ 2836226 ] {} <Information> NuRaft: [PRE-VOTE DONE] initiate actual vote
2023.03.24 02:57:34.073311 [ 2836226 ] {} <Information> NuRaftStateManager: save srv_state with term 4 and vote_for 1
2023.03.24 02:57:34.073424 [ 2836226 ] {} <Information> NuRaft: [VOTE INIT] my id 1, my role candidate, term 4, log idx 3, log term 3, priority (target 1 / mine 1)
2023.03.24 02:57:34.073463 [ 2836226 ] {} <Warning> NuRaft: failed to send vote request: peer 3 (127.0.0.1:8103) is busy
2023.03.24 02:57:34.073671 [ 2836209 ] {} <Information> NuRaft: [PRE-VOTE REQ] my role candidate, from peer 1, log term: req 3 / mine 3
last idx: req 3 / mine 3, term: req 3 / mine 4
HB dead
2023.03.24 02:57:34.073801 [ 2836209 ] {} <Information> NuRaft: pre-vote decision: O (grant)
2023.03.24 02:57:34.073890 [ 2836214 ] {} <Information> NuRaft: [VOTE REQ] my role candidate, from peer 1, log term: req 3 / mine 3
last idx: req 3 / mine 3, term: req 4 / mine 4
priority: target 1 / mine 1, voted_for 1
2023.03.24 02:57:34.073970 [ 2836214 ] {} <Information> NuRaft: decision: O (grant), voted_for 1, term 4
2023.03.24 02:57:34.074643 [ 2836214 ] {} <Information> NuRaftStateManager: save srv_state with term 4 and vote_for 1
2023.03.24 02:57:34.074800 [ 2836206 ] {} <Information> NuRaft: [PRE-VOTE RESP] peer 1 (O), term 3, resp term 3, my role candidate, dead 3, live 0, abandoned 0, num voting members 3, quorum 2
2023.03.24 02:57:34.074908 [ 2836206 ] {} <Information> NuRaft: [PRE-VOTE DONE] SUCCESS, term 3
2023.03.24 02:57:34.074956 [ 2836206 ] {} <Information> NuRaft: [PRE-VOTE DONE] actual vote is already initiated, do nothing
2023.03.24 02:57:34.075027 [ 2836229 ] {} <Information> NuRaft: [VOTE RESP] peer 1 (O), resp term 4, my role candidate, granted 2, responded 2, num voting members 3, quorum 2
2023.03.24 02:57:34.075118 [ 2836229 ] {} <Information> NuRaft: Server is elected as leader for term 4
2023.03.24 02:57:34.075182 [ 2836229 ] {} <Information> NuRaft: number of pending commit elements: 0
2023.03.24 02:57:34.075268 [ 2836229 ] {} <Information> NuRaft: state machine commit index 0, precommit index 3, last log index 3
2023.03.24 02:57:34.075344 [ 2836229 ] {} <Information> NuRaft: found uncommitted config at 1, size 112
2023.03.24 02:57:34.075395 [ 2836229 ] {} <Information> NuRaft: found uncommitted config at 2, size 112
2023.03.24 02:57:34.075498 [ 2836229 ] {} <Information> NuRaft: found uncommitted config at 3, size 112
2023.03.24 02:57:34.075545 [ 2836229 ] {} <Information> NuRaft: [BECOME LEADER] appended new config at 4
2023.03.24 02:57:34.076051 [ 2836229 ] {} <Information> NuRaft:   === LEADER (term 4) ===
2023.03.24 02:57:34.076222 [ 2836222 ] {} <Warning> NuRaft: Receive AppendEntriesRequest from another leader (1) with same term, there must be a bug. Ignore it instead of exit.
2023.03.24 02:57:34.076338 [ 2836222 ] {} <Warning> NuRaft: no response is returned from raft message handler
2023.03.24 02:57:34.076400 [ 2836215 ] {} <Warning> NuRaft: Receive AppendEntriesRequest from another leader (1) with same term, there must be a bug. Ignore it instead of exit.
2023.03.24 02:57:34.076535 [ 2836215 ] {} <Warning> NuRaft: no response is returned from raft message handler
2023.03.24 02:57:34.076692 [ 2836213 ] {} <Warning> NuRaft: peer (2) response error: failed to read response to peer 2, 127.0.0.1:8103, error 2, End of file
2023.03.24 02:57:34.076884 [ 2836227 ] {} <Warning> NuRaft: peer (3) response error: failed to read response to peer 3, 127.0.0.1:8103, error 2, End of file
2023.03.24 02:57:34.576686 [ 2836232 ] {} <Error> NuRaft: 2 nodes (out of 3, 3 including learners) are not responding longer than 10000 ms, at least 2 nodes (including leader) should be alive to proceed commit
2023.03.24 02:57:34.577036 [ 2836232 ] {} <Error> NuRaft: will yield the leadership of this node
2023.03.24 02:57:34.577131 [ 2836232 ] {} <Information> NuRaft: got immediate re-elect request, resign now
2023.03.24 02:57:34.577189 [ 2836232 ] {} <Information> NuRaft: [BECOME FOLLOWER] term 4
2023.03.24 02:57:52.469107 [ 2836221 ] {} <Warning> NuRaft: Election timeout, initiate leader election
2023.03.24 02:57:52.469208 [ 2836221 ] {} <Information> NuRaft: [PRIORITY] decay, target 1 -> 1, mine 1
2023.03.24 02:57:52.469235 [ 2836221 ] {} <Information> NuRaft: [ELECTION TIMEOUT] current role: follower, log last term 4, state term 4, target p 1, my p 1, hb dead, pre-vote done
2023.03.24 02:57:52.469278 [ 2836221 ] {} <Information> NuRaft: pre-vote term (3) is different, reset it to 4
2023.03.24 02:57:52.469300 [ 2836221 ] {} <Information> NuRaft: reset RPC client for peer 3
2023.03.24 02:57:52.469324 [ 2836221 ] {} <Information> NuRaft: reset RPC client for peer 2
2023.03.24 02:57:52.471454 [ 2836221 ] {} <Information> NuRaft: [PRE-VOTE INIT] my id 1, my role candidate, term 4, log idx 4, log term 4, priority (target 1 / mine 1)
2023.03.24 02:57:52.472534 [ 2836220 ] {} <Information> NuRaft: 0x10f1d8018 connected to 127.0.0.1:8103 (as a client)
2023.03.24 02:57:52.472651 [ 2836234 ] {} <Information> NuRaft: receive a incoming rpc connection
2023.03.24 02:57:52.472743 [ 2836218 ] {} <Information> NuRaft: 0x10f1d8198 connected to 127.0.0.1:8103 (as a client)
2023.03.24 02:57:52.472861 [ 2836234 ] {} <Information> NuRaft: session 9 got connection from 127.0.0.1:56356 (as a server)
2023.03.24 02:57:52.472972 [ 2836234 ] {} <Information> NuRaft: receive a incoming rpc connection
2023.03.24 02:57:52.473016 [ 2836234 ] {} <Information> NuRaft: session 10 got connection from 127.0.0.1:56357 (as a server)
2023.03.24 02:57:52.473103 [ 2836233 ] {} <Information> NuRaft: [PRE-VOTE REQ] my role candidate, from peer 1, log term: req 4 / mine 4
last idx: req 4 / mine 4, term: req 4 / mine 4
HB dead
2023.03.24 02:57:52.473183 [ 2836233 ] {} <Information> NuRaft: pre-vote decision: O (grant)
2023.03.24 02:57:52.473274 [ 2836234 ] {} <Information> NuRaft: [PRE-VOTE REQ] my role candidate, from peer 1, log term: req 4 / mine 4
last idx: req 4 / mine 4, term: req 4 / mine 4
HB dead
2023.03.24 02:57:52.473313 [ 2836234 ] {} <Information> NuRaft: pre-vote decision: O (grant)
2023.03.24 02:57:52.473386 [ 2836210 ] {} <Information> NuRaft: [PRE-VOTE RESP] peer 1 (O), term 4, resp term 4, my role candidate, dead 2, live 0, abandoned 0, num voting members 3, quorum 2
2023.03.24 02:57:52.473433 [ 2836210 ] {} <Information> NuRaft: [PRE-VOTE DONE] SUCCESS, term 4
2023.03.24 02:57:52.473478 [ 2836210 ] {} <Information> NuRaft: [PRE-VOTE DONE] initiate actual vote
2023.03.24 02:57:52.473952 [ 2836210 ] {} <Information> NuRaftStateManager: save srv_state with term 5 and vote_for 1
2023.03.24 02:57:52.474018 [ 2836210 ] {} <Information> NuRaft: [VOTE INIT] my id 1, my role candidate, term 5, log idx 4, log term 4, priority (target 1 / mine 1)
2023.03.24 02:57:52.474228 [ 2836212 ] {} <Information> NuRaft: [PRE-VOTE RESP] peer 1 (O), term 4, resp term 4, my role candidate, dead 3, live 0, abandoned 0, num voting members 3, quorum 2
2023.03.24 02:57:52.474323 [ 2836212 ] {} <Information> NuRaft: [PRE-VOTE DONE] SUCCESS, term 4
2023.03.24 02:57:52.474350 [ 2836212 ] {} <Information> NuRaft: [PRE-VOTE DONE] actual vote is already initiated, do nothing
2023.03.24 02:57:52.475191 [ 2836214 ] {} <Information> NuRaft: [VOTE REQ] my role candidate, from peer 1, log term: req 4 / mine 4
last idx: req 4 / mine 4, term: req 5 / mine 5
priority: target 1 / mine 1, voted_for 1
2023.03.24 02:57:52.475247 [ 2836214 ] {} <Information> NuRaft: decision: O (grant), voted_for 1, term 5
2023.03.24 02:57:52.475506 [ 2836214 ] {} <Information> NuRaftStateManager: save srv_state with term 5 and vote_for 1
2023.03.24 02:57:52.475615 [ 2836219 ] {} <Information> NuRaft: [VOTE REQ] my role candidate, from peer 1, log term: req 4 / mine 4
last idx: req 4 / mine 4, term: req 5 / mine 5
priority: target 1 / mine 1, voted_for 1
2023.03.24 02:57:52.475720 [ 2836219 ] {} <Information> NuRaft: decision: O (grant), voted_for 1, term 5
2023.03.24 02:57:52.476071 [ 2836219 ] {} <Information> NuRaftStateManager: save srv_state with term 5 and vote_for 1
2023.03.24 02:57:52.476170 [ 2836207 ] {} <Information> NuRaft: [VOTE RESP] peer 1 (O), resp term 5, my role candidate, granted 2, responded 2, num voting members 3, quorum 2
2023.03.24 02:57:52.476222 [ 2836207 ] {} <Information> NuRaft: Server is elected as leader for term 5
2023.03.24 02:57:52.476248 [ 2836207 ] {} <Information> NuRaft: number of pending commit elements: 0
2023.03.24 02:57:52.476265 [ 2836207 ] {} <Information> NuRaft: state machine commit index 0, precommit index 4, last log index 4
2023.03.24 02:57:52.476292 [ 2836207 ] {} <Information> NuRaft: found uncommitted config at 1, size 112
2023.03.24 02:57:52.476313 [ 2836207 ] {} <Information> NuRaft: found uncommitted config at 2, size 112
2023.03.24 02:57:52.476333 [ 2836207 ] {} <Information> NuRaft: found uncommitted config at 3, size 112
2023.03.24 02:57:52.476349 [ 2836207 ] {} <Information> NuRaft: found uncommitted config at 4, size 112
2023.03.24 02:57:52.476371 [ 2836207 ] {} <Information> NuRaft: [BECOME LEADER] appended new config at 5
2023.03.24 02:57:52.476837 [ 2836207 ] {} <Information> NuRaft:   === LEADER (term 5) ===
2023.03.24 02:57:52.476916 [ 2836225 ] {} <Information> NuRaft: Election completed, will ignore the voting result from this server
2023.03.24 02:57:52.477027 [ 2836221 ] {} <Warning> NuRaft: Receive AppendEntriesRequest from another leader (1) with same term, there must be a bug. Ignore it instead of exit.
2023.03.24 02:57:52.477091 [ 2836221 ] {} <Warning> NuRaft: no response is returned from raft message handler
2023.03.24 02:57:52.477162 [ 2836208 ] {} <Warning> NuRaft: Receive AppendEntriesRequest from another leader (1) with same term, there must be a bug. Ignore it instead of exit.
2023.03.24 02:57:52.477244 [ 2836208 ] {} <Warning> NuRaft: no response is returned from raft message handler
2023.03.24 02:57:52.477327 [ 2836207 ] {} <Warning> NuRaft: peer (3) response error: failed to read response to peer 3, 127.0.0.1:8103, error 2, End of file
2023.03.24 02:57:52.477533 [ 2836204 ] {} <Warning> NuRaft: peer (2) response error: failed to read response to peer 2, 127.0.0.1:8103, error 2, End of file
2023.03.24 02:57:52.977313 [ 2836230 ] {} <Error> NuRaft: 2 nodes (out of 3, 3 including learners) are not responding longer than 10000 ms, at least 2 nodes (including leader) should be alive to proceed commit
2023.03.24 02:57:52.977531 [ 2836230 ] {} <Error> NuRaft: will yield the leadership of this node
2023.03.24 02:57:52.977837 [ 2836230 ] {} <Information> NuRaft: got immediate re-elect request, resign now
2023.03.24 02:57:52.977884 [ 2836230 ] {} <Information> NuRaft: [BECOME FOLLOWER] term 5
2023.03.24 02:58:06.312654 [ 2836220 ] {} <Warning> NuRaft: Election timeout, initiate leader election
2023.03.24 02:58:06.312941 [ 2836220 ] {} <Information> NuRaft: [PRIORITY] decay, target 1 -> 1, mine 1
2023.03.24 02:58:06.313020 [ 2836220 ] {} <Information> NuRaft: [ELECTION TIMEOUT] current role: follower, log last term 5, state term 5, target p 1, my p 1, hb dead, pre-vote done
2023.03.24 02:58:06.313147 [ 2836220 ] {} <Information> NuRaft: pre-vote term (4) is different, reset it to 5
2023.03.24 02:58:06.313226 [ 2836220 ] {} <Information> NuRaft: reset RPC client for peer 3
2023.03.24 02:58:06.313320 [ 2836220 ] {} <Information> NuRaft: reset RPC client for peer 2
2023.03.24 02:58:06.313395 [ 2836220 ] {} <Information> NuRaft: [PRE-VOTE INIT] my id 1, my role candidate, term 5, log idx 5, log term 5, priority (target 1 / mine 1)
2023.03.24 02:58:06.314632 [ 2836223 ] {} <Information> NuRaft: 0x10d2e4198 connected to 127.0.0.1:8103 (as a client)
2023.03.24 02:58:06.314985 [ 2836234 ] {} <Information> NuRaft: 0x10d2e4018 connected to 127.0.0.1:8103 (as a client)
2023.03.24 02:58:06.315265 [ 2836217 ] {} <Information> NuRaft: receive a incoming rpc connection
2023.03.24 02:58:06.315467 [ 2836217 ] {} <Information> NuRaft: session 11 got connection from 127.0.0.1:56393 (as a server)
2023.03.24 02:58:06.315673 [ 2836210 ] {} <Information> NuRaft: receive a incoming rpc connection
2023.03.24 02:58:06.315983 [ 2836217 ] {} <Information> NuRaft: [PRE-VOTE REQ] my role candidate, from peer 1, log term: req 5 / mine 5
last idx: req 5 / mine 5, term: req 5 / mine 5
HB dead
2023.03.24 02:58:06.316239 [ 2836217 ] {} <Information> NuRaft: pre-vote decision: O (grant)
2023.03.24 02:58:06.316621 [ 2836210 ] {} <Information> NuRaft: session 12 got connection from 127.0.0.1:56394 (as a server)
2023.03.24 02:58:06.316810 [ 2836211 ] {} <Information> NuRaft: [PRE-VOTE RESP] peer 1 (O), term 5, resp term 5, my role candidate, dead 2, live 0, abandoned 0, num voting members 3, quorum 2
2023.03.24 02:58:06.316953 [ 2836211 ] {} <Information> NuRaft: [PRE-VOTE DONE] SUCCESS, term 5
2023.03.24 02:58:06.317018 [ 2836211 ] {} <Information> NuRaft: [PRE-VOTE DONE] initiate actual vote
2023.03.24 02:58:06.317835 [ 2836211 ] {} <Information> NuRaftStateManager: save srv_state with term 6 and vote_for 1
2023.03.24 02:58:06.317921 [ 2836211 ] {} <Information> NuRaft: [VOTE INIT] my id 1, my role candidate, term 6, log idx 5, log term 5, priority (target 1 / mine 1)
2023.03.24 02:58:06.317962 [ 2836211 ] {} <Warning> NuRaft: failed to send vote request: peer 3 (127.0.0.1:8103) is busy
2023.03.24 02:58:06.318314 [ 2836231 ] {} <Information> NuRaft: [PRE-VOTE REQ] my role candidate, from peer 1, log term: req 5 / mine 5
last idx: req 5 / mine 5, term: req 5 / mine 6
HB dead
2023.03.24 02:58:06.318465 [ 2836231 ] {} <Information> NuRaft: pre-vote decision: O (grant)
2023.03.24 02:58:06.318569 [ 2836229 ] {} <Information> NuRaft: [VOTE REQ] my role candidate, from peer 1, log term: req 5 / mine 5
last idx: req 5 / mine 5, term: req 6 / mine 6
priority: target 1 / mine 1, voted_for 1
2
...

It seems that the Raft cluster has failed to maintain heartbeats, resulting in re-elections.

Has this situation occurred before? If it is confirmed to be a reproducible situation, I am willing to participate in resolving it.

nicelulu commented 1 year ago

Looks like it's due to 3 nodes using the same internal_port. If you deploy three instances on one node, you need to use different port, forwarding_port, internal_port.

And use a configuration similar to the following in :

        <cluster>
            <server>
                <id>1</id>
                <host>127.0.0.1</host>
                <internal_port>8103</internal_port>
                <forwarding_port>8102</forwarding_port>
            </server>
            <server>
                <id>2</id>
                <host>127.0.0.1</host>
                <internal_port>8113</internal_port>
                <forwarding_port>8112</forwarding_port>
            </server>
            <server>
                <id>3</id>
                <host>127.0.0.1</host>
                <internal_port>8123</internal_port>
                <forwarding_port>8122</forwarding_port>
            </server>
        </cluster>
Hooollin commented 1 year ago

How can I deploy a 3-node RaftKeeper cluster on a single machine? After setting different ports for the nodes, I tried to modify the my_id field in config.xml and start 3 instances of RaftKeeper in 3 different folders, but encountered port conflict issues. Before starting the 3 instances, I used pgrep and kill to terminate all the previous RaftKeeper instances, making sure the availability of the ports to be used in the 3 instance.

nicelulu commented 1 year ago

You can use:

./raftkeeper server --config-file ./config1.xml
./raftkeeper server --config-file ./config2.xml
./raftkeeper server --config-file ./config3.xml

Different port internal_port forwarding_port and my_id are specified in config1.xml, config2.xml, and config3.xml.

Please pull the latest code to 9c10ee24534b21f0d17d1906ebae41646446779b. Fixed some issues.

Hooollin commented 1 year ago

After configuring three different config.xml files, I successfully started the service in cluster mode. There are two issues keeps me from successfully starting the RaftKeeper service.

My three config.xml files are as follows (For those who may run into the same problems):

config1.xml:

<?xml version="1.0"?>
<raftkeeper>
    <logger>
        <!-- Logger file path, default is empty string. If is empty string will not log to file -->
        <path>./node1/log/raftkeeper.log</path>
        <!-- Error logger file path, default is empty string. If is empty string will not log to file -->
        <err_log_path>./node1/log/raftkeeper.err.log</err_log_path>
    </logger>

    <keeper>
        <!-- My id in cluster. -->
        <my_id>1</my_id>

        <!-- Bing(d, maybe it's a typo)ing host, default is "0.0.0.0." -->
        <host>127.0.0.1</host>

        <!-- Port for user request and 4lw command -->
        <port>8101</port>

        <!-- Port for follower forward write request and session info to leader. -->
        <forwarding_port>8102</forwarding_port>

        <!-- Port for Raft internal usage: heartbeat, log replicate, leader selection etc. -->
         <internal_port>8103</internal_port>

        <!-- Raft log store directory -->
        <log_dir>./node1/data/log</log_dir>

        <!-- Raft snapshot store directory -->
        <snapshot_dir>./node1/data/snapshot</snapshot_dir>

        <!-- If you want a RaftKeeper cluster, you can uncomment this and configure it carefully -->
        <cluster>
            <server>
                <id>1</id>
                <host>127.0.0.1</host>
                <forwarding_port>8102</forwarding_port>
                <internal_port>8103</internal_port> 
                <!-- `true` if this node is learner. Learner will not initiate or participate in leader election. -->
                <!-- <learner>false</learner> -->
                <!-- Priority of this server, default is 1 and if is 0 the server will never be leader. -->
                <!-- <priority>1</priority> -->
            </server>
            <server>
                <id>2</id>
                <host>127.0.0.1</host>
                <forwarding_port>8112</forwarding_port>
                <internal_port>8113</internal_port> 
            </server>
            <server>
                <id>3</id>
                <host>127.0.0.1</host>
                <forwarding_port>8122</forwarding_port>
                <internal_port>8123</internal_port> 
            </server>
        </cluster>
    </keeper>
</raftkeeper>

----------------------------------------------------------
config2.xml:

<?xml version="1.0"?>
<raftkeeper>
    <logger>
        <!-- Logger file path, default is empty string. If is empty string will not log to file -->
        <path>./node2/log/raftkeeper.log</path>
        <!-- Error logger file path, default is empty string. If is empty string will not log to file -->
        <err_log_path>./node2/log/raftkeeper.err.log</err_log_path>
    </logger>

    <keeper>
        <!-- My id in cluster. -->
        <my_id>2</my_id>

        <!-- Bing(d)ing host, default is "0.0.0.0." -->
        <host>127.0.0.1</host>

        <!-- Port for user request and 4lw command -->
        <port>8111</port>

        <!-- Port for follower forward write request and session info to leader. -->
        <forwarding_port>8112</forwarding_port>

        <!-- Port for Raft internal usage: heartbeat, log replicate, leader selection etc. -->
         <internal_port>8113</internal_port>

        <!-- Raft log store directory -->
        <log_dir>./node2/data/log</log_dir>

        <!-- Raft snapshot store directory -->
        <snapshot_dir>./node2/data/snapshot</snapshot_dir>

        <!-- If you want a RaftKeeper cluster, you can uncomment this and configure it carefully -->
        <cluster>
           same as cluster in config1.xml
        </cluster>
    </keeper>
</raftkeeper>

----------------------------------------------------------
config3.xml:

<?xml version="1.0"?>
<raftkeeper>
    <logger>
        <!-- Logger file path, default is empty string. If is empty string will not log to file -->
        <path>./node3/log/raftkeeper.log</path>
        <!-- Error logger file path, default is empty string. If is empty string will not log to file -->
        <err_log_path>./node3/log/raftkeeper.err.log</err_log_path>
    </logger>

    <keeper>
        <!-- My id in cluster. -->
        <my_id>3</my_id>

        <!-- Binging host, default is "0.0.0.0." -->
        <host>127.0.0.1</host>

        <!-- Port for user request and 4lw command -->
        <port>8121</port>

        <!-- Port for follower forward write request and session info to leader. -->
        <forwarding_port>8122</forwarding_port>

        <!-- Port for Raft internal usage: heartbeat, log replicate, leader selection etc. -->
         <internal_port>8123</internal_port>

        <!-- Raft log store directory -->
        <log_dir>./node3/data/log</log_dir>

        <!-- Raft snapshot store directory -->
        <snapshot_dir>./node3/data/snapshot</snapshot_dir>

        <!-- If you want a RaftKeeper cluster, you can uncomment this and configure it carefully -->
        <cluster>
           same as cluster in config1.xml
        </cluster>
    </keeper>
</raftkeeper>
JackyWoo commented 1 year ago

@Hooollin Thanks for your recording.

  1. You run 3 nodes in one server, you should use separated log dir and data dir. I edit the config.xml in your last post.
  2. If you run intto NPE too with the correct configuration, please create a new issue for the bug.
Hooollin commented 1 year ago

It works fine now. I believe the NPE is due to the same data/ directory I used in these 3 nodes. Thanks a lot!

JackyWoo commented 1 year ago

RaftKeeper is new in github. We appreciate any contributions for docs and code and we have some easy tasks for beginners, if you are interesting see #22 .