From 730a130cfb9951f602e8bb5e9d185c192b7f65e2 Mon Sep 17 00:00:00 2001 From: Joshua Zhang Date: Mon, 16 Oct 2023 13:21:09 +0800 Subject: [PATCH] 1. raft TLA spec with etcd implementation 2. etcd TLA trace validation --- raft.go | 21 ++ state_trace.go | 226 ++++++++++++ tla/Traceetcdraft.cfg | 49 +++ tla/Traceetcdraft.tla | 325 +++++++++++++++++ tla/etcdraft.cfg | 5 - tla/etcdraft.tla | 454 ++++++++--------------- tla/example.ndjson | 700 ++++++++++++++++++++++++++++++++++++ tla/trace-preprocess-log.sh | 4 + 8 files changed, 1484 insertions(+), 300 deletions(-) create mode 100644 state_trace.go create mode 100644 tla/Traceetcdraft.cfg create mode 100644 tla/Traceetcdraft.tla create mode 100644 tla/example.ndjson create mode 100755 tla/trace-preprocess-log.sh diff --git a/raft.go b/raft.go index 8691662..008f4be 100644 --- a/raft.go +++ b/raft.go @@ -578,11 +578,14 @@ func (r *raft) send(m pb.Message) { // we err on the side of safety and omit a `&& !m.Reject` condition // above. r.msgsAfterAppend = append(r.msgsAfterAppend, m) + traceSendMessage(r, &m) + } else { if m.To == r.id { r.logger.Panicf("message should not be self-addressed when sending %s", m.Type) } r.msgs = append(r.msgs, m) + traceSendMessage(r, &m) } } @@ -753,6 +756,8 @@ func (r *raft) appliedSnap(snap *pb.Snapshot) { // the commit index changed (in which case the caller should call // r.bcastAppend). func (r *raft) maybeCommit() bool { + traceNodeEvent(RsmCommit, r) + mci := r.prs.Committed() return r.raftLog.maybeCommit(mci, r.Term) } @@ -868,6 +873,8 @@ func (r *raft) becomeFollower(term uint64, lead uint64) { r.lead = lead r.state = StateFollower r.logger.Infof("%x became follower at term %d", r.id, r.Term) + + traceNodeEvent(RsmBecomeFollower, r) } func (r *raft) becomeCandidate() { @@ -875,12 +882,15 @@ func (r *raft) becomeCandidate() { if r.state == StateLeader { panic("invalid transition [leader -> candidate]") } + r.step = stepCandidate r.reset(r.Term + 1) r.tick = r.tickElection r.Vote = r.id r.state = StateCandidate r.logger.Infof("%x became candidate at term %d", r.id, r.Term) + + traceNodeEvent(RsmBecomeCandidate, r) } func (r *raft) becomePreCandidate() { @@ -904,6 +914,7 @@ func (r *raft) becomeLeader() { if r.state == StateFollower { panic("invalid transition [follower -> leader]") } + r.step = stepLeader r.reset(r.Term) r.tick = r.tickHeartbeat @@ -926,6 +937,8 @@ func (r *raft) becomeLeader() { // could be expensive. r.pendingConfIndex = r.raftLog.lastIndex() + traceNodeEvent(RsmBecomeLeader, r) + emptyEnt := pb.Entry{Data: nil} if !r.appendEntry(emptyEnt) { // This won't happen because we just called reset() above. @@ -1049,6 +1062,8 @@ func (r *raft) poll(id uint64, t pb.MessageType, v bool) (granted int, rejected } func (r *raft) Step(m pb.Message) error { + traceReceiveMessage(r, &m) + // Handle the message term, which may result in our stepping down to a follower. switch { case m.Term == 0: @@ -1273,6 +1288,8 @@ func stepLeader(r *raft, m pb.Message) error { cc = ccc } if cc != nil { + traceChangeConfEvent(cc, r) + alreadyPending := r.pendingConfIndex > r.raftLog.applied alreadyJoint := len(r.prs.Config.Voters[1]) > 0 wantsLeaveJoint := len(cc.AsV2().Changes) == 0 @@ -1292,6 +1309,8 @@ func stepLeader(r *raft, m pb.Message) error { } else { r.pendingConfIndex = r.raftLog.lastIndex() + uint64(i) + 1 } + } else { + traceNodeEvent(RsmReplicate, r) } } @@ -1915,6 +1934,8 @@ func (r *raft) applyConfChange(cc pb.ConfChangeV2) pb.ConfState { // // The inputs usually result from restoring a ConfState or applying a ConfChange. func (r *raft) switchToConfig(cfg tracker.Config, prs tracker.ProgressMap) pb.ConfState { + traceConfChangeEvent(cfg, r) + r.prs.Config = cfg r.prs.Progress = prs diff --git a/state_trace.go b/state_trace.go new file mode 100644 index 0000000..0474903 --- /dev/null +++ b/state_trace.go @@ -0,0 +1,226 @@ +package raft + +import ( + "go.etcd.io/raft/v3/raftpb" + "go.etcd.io/raft/v3/tracker" +) + +type RaftStateMachineEventType int + +const ( + RsmInitState RaftStateMachineEventType = iota + RsmBecomeCandidate + RsmBecomeFollower + RsmBecomeLeader + RsmCommit + RsmReplicate + RsmChangeConf + RsmApplyConfChange + RsmSendAppendEntriesRequest + RsmReceiveAppendEntriesRequest + RsmSendAppendEntriesResponse + RsmReceiveAppendEntriesResponse + RsmSendRequestVoteRequest + RsmReceiveRequestVoteRequest + RsmSendRequestVoteResponse + RsmReceiveRequestVoteResponse +) + +func (e RaftStateMachineEventType) String() string { + return []string{ + "InitState", + "BecomeCandidate", + "BecomeFollower", + "BecomeLeader", + "Commit", + "Replicate", + "ChangeConf", + "ApplyConfChange", + "SendAppendEntriesRequest", + "ReceiveAppendEntriesRequest", + "SendAppendEntriesResponse", + "ReceiveAppendEntriesResponse", + "SendRequestVoteRequest", + "ReceiveRequestVoteRequest", + "SendRequestVoteResponse", + "ReceiveRequestVoteResponse", + }[e] +} + +const ( + ConfChangeAddNewServer string = "AddNewServer" + ConfChangeRemoveServer string = "RemoveServer" +) + +type TracingEvent struct { + Name string `json:"name"` + NodeID uint64 `json:"nid"` + State raftpb.HardState `json:"state"` + Role string `json:"role"` + Conf [2][]uint64 `json:"conf"` + Message *TracingMessage `json:"msg,omitempty"` + ConfChange *TracingConfChange `json:"cc,omitempty"` +} + +type TracingMessage struct { + Type string `json:"type"` + Term uint64 `json:"term"` + From uint64 `json:"from"` + To uint64 `json:"to"` + EntryLength int `json:"entries"` + LogTerm uint64 `json:"logTerm"` + Index uint64 `json:"index"` + Commit uint64 `json:"commit"` + Vote uint64 `json:"vote"` + Reject bool `json:"reject"` + RejectHint uint64 `json:"rejectHint"` +} + +type SingleConfChange struct { + NodeId uint64 `json:"nid"` + Action string `json:"action"` +} + +type TracingConfChange struct { + Changes []SingleConfChange `json:"changes,omitempty"` + NewConf []uint64 `json:"newconf,omitempty"` +} + +func makeTracingMessage(m *raftpb.Message) *TracingMessage { + if m == nil { + return nil + } + + return &TracingMessage{ + Type: m.Type.String(), + Term: m.Term, + From: m.From, + To: m.To, + EntryLength: len(m.Entries), + LogTerm: m.LogTerm, + Index: m.Index, + Commit: m.Commit, + Vote: m.Vote, + Reject: m.Reject, + RejectHint: m.RejectHint, + } +} + +type RaftStateMachineTracer interface { + TraceState(*TracingEvent) +} + +var stateTracer RaftStateMachineTracer + +func SetStateTracer(t RaftStateMachineTracer) { + stateTracer = t +} + +func traceEvent(evt RaftStateMachineEventType, r *raft, m *raftpb.Message, cc *TracingConfChange) { + if stateTracer == nil { + return + } + + stateTracer.TraceState(&TracingEvent{ + Name: evt.String(), + NodeID: r.id, + State: r.hardState(), + Conf: [2][]uint64{nonNilSlice(r.prs.Voters[0].Slice()), nonNilSlice(r.prs.Voters[1].Slice())}, + Role: r.state.String(), + Message: makeTracingMessage(m), + ConfChange: cc, + }) +} + +func traceNodeEvent(evt RaftStateMachineEventType, r *raft) { + traceEvent(evt, r, nil, nil) +} + +func traceChangeConfEvent(cci raftpb.ConfChangeI, r *raft) { + cc2 := cci.AsV2() + cc := &TracingConfChange{ + Changes: []SingleConfChange{}, + NewConf: []uint64{}, + } + for _, c := range cc2.Changes { + switch c.Type { + case raftpb.ConfChangeAddNode: + cc.Changes = append(cc.Changes, SingleConfChange{ + NodeId: c.NodeID, + Action: ConfChangeAddNewServer, + }) + case raftpb.ConfChangeRemoveNode: + cc.Changes = append(cc.Changes, SingleConfChange{ + NodeId: c.NodeID, + Action: ConfChangeRemoveServer, + }) + } + } + + traceEvent(RsmChangeConf, r, nil, cc) +} + +func traceConfChangeEvent(cfg tracker.Config, r *raft) { + if stateTracer == nil { + return + } + + cc := &TracingConfChange{ + Changes: []SingleConfChange{}, + NewConf: nonNilSlice(cfg.Voters[0].Slice()), + } + + traceEvent(RsmApplyConfChange, r, nil, cc) +} + +func traceSendMessage(r *raft, m *raftpb.Message) { + if stateTracer == nil { + return + } + + var evt RaftStateMachineEventType + switch m.Type { + case raftpb.MsgApp: + evt = RsmSendAppendEntriesRequest + case raftpb.MsgAppResp: + evt = RsmSendAppendEntriesResponse + case raftpb.MsgVote: + evt = RsmSendRequestVoteRequest + case raftpb.MsgVoteResp: + evt = RsmSendRequestVoteResponse + default: + return + } + + traceEvent(evt, r, m, nil) +} + +func traceReceiveMessage(r *raft, m *raftpb.Message) { + if stateTracer == nil { + return + } + + var evt RaftStateMachineEventType + switch m.Type { + case raftpb.MsgApp: + evt = RsmReceiveAppendEntriesRequest + case raftpb.MsgAppResp: + evt = RsmReceiveAppendEntriesResponse + case raftpb.MsgVote: + evt = RsmReceiveRequestVoteRequest + case raftpb.MsgVoteResp: + evt = RsmReceiveRequestVoteResponse + default: + return + } + + traceEvent(evt, r, m, nil) +} + +func nonNilSlice(s []uint64) []uint64 { + if s == nil { + return []uint64{} + } + + return s +} diff --git a/tla/Traceetcdraft.cfg b/tla/Traceetcdraft.cfg new file mode 100644 index 0000000..a40eddb --- /dev/null +++ b/tla/Traceetcdraft.cfg @@ -0,0 +1,49 @@ +\* A trace specification defines a set of one or more traces, wherein the value of some +\* variables in each state aligns with the values specified on the corresponding line +\* of the log or trace file. Commonly, the log file might be incomplete, failing to +\* provide the value of all variables. In such instances, the omitted values are +\* determined non-deterministically, adhering to the high-level specification's parameters. +\* Furthermore, a trace may not be complete such that it only matches a prefix of the log. +SPECIFICATION + TraceSpec + +VIEW + TraceView + +\* TLA has only limited support for hyperproperties. The following property is a poorman's +\* hyperproperty that asserts that TLC generated *at least one* trace that fully matches the +\* log file. +PROPERTIES + TraceMatched + +\* Checking for deadlocks during trace validation is disabled, as it may lead to false +\* counterexamples. A trace specification defines a set of traces, where at least one +\* trace is expected to match the log file in terms of variable values and length. +\* However, partial matches may occur where the trace cannot be extended to fully +\* correspond with the log file. In such cases, deadlock checking would report the first +\* of these traces. +CHECK_DEADLOCK + FALSE + +CONSTANTS + InitServer <- TraceInitServer + Server <- TraceServer + + InitConfVars <- TraceInitConfVars + InitLogVars <- TraceInitLogVars + + EntriesToAppend <- TraceEntriesToAppend + NextIndexForUnsuccessfulAppendResponse <- TraceNextIndexForUnsuccessfulAppendResponse + + Nil = 0 + + ValueEntry = "ValueEntry" + ConfigEntry = "ConfigEntry" + + Follower = "Follower" + Candidate = "Candidate" + Leader = "Leader" + RequestVoteRequest = "RequestVoteRequest" + RequestVoteResponse = "RequestVoteResponse" + AppendEntriesRequest = "AppendEntriesRequest" + AppendEntriesResponse = "AppendEntriesResponse" diff --git a/tla/Traceetcdraft.tla b/tla/Traceetcdraft.tla new file mode 100644 index 0000000..422efb7 --- /dev/null +++ b/tla/Traceetcdraft.tla @@ -0,0 +1,325 @@ +-------------------------------- MODULE Traceetcdraft ------------------------------- +EXTENDS etcdraft, Json, IOUtils, Sequences + +\* raft.pb.go enum MessageType +RaftMsgType == + "MsgApp" :> AppendEntriesRequest @@ "MsgAppResp" :> AppendEntriesResponse @@ + "MsgVote" :> RequestVoteRequest @@ "MsgVoteResp" :> RequestVoteResponse + +LeadershipState == + Leader :> "StateLeader" @@ Follower :> "StateFollower" @@ Candidate :> "StateCandidate" + +------------------------------------------------------------------------------------- + +\* Trace validation has been designed for TLC running in default model-checking + \* mode, i.e., breadth-first search. +ASSUME TLCGet("config").mode = "bfs" + +JsonFile == + IF "JSON" \in DOMAIN IOEnv THEN IOEnv.JSON ELSE "./example.ndjson" + +TraceLog == + \* Deserialize the System log as a sequence of records from the log file. + \* Run TLC with (assuming a suitable "tlc" shell alias): + \* $ JSON=../tests/raft_scenarios/4582.ndjson tlc -note Traceccfraft + \* Fall back to trace.ndjson if the JSON environment variable is not set. + SelectSeq(ndJsonDeserialize(JsonFile), LAMBDA l: "tag" \in DOMAIN l /\ l.tag = "raft_trace") + + +ASSUME PrintT(<< "Trace:", JsonFile, "Length:", Len(TraceLog)>>) + +TraceServer == { TraceLog[i].event.nid: i \in DOMAIN TraceLog } + +TraceFirstActionLogIndex == + FoldSeq(LAMBDA x, y: [y EXCEPT ![TraceLog[x].event.nid] = IF @ = 0 /\ TraceLog[x].event.name # "ApplyConfChange" THEN x ELSE @], [ i \in TraceServer |-> 0], [j \in DOMAIN TraceLog |-> j]) + +ASSUME \A k \in DOMAIN TraceLog: k < TraceFirstActionLogIndex[TraceLog[k].event.nid] => TraceLog[k].event.state.term = 1 /\ TraceLog[k].event.state.vote = 0 /\ TraceLog[k].event.name = "ApplyConfChange" + + +TraceInitServer == ToSet(TraceLog[1].event.conf[1]) +ASSUME TraceInitServer \subseteq TraceServer + +------------------------------------------------------------------------------------- +ConfFromLog(l) == << ToSet(l.event.conf[1]), ToSet(l.event.conf[2]) >> + +TraceInitConfVars == + /\ pendingConfChangeIndex = [i \in Server |-> 0] + /\ config = [ i \in Server |-> ConfFromLog(TraceLog[TraceFirstActionLogIndex[i]]) ] + +TraceInitLogVars == /\ log = [i \in Server |-> [j \in 1..TraceLog[TraceFirstActionLogIndex[i]].event.state.commit |-> [term |-> 1, type |-> ConfigEntry]]] + /\ commitIndex = [i \in Server |-> TraceLog[TraceFirstActionLogIndex[i]].event.state.commit] + +OneMoreMessage(msg) == + \/ msg \notin DOMAIN messages /\ msg \in DOMAIN messages' /\ messages'[msg] = 1 + \/ msg \in DOMAIN messages /\ messages'[msg] = messages[msg] + 1 + +OneLessMessage(msg) == + \/ msg \in DOMAIN messages /\ messages[msg] = 1 /\ msg \notin DOMAIN messages' + \/ msg \in DOMAIN messages /\ messages'[msg] = messages[msg] - 1 + +------------------------------------------------------------------------------------- + +VARIABLE l, logline + +NextLogIndex(x) == IF x < Len(TraceLog) + THEN CHOOSE k \in (x+1)..Len(TraceLog): k >= TraceFirstActionLogIndex[TraceLog[k].event.nid] + ELSE x+1 + +TraceInit == + /\ l = NextLogIndex(0) + /\ logline = TraceLog[l] + /\ Init + +StepToNextTrace == + /\ l' = IF l+1>Len(TraceLog) THEN l+1 ELSE NextLogIndex(l) + /\ logline' = IF l' <= Len(TraceLog) THEN TraceLog[l'] ELSE {} + +StepToNextTraceIfMessageIsProcessed(msg) == + IF OneLessMessage(msg) + THEN StepToNextTrace + ELSE UNCHANGED <> + +------------------------------------------------------------------------------------- + + +LoglineIsEvent(e) == + \* Equals FALSE if we get past the end of the log, causing model checking to stop. + /\ l \in 1..Len(TraceLog) + /\ logline.event.name = e + +LoglineIsMessageEvent(e, i, j) == + /\ LoglineIsEvent(e) + /\ logline.event.msg.from = i + /\ logline.event.msg.to = j + +LoglineIsNodeEvent(e, i) == + /\ LoglineIsEvent(e) + /\ logline.event.nid = i + +LoglineIsAppendEntriesRequest(m) == + /\ m.mtype = AppendEntriesRequest + /\ m.mtype = RaftMsgType[logline.event.msg.type] + /\ m.mdest = logline.event.msg.to + /\ m.msource = logline.event.msg.from + /\ m.mterm = logline.event.msg.term + /\ m.mcommitIndex = logline.event.msg.commit + /\ m.mprevLogTerm = logline.event.msg.logTerm + /\ m.mprevLogIndex = logline.event.msg.index + /\ Len(m.mentries) = logline.event.msg.entries + +LoglineIsAppendEntriesResponse(m) == + /\ m.mtype = AppendEntriesResponse + /\ m.mtype = RaftMsgType[logline.event.msg.type] + /\ m.mdest = logline.event.msg.to + /\ m.msource = logline.event.msg.from + /\ m.mterm = logline.event.msg.term + /\ m.msuccess = ~logline.event.msg.reject + /\ m.mmatchIndex = IF logline.event.msg.reject THEN logline.event.msg.rejectHint ELSE logline.event.msg.index + +LoglineIsRequestVoteRequest(m) == + /\ m.mtype = RequestVoteRequest + /\ m.mtype = RaftMsgType[logline.event.msg.type] + /\ m.mdest = logline.event.msg.to + /\ m.msource = logline.event.msg.from + /\ m.mterm = logline.event.msg.term + /\ m.mlastLogIndex = logline.event.msg.index + /\ m.mlastLogTerm = logline.event.msg.logTerm + +LoglineIsRequestVoteResponse(m) == + /\ m.mtype = RequestVoteResponse + /\ m.mtype = RaftMsgType[logline.event.msg.type] + /\ m.mdest = logline.event.msg.to + /\ m.msource = logline.event.msg.from + /\ m.mterm = logline.event.msg.term + /\ m.mvoteGranted = ~logline.event.msg.reject + +\* perform RequestVote transition if logline indicates so +ValidateAfterRequestVote(i, j) == + /\ \E m \in DOMAIN messages': + /\ \/ LoglineIsRequestVoteRequest(m) + \/ /\ LoglineIsRequestVoteResponse(m) + /\ m.msource = m.mdest + /\ OneMoreMessage(m) + +RequestVoteIfLogged(i, j) == + /\ \/ /\ LoglineIsMessageEvent("SendRequestVoteRequest", i, j) + /\ PrintT(<<"SendRequestVoteRequest", "from:", i, "to:", j>>) + \* etcd candidate sends MsgVoteResp to itself upon compain starting + \/ /\ LoglineIsMessageEvent("SendRequestVoteResponse", i, j) + /\ i = j + /\ PrintT(<<"SendRequestVoteResponse", "from:", i, "to:", j>>) + /\ RequestVote(i, j) + /\ ValidateAfterRequestVote(i, j) + /\ StepToNextTrace + +\* perform BecomeLeader transition if logline indicates so +ValidateAfterBecomeLeader(i) == + /\ logline.event.role = "StateLeader" + /\ state'[i] = Leader + +BecomeLeaderIfLogged(i) == + /\ LoglineIsNodeEvent("BecomeLeader", i) + /\ BecomeLeader(i) + /\ ValidateAfterBecomeLeader(i) + /\ StepToNextTrace + +\* perform ClientRequest transition if logline indicates so +ClientRequestIfLogged(i, v) == + /\ LoglineIsNodeEvent("Replicate", i) + /\ ClientRequest(i, v) + /\ StepToNextTrace + +\* perform AdvanceCommitIndex transition if logline indicates so +ValidateAfterAdvanceCommitIndex(i) == + /\ logline.event.role = "StateLeader" + /\ state[i] = Leader + /\ commitIndex'[i] >= logline.event.state.commit + +AdvanceCommitIndexIfLogged(i) == + /\ LoglineIsNodeEvent("Commit", i) + /\ AdvanceCommitIndex(i) + /\ ValidateAfterAdvanceCommitIndex(i) + /\ StepToNextTrace + +\* perform AppendEntries transition if logline indicates so +ValidateAfterAppendEntries(i, j) == + /\ \E msg \in DOMAIN messages': + /\ \/ LoglineIsAppendEntriesRequest(msg) + \/ /\ LoglineIsAppendEntriesResponse(msg) + /\ msg.msource = msg.mdest + \* There is now one more message of this type. + /\ OneMoreMessage(msg) + +TraceEntriesToAppend == logline.event.msg.entries + +AppendEntriesIfLogged(i, j) == + /\ \/ /\ LoglineIsMessageEvent("SendAppendEntriesRequest", i, j) + /\ PrintT(<<"SendAppendEntriesRequest", "from:", i, "to:", j>>) + \* etcd leader sends MsgAppResp to itself after appending log entry + \/ /\ LoglineIsMessageEvent("SendAppendEntriesResponse", i, j) + /\ i = j + /\ PrintT(<<"SendAppendEntriesResponse", "from:", i, "to:", j>>) + /\ AppendEntries(i, j) + /\ ValidateAfterAppendEntries(i, j) + /\ StepToNextTrace + +\* perform Receive transition if logline indicates so +LoglineIsReceivedMessage(m) == + \/ /\ LoglineIsEvent("ReceiveAppendEntriesRequest") + /\ LoglineIsAppendEntriesRequest(m) + /\ PrintT(<<"ReceiveAppendEntriesRequest", "from:", m.msource, "to:", m.mdest>>) + \/ /\ LoglineIsEvent("ReceiveAppendEntriesResponse") + /\ LoglineIsAppendEntriesResponse(m) + /\ PrintT(<<"ReceiveAppendEntriesResponse", "from:", m.msource, "to:", m.mdest>>) + \/ /\ LoglineIsEvent("ReceiveRequestVoteRequest") + /\ LoglineIsRequestVoteRequest(m) + /\ PrintT(<<"ReceiveRequestVoteRequest", "from:", m.msource, "to:", m.mdest>>) + \/ /\ LoglineIsEvent("ReceiveRequestVoteResponse") + /\ LoglineIsRequestVoteResponse(m) + /\ PrintT(<<"ReceiveRequestVoteResponse", "from:", m.msource, "to:", m.mdest, "grant:", m.mvoteGranted>>) + +TraceNextIndexForUnsuccessfulAppendResponse(m) == logline.event.msg.index + +ReceiveIfLogged(m) == + /\ LoglineIsReceivedMessage(m) + /\ Receive(m) + /\ StepToNextTraceIfMessageIsProcessed(m) + +\* perform Timeout transition if logline indicates so +ValidateAfterTimeout(i) == + /\ logline.event.role = "StateCandidate" + /\ logline.event.nid = i + /\ state'[i] = Candidate + /\ currentTerm'[i] = logline.event.state.term + +TimeoutIfLogged(i) == + /\ LoglineIsNodeEvent("BecomeCandidate", i) + /\ Timeout(i) + /\ ValidateAfterTimeout(i) + /\ StepToNextTrace + /\ PrintT(<<"BecomeCandidate", "node:", i>>) + +\* perform AddNewServer transition if logline indicates so +AddNewServerIfLogged(i, j) == + /\ LoglineIsNodeEvent("ChangeConf", i) + /\ Len(logline.event.cc.changes) = 1 + /\ logline.event.cc.changes[1].action = "AddNewServer" + /\ logline.event.cc.changes[1].nid = j + /\ AddNewServer(i, j) + /\ StepToNextTrace + /\ PrintT(<<"ChangeConf", "node:", i, "new:", j>>) + +\* perform DeleteServer transition if logline indicates so +DeleteServerIfLogged(i, j) == + /\ LoglineIsNodeEvent("ChangeConf", i) + /\ Len(logline.event.cc.changes) = 1 + /\ logline.event.cc.changes[1].action = "RemoveServer" + /\ logline.event.cc.changes[1].nid = j + /\ DeleteServer(i, j) + /\ StepToNextTrace + /\ PrintT(<<"ChangeConf", "node:", i, "delete:", j>>) + +\* perform ApplyConfChange transition if logline indicates so +ApplyConfChangeIfLogged(i) == + /\ LoglineIsNodeEvent("ApplyConfChange", i) + /\ ApplyConfChange(i) + /\ StepToNextTrace + /\ PrintT(<<"ApplyConfChange", "node:", i>>) + +\* skip unused logs +SkipUnusedLogline == + /\ \/ /\ LoglineIsEvent("SendAppendEntriesResponse") + /\ logline.event.msg.from # logline.event.msg.to + \/ /\ LoglineIsEvent("SendRequestVoteResponse") + /\ logline.event.msg.from # logline.event.msg.to + \/ LoglineIsEvent("BecomeFollower") + /\ PrintT(<<"skip", "line:", l, "event:", logline.event.name>>) + /\ StepToNextTrace + /\ UNCHANGED <> + +TraceNext == + \/ \E i,j \in Server : RequestVoteIfLogged(i, j) + \/ \E i \in Server : BecomeLeaderIfLogged(i) + \/ \E i \in Server : ClientRequestIfLogged(i, 0) + \/ \E i \in Server : AdvanceCommitIndexIfLogged(i) + \/ \E i,j \in Server : AppendEntriesIfLogged(i, j) + \/ \E m \in DOMAIN messages : ReceiveIfLogged(m) + \/ \E i \in Server : TimeoutIfLogged(i) + \/ SkipUnusedLogline + + +TraceSpec == + TraceInit /\ [][TraceNext]_<> + +------------------------------------------------------------------------------------- + +TraceView == + \* A high-level state s can appear multiple times in a system trace. Including the + \* current level in TLC's view ensures that TLC will not stop model checking when s + \* appears the second time in the trace. Put differently, TraceView causes TLC to + \* consider s_i and s_j , where i and j are the positions of s in the trace, + \* to be different states. + <> + +------------------------------------------------------------------------------------- + +\* The property TraceMatched below will be violated if TLC runs with more than a single worker. +ASSUME TLCGet("config").worker = 1 + +TraceMatched == + \* We force TLC to check TraceMatched as a temporal property because TLC checks temporal + \* properties after generating all successor states of the current state, unlike + \* invariants that are checked after generating a successor state. + \* If the queue is empty after generating all successors of the current state, + \* and l is less than the length of the trace, then TLC failed to validate the trace. + \* + \* We allow more than a single successor state to accept traces like suffix_collision.1 + \* and fancy_election.1. The trace suffix_collision.1 at h_ts 466 has a follower receiving + \* an AppendEntries request. At that point in time, there are two AE requests contained in + \* the variable messages. However, the loglines before h_ts 506 do not allow us to determine + \* which request it is. + \* + \* Note: Consider changing {1,2} to (Nat \ {0}) while validating traces with holes. + [](l <= Len(TraceLog) => [](TLCGet("queue") \in {1,2} \/ l > Len(TraceLog))) + +================================================================================== diff --git a/tla/etcdraft.cfg b/tla/etcdraft.cfg index cfe257b..6bde2f9 100644 --- a/tla/etcdraft.cfg +++ b/tla/etcdraft.cfg @@ -8,10 +8,8 @@ CONSTANTS InitServer = {s1, s2, s3} Server = {s1, s2, s3} - NumRounds = 1 Nil = 0 - Value = {1, 2} ValueEntry = "ValueEntry" ConfigEntry = "ConfigEntry" @@ -22,9 +20,6 @@ CONSTANTS RequestVoteResponse = "RequestVoteResponse" AppendEntriesRequest = "AppendEntriesRequest" AppendEntriesResponse = "AppendEntriesResponse" - CatchupRequest = "CatchupRequest" - CatchupResponse = "CatchupResponse" - CheckOldConfig = "CheckOldConfig" SYMMETRY perms VIEW vars diff --git a/tla/etcdraft.tla b/tla/etcdraft.tla index d66cc84..2e9bbc5 100644 --- a/tla/etcdraft.tla +++ b/tla/etcdraft.tla @@ -7,15 +7,11 @@ \* This work is licensed under the Creative Commons Attribution-4.0 \* International License https://creativecommons.org/licenses/by/4.0/ -EXTENDS Naturals, Integers, TypedBags, FiniteSets, Sequences, SequencesExt, TLC +EXTENDS Naturals, Integers, Bags, FiniteSets, Sequences, SequencesExt, FiniteSetsExt, TLC \* The initial and global set of server IDs. CONSTANTS InitServer, Server -\* The number of rounds to catch new servers up for. -\* Must be >= 1. -CONSTANT NumRounds - \* Log metadata to distinguish values from configuration changes. CONSTANT ValueEntry, ConfigEntry @@ -29,11 +25,6 @@ MaxMembershipChanges == 3 MaxTriedMembershipChanges == MaxMembershipChanges + 1 MaxInFlightMessages == LET card == Cardinality(Server) IN 2 * card * card -\* The set of requests that can go into the log -CONSTANTS - \* @type: Set(Int); - Value - \* Server states. CONSTANTS \* @type: Str; @@ -57,12 +48,7 @@ CONSTANTS \* @type: Str; AppendEntriesRequest, \* @type: Str; - AppendEntriesResponse, - - \* Membership changes - CatchupRequest, - CatchupResponse, - CheckOldConfig + AppendEntriesResponse ----- @@ -186,11 +172,18 @@ VARIABLE \* @type: Seq(Int -> (Int -> Int)); leaderVars == <> +VARIABLE + pendingConfChangeIndex +VARIABLE + config +confVars == <> + + \* End of per server variables. ---- \* All variables; used for stuttering (asserting state hasn't changed). -vars == <> +vars == <> systemState == [ messages |-> messages, \* serverVars @@ -205,7 +198,10 @@ systemState == [ matchIndex |-> matchIndex, \* logVars log |-> log, - commitIndex |-> commitIndex + commitIndex |-> commitIndex, + \* confVars + config |->config, + pendingConfChangeIndex |-> pendingConfChangeIndex ] @@ -214,7 +210,7 @@ systemState == [ \* The set of all quorums. This just calculates simple majorities, but the only \* important property is that every quorum overlaps with every other. -Quorum(config) == {i \in SUBSET(config) : Cardinality(i) * 2 > Cardinality(config)} +Quorum(c) == {i \in SUBSET(c) : Cardinality(i) * 2 > Cardinality(c)} \* The term of the last entry in a log, or 0 if the log is empty. \* @type: LOGT => Int; @@ -246,21 +242,9 @@ WrapMsg(m) == \* Add a message to the bag of messages. SendDirect(m) == LET msgAction == [action |-> "Send", executedOn |-> m.msource, msg |-> m] - membershipAction == - IF m.mtype = CatchupRequest - THEN [action |-> "TryAddServer", executedOn |-> m.msource, added |-> m.mdest] - ELSE IF m.mtype = CheckOldConfig - THEN [action |-> "TryRemoveServer", executedOn |-> m.msource, removed |-> m.mserver] - ELSE << >> IN /\ messages' = WithMessage(m, messages) - /\ history' = - IF membershipAction = << >> - THEN [history EXCEPT !["global"] = Append(history["global"], msgAction)] - ELSE - [history EXCEPT - !["hadNumTriedMembershipChanges"] = history["hadNumTriedMembershipChanges"] + 1, - !["global"] = Append(Append(history["global"], membershipAction), msgAction)] + /\ history' = [history EXCEPT !["global"] = Append(history["global"], msgAction)] \* @type: [msource: Int] => Bool; SendWrapped(m) == @@ -282,13 +266,6 @@ DiscardDirect(m) == /\ messages' = WithoutMessage(m, messages) /\ history' = [history EXCEPT !["global"] = Append(history["global"], action)] -DiscardDirectWithMembershipChange(m, extraAction) == - LET action == [action |-> "Receive", executedOn |-> m.mdest, msg |-> m] IN - /\ messages' = WithoutMessage(m, messages) - /\ history' = [history EXCEPT - !["hadNumMembershipChanges"] = history["hadNumMembershipChanges"] + 1, - !["global"] = Append(Append(history["global"], action), extraAction)] - \* processing a message. \* @type: [mdest: Int] => Bool; DiscardWrapped(m) == @@ -323,7 +300,6 @@ ReplyWrapped(response, request) == Send(m) == SendDirect(m) Reply(response, request) == ReplyDirect(response, request) Discard(m) == DiscardDirect(m) - DiscardWithMembershipChange(m, extraAction) == DiscardDirectWithMembershipChange(m, extraAction) SendWithoutHistory(m) == SendWithoutHistoryDirect(m) DiscardWithoutHistory(m) == DiscardWithoutHistoryDirect(m) @@ -333,31 +309,19 @@ ReplyWrapped(response, request) == \*SendWithoutHistory(m) == SendWithoutHistoryWrapped(m) \*DiscardWithoutHistory(m) == DiscardWithoutHistoryWrapped(m) -\* Return the minimum value from a set, or undefined if the set is empty. -\* @type: Set(Int) => Int; -Min(s) == CHOOSE x \in s : \A y \in s : x <= y -\* Return the maximum value from a set, or undefined if the set is empty. -\* @type: Set(Int) => Int; -Max(s) == CHOOSE x \in s : \A y \in s : x >= y - MaxOrZero(s) == IF s = {} THEN 0 ELSE Max(s) -\* Return the index of the latest configuration in server i's log. -GetHistoricalMaxConfigIndex(i, s) == - LET configIndexes == { index \in 1..Len(s.log[i]) : s.log[i][index].type = ConfigEntry } - IN IF configIndexes = {} THEN 0 - ELSE Max(configIndexes) +GetJointConfig(i) == + config[i] -GetMaxConfigIndex(i) == GetHistoricalMaxConfigIndex(i, systemState) +GetConfig(i) == + GetJointConfig(i)[1] -\* Return the latest configuration in server i's log. -GetHistoricalConfig(i, s) == - LET maxConfigIndex == GetHistoricalMaxConfigIndex(i, s) IN - IF maxConfigIndex = 0 THEN InitServer - ELSE s.log[i][maxConfigIndex].value +GetOutgoingConfig(i) == + GetJointConfig(i)[2] - -GetConfig(i) == GetHistoricalConfig(i, systemState) +IsJointConfig(i) == + /\ config[i][2] # {} CurrentLeaders == {i \in Server : state[i] = Leader} @@ -369,13 +333,12 @@ InitServerVars == /\ currentTerm = [i \in Server |-> 1] /\ votedFor = [i \in Server |-> Nil] InitCandidateVars == /\ votesResponded = [i \in Server |-> {}] /\ votesGranted = [i \in Server |-> {}] -\* The values nextIndex[i][i] and matchIndex[i][i] are never read, since the -\* leader does not send itself messages. It's still easier to include these -\* in the functions. InitLeaderVars == /\ nextIndex = [i \in Server |-> [j \in Server |-> 1]] /\ matchIndex = [i \in Server |-> [j \in Server |-> 0]] InitLogVars == /\ log = [i \in Server |-> << >>] /\ commitIndex = [i \in Server |-> 0] +InitConfVars == /\ pendingConfChangeIndex = [i \in Server |-> 0] + /\ config = [ i \in Server |-> <> ] InitHistory == [ server |-> [i \in Server |-> [restarted |-> 0, timeout |-> 0]], global |-> << >>, @@ -391,6 +354,7 @@ Init == /\ messages = EmptyBag /\ InitCandidateVars /\ InitLeaderVars /\ InitLogVars + /\ InitConfVars ---- \* Define state transitions @@ -404,11 +368,10 @@ Restart(i) == /\ votesGranted' = [votesGranted EXCEPT ![i] = {}] /\ nextIndex' = [nextIndex EXCEPT ![i] = [j \in Server |-> 1]] /\ matchIndex' = [matchIndex EXCEPT ![i] = [j \in Server |-> 0]] - /\ commitIndex' = [commitIndex EXCEPT ![i] = 0] /\ history' = [history EXCEPT !["server"] [i] ["restarted"] = history["server"][i]["restarted"] + 1, !["global"] = Append(history["global"], [action |-> "Restart", executedOn |-> i])] - /\ UNCHANGED <> + /\ UNCHANGED <> \* Server i times out and starts a new election. \* @type: Int => Bool; @@ -416,56 +379,71 @@ Timeout(i) == /\ state[i] \in {Follower, Candidate} /\ i \in GetConfig(i) /\ state' = [state EXCEPT ![i] = Candidate] /\ currentTerm' = [currentTerm EXCEPT ![i] = currentTerm[i] + 1] - \* Most implementations would probably just set the local vote - \* atomically, but messaging localhost for it is weaker. - /\ votedFor' = [votedFor EXCEPT ![i] = Nil] + /\ votedFor' = [votedFor EXCEPT ![i] = i] /\ votesResponded' = [votesResponded EXCEPT ![i] = {}] /\ votesGranted' = [votesGranted EXCEPT ![i] = {}] /\ history' = [history EXCEPT !["server"] [i] ["timeout"] = history["server"][i]["timeout"] + 1, !["global"] = Append(history["global"], [action |-> "Timeout", executedOn |-> i])] - /\ UNCHANGED <> + /\ UNCHANGED <> \* Candidate i sends j a RequestVote request. \* @type: (Int, Int) => Bool; RequestVote(i, j) == /\ state[i] = Candidate /\ j \in (GetConfig(i) \ votesResponded[i]) - /\ Send([mtype |-> RequestVoteRequest, - mterm |-> currentTerm[i], - mlastLogTerm |-> LastTerm(log[i]), - mlastLogIndex |-> Len(log[i]), - msource |-> i, - mdest |-> j]) - /\ UNCHANGED <> - -\* Leader i sends j an AppendEntries request containing up to 1 entry. -\* While implementations may want to send more than 1 at a time, this spec uses -\* just 1 because it minimizes atomic regions without loss of generality. + /\ IF i # j + THEN Send([mtype |-> RequestVoteRequest, + mterm |-> currentTerm[i], + mlastLogTerm |-> LastTerm(log[i]), + mlastLogIndex |-> Len(log[i]), + msource |-> i, + mdest |-> j]) + ELSE Send([mtype |-> RequestVoteResponse, + mterm |-> currentTerm[i], + mvoteGranted |-> TRUE, + mlog |-> log[i], + msource |-> i, + mdest |-> i]) + /\ UNCHANGED <> + +EntriesToAppend == 1 + +\* Leader i sends j an AppendEntries request containing specific # of entries \* @type: (Int, Int) => Bool; AppendEntries(i, j) == - /\ i /= j /\ state[i] = Leader /\ j \in GetConfig(i) - /\ LET prevLogIndex == nextIndex[i][j] - 1 - \* The following upper bound on prevLogIndex is unnecessary - \* but makes verification substantially simpler. - prevLogTerm == IF prevLogIndex > 0 /\ prevLogIndex <= Len(log[i]) THEN - log[i][prevLogIndex].term - ELSE - 0 - \* Send up to 1 entry, constrained by the end of the log. - lastEntry == Min({Len(log[i]), nextIndex[i][j]}) - entries == SubSeq(log[i], nextIndex[i][j], lastEntry) - IN Send([mtype |-> AppendEntriesRequest, - mterm |-> currentTerm[i], - mprevLogIndex |-> prevLogIndex, - mprevLogTerm |-> prevLogTerm, - mentries |-> entries, - mcommitIndex |-> Min({commitIndex[i], lastEntry}), - msource |-> i, - mdest |-> j]) - /\ UNCHANGED <> + /\ IF i /= j THEN + /\ LET prevLogIndex == nextIndex[i][j] - 1 + \* The following upper bound on prevLogIndex is unnecessary + \* but makes verification substantially simpler. + prevLogTerm == IF prevLogIndex > 0 /\ prevLogIndex <= Len(log[i]) THEN + log[i][prevLogIndex].term + ELSE + 0 + \* Send specific # of entries + lastEntry == Min({Len(log[i]), nextIndex[i][j] - 1 + EntriesToAppend}) + entries == SubSeq(log[i], nextIndex[i][j], lastEntry) + IN /\ Send([mtype |-> AppendEntriesRequest, + mterm |-> currentTerm[i], + mprevLogIndex |-> prevLogIndex, + mprevLogTerm |-> prevLogTerm, + mentries |-> entries, + mcommitIndex |-> Min({commitIndex[i], lastEntry}), + msource |-> i, + mdest |-> j]) + \* etcd optimize append entries pipeline by updating next index immediately after sending + /\ nextIndex' = [nextIndex EXCEPT ![i][j] = lastEntry + 1] + /\ UNCHANGED <> + ELSE \* etcd leader sends MsgAppResp to itself immediately after appending log entry + /\ Send([mtype |-> AppendEntriesResponse, + mterm |-> currentTerm[i], + msuccess |-> TRUE, + mmatchIndex |-> Len(log[i]), + msource |-> i, + mdest |-> i]) + /\ UNCHANGED <> \* Candidate i transitions to leader. \* @type: Int => Bool; @@ -476,25 +454,31 @@ BecomeLeader(i) == /\ nextIndex' = [nextIndex EXCEPT ![i] = [j \in Server |-> Len(log[i]) + 1]] /\ matchIndex' = [matchIndex EXCEPT ![i] = - [j \in Server |-> 0]] + [j \in Server |-> IF j = i THEN Len(log[i]) ELSE 0]] + /\ log' = [log EXCEPT ![i] = Append(@, [term |-> currentTerm[i]]) ] /\ history' = [history EXCEPT !["hadNumLeaders"] = history["hadNumLeaders"] + 1, !["global"] = Append(history["global"], [action |-> "BecomeLeader", executedOn |-> i, leaders |-> (CurrentLeaders \cup {i})])] - /\ UNCHANGED <> + /\ UNCHANGED <> -\* Leader i receives a client request to add v to the log. -\* @type: (Int, Int) => Bool; -ClientRequest(i, v) == +Replicate(i, v, t) == + /\ t \in {ValueEntry, ConfigEntry} /\ state[i] = Leader - /\ LET entry == [term |-> currentTerm[i], - type |-> ValueEntry, + /\ LET historyKey == IF t = ValueEntry THEN "hadNumClientRequests" ELSE "hadNumMembershipChanges" + entry == [term |-> currentTerm[i], + type |-> t, + seq |-> history[historyKey], value |-> v] newLog == Append(log[i], entry) - IN log' = [log EXCEPT ![i] = newLog] - /\ history' = [history EXCEPT !["hadNumClientRequests"] = history["hadNumClientRequests"] + 1] - /\ UNCHANGED <> + IN /\ log' = [log EXCEPT ![i] = newLog] + /\ history' = [history EXCEPT ![historyKey] = @ + 1] + /\ UNCHANGED <> + +\* Leader i receives a client request to add v to the log. +\* @type: (Int, Int) => Bool; +ClientRequest(i, v) == + Replicate(i, v, ValueEntry) \* Leader i advances its commitIndex. \* This is done as a separate step from handling AppendEntries responses, @@ -520,54 +504,43 @@ AdvanceCommitIndex(i) == ELSE commitIndex[i] committed == newCommitIndex > commitIndex[i] - committedMembershipChange == - /\ committed - /\ log[i][newCommitIndex].type = ConfigEntry - \* The newly commited entry actually changes the configuration, i.e. is not the same config commited again - /\ log[i][newCommitIndex].value /= - GetHistoricalConfig(i, [log |-> [log EXCEPT ![i] = SubSeq(log[i], 1, newCommitIndex - 1)]]) IN /\ commitIndex' = [commitIndex EXCEPT ![i] = newCommitIndex] - /\ IF committedMembershipChange THEN - history' = [history EXCEPT - !["global"] = Append(history["global"], - [action |-> "CommitMembershipChange", executedOn |-> i, config |-> log[i][newCommitIndex].value])] - ELSE IF committed THEN + /\ IF committed THEN history' = [history EXCEPT !["global"] = Append(history["global"], [action |-> "CommitEntry", executedOn |-> i, entry |-> log[i][newCommitIndex]])] ELSE UNCHANGED <> - /\ UNCHANGED <> + /\ UNCHANGED <> + \* Leader i adds a new server j to the cluster. AddNewServer(i, j) == /\ state[i] = Leader /\ j \notin GetConfig(i) + /\ pendingConfChangeIndex[i] = 0 + /\ ~IsJointConfig(i) + /\ Replicate(i, [newconf |-> GetConfig(i) \union {j}], ConfigEntry) /\ currentTerm' = [currentTerm EXCEPT ![j] = 1] /\ votedFor' = [votedFor EXCEPT ![j] = Nil] - /\ Send([mtype |-> CatchupRequest, - mterm |-> currentTerm[i], - mlogLen |-> matchIndex[i][j], - mentries |-> SubSeq(log[i], nextIndex[i][j], commitIndex[i]), - mcommitIndex |-> commitIndex[i], - msource |-> i, - mdest |-> j, - mrounds |-> NumRounds]) - /\ UNCHANGED <> + /\ pendingConfChangeIndex' = [pendingConfChangeIndex EXCEPT ![i]=Len(log[i])] \* Leader i removes a server j (possibly itself) from the cluster. DeleteServer(i, j) == /\ state[i] = Leader /\ state[j] \in {Follower, Candidate} /\ j \in GetConfig(i) - /\ j /= i \* TODO: A leader cannot remove itself. - /\ Send([mtype |-> CheckOldConfig, - mterm |-> currentTerm[i], - madd |-> FALSE, - mserver |-> j, - msource |-> i, - mdest |-> i]) - /\ UNCHANGED <> - + /\ pendingConfChangeIndex[i] = 0 + /\ ~IsJointConfig(i) + /\ Replicate(i, [newconf |-> GetConfig(i) \ {j}], ConfigEntry) + /\ pendingConfChangeIndex' = [pendingConfChangeIndex EXCEPT ![i]=Len(log[i])] + +ApplyConfChange(i) == + /\ pendingConfChangeIndex[i] > 0 + /\ pendingConfChangeIndex[i] <= commitIndex[i] + /\ ~IsJointConfig(i) + /\ config' = [config EXCEPT ![i]= << log[i][pendingConfChangeIndex[i]].value.newconf, {} >>] + /\ pendingConfChangeIndex' = [pendingConfChangeIndex EXCEPT ![i] = 0] + ---- \* Message handlers \* i = recipient, j = sender, m = message @@ -594,7 +567,7 @@ HandleRequestVoteRequest(i, j, m) == msource |-> i, mdest |-> j], m) - /\ UNCHANGED <> + /\ UNCHANGED <> \* Server i receives a RequestVote response from server j with \* m.mterm = currentTerm[i]. @@ -611,7 +584,7 @@ HandleRequestVoteResponse(i, j, m) == \/ /\ ~m.mvoteGranted /\ UNCHANGED <> /\ Discard(m) - /\ UNCHANGED <> + /\ UNCHANGED <> \* @type: (Int, Int, AEREQT, Bool) => Bool; RejectAppendEntriesRequest(i, j, m, logOk) == @@ -626,49 +599,49 @@ RejectAppendEntriesRequest(i, j, m, logOk) == msource |-> i, mdest |-> j], m) - /\ UNCHANGED <> + /\ UNCHANGED <> \* @type: (Int, MSG) => Bool; ReturnToFollowerState(i, m) == /\ m.mterm = currentTerm[i] /\ state[i] = Candidate /\ state' = [state EXCEPT ![i] = Follower] - /\ UNCHANGED <> + /\ UNCHANGED <> + +HasNoConflict(i, index, ents) == + /\ index <= Len(log[i]) + 1 + /\ \A k \in 1..Len(ents): index + k - 1 <= Len(log[i]) => log[i][index+k-1].term = ents[k].term \* @type: (Int, Int, Int, AEREQT) => Bool; AppendEntriesAlreadyDone(i, j, index, m) == - /\ \/ m.mentries = << >> + /\ \/ index <= commitIndex[i] + \/ m.mentries = << >> \/ /\ m.mentries /= << >> - /\ Len(log[i]) >= index - /\ log[i][index].term = m.mentries[1].term - \* This could make our commitIndex decrease (for - \* example if we process an old, duplicated request), - \* but that doesn't really affect anything. - /\ commitIndex' = [commitIndex EXCEPT ![i] = m.mcommitIndex] + /\ m.mprevLogIndex + Len(m.mentries) <= Len(log[i]) + /\ HasNoConflict(i, index, m.mentries) + /\ commitIndex' = [commitIndex EXCEPT ![i] = IF index <= commitIndex[i] THEN @ ELSE Min({m.mcommitIndex, m.mprevLogIndex+Len(m.mentries)})] /\ Reply([mtype |-> AppendEntriesResponse, - mterm |-> currentTerm[i], - msuccess |-> TRUE, - mmatchIndex |-> m.mprevLogIndex + Len(m.mentries), - msource |-> i, - mdest |-> j], - m) - /\ UNCHANGED <> + mterm |-> currentTerm[i], + msuccess |-> TRUE, + mmatchIndex |-> IF index <= commitIndex[i] THEN commitIndex[i] ELSE m.mprevLogIndex+Len(m.mentries), + msource |-> i, + mdest |-> j], + m) + /\ UNCHANGED <> \* @type: (Int, Int, AEREQT) => Bool; ConflictAppendEntriesRequest(i, index, m) == /\ m.mentries /= << >> - /\ Len(log[i]) >= index - /\ log[i][index].term /= m.mentries[1].term - \* /\ LET new == [index2 \in 1..(Len(log[i]) - 1) |-> log[i][index2]] - /\ LET new == SubSeq(log[i], 1, Len(log[i]) - 1) - IN log' = [log EXCEPT ![i] = new] + /\ index > commitIndex[i] + /\ ~HasNoConflict(i, index, m.mentries) + /\ log' = [log EXCEPT ![i] = SubSeq(log[i], 1, Len(log[i]) - 1)] /\ UNCHANGED <> \* @type: (Int, AEREQT) => Bool; -NoConflictAppendEntriesRequest(i, m) == +NoConflictAppendEntriesRequest(i, index, m) == /\ m.mentries /= << >> - /\ Len(log[i]) = m.mprevLogIndex - /\ log' = [log EXCEPT ![i] = Append(log[i], m.mentries[1])] + /\ HasNoConflict(i, index, m.mentries) + /\ log' = [log EXCEPT ![i] = @ \o SubSeq(m.mentries, Len(log[i])-index+2, Len(m.mentries))] /\ UNCHANGED <> \* @type: (Int, Int, Bool, AEREQT) => Bool; @@ -680,7 +653,7 @@ AcceptAppendEntriesRequest(i, j, logOk, m) == /\ LET index == m.mprevLogIndex + 1 IN \/ AppendEntriesAlreadyDone(i, j, index, m) \/ ConflictAppendEntriesRequest(i, index, m) - \/ NoConflictAppendEntriesRequest(i, m) + \/ NoConflictAppendEntriesRequest(i, index, m) \* Server i receives an AppendEntries request from server j with \* m.mterm <= currentTerm[i]. This just handles m.entries of length 0 or 1, but @@ -697,7 +670,10 @@ HandleAppendEntriesRequest(i, j, m) == /\ \/ RejectAppendEntriesRequest(i, j, m, logOk) \/ ReturnToFollowerState(i, m) \/ AcceptAppendEntriesRequest(i, j, logOk, m) - /\ UNCHANGED <> + /\ UNCHANGED <> + +NextIndexForUnsuccessfulAppendResponse(m) == + Max({nextIndex[m.mdest][m.msource] - 1, 1}) \* Server i receives an AppendEntries response from server j with \* m.mterm = currentTerm[i]. @@ -705,121 +681,14 @@ HandleAppendEntriesRequest(i, j, m) == HandleAppendEntriesResponse(i, j, m) == /\ m.mterm = currentTerm[i] /\ \/ /\ m.msuccess \* successful - /\ nextIndex' = [nextIndex EXCEPT ![i][j] = m.mmatchIndex + 1] - /\ matchIndex' = [matchIndex EXCEPT ![i][j] = m.mmatchIndex] + \* etcd optimize append entries pipeline by allowing MsgApp messages sent out in any order + /\ nextIndex' = [nextIndex EXCEPT ![i][j] = Max({@, m.mmatchIndex + 1})] + /\ matchIndex' = [matchIndex EXCEPT ![i][j] = Max({@, m.mmatchIndex})] \/ /\ \lnot m.msuccess \* not successful - /\ nextIndex' = [nextIndex EXCEPT ![i][j] = - Max({nextIndex[i][j] - 1, 1})] + /\ nextIndex' = [nextIndex EXCEPT ![i][j] = NextIndexForUnsuccessfulAppendResponse(m)] /\ UNCHANGED <> /\ Discard(m) - /\ UNCHANGED <> - -\* Detached server i receives a CatchupRequest from leader j. -HandleCatchupRequest(i, j, m) == - \/ /\ m.mterm < currentTerm[i] - /\ Reply([mtype |-> CatchupResponse, - mterm |-> currentTerm[i], - msuccess |-> FALSE, - mmatchIndex |-> 0, - msource |-> i, - mdest |-> j, - mroundsLeft |-> 0], - m) - /\ UNCHANGED <> - \/ /\ m.mterm >= currentTerm[i] - /\ currentTerm' = [currentTerm EXCEPT ![i] = m.mterm] - \* This was previously the following, but that's buggy - \* (shows how this spec wasn't tested very extensively) - \* /\ log' = [log EXCEPT ![i] = SubSeq(log[i], 1, m.mlogLen) \circ m.mentries] - /\ log' = [log EXCEPT ![i] = - IF log[i] = << >> THEN m.mentries - ELSE SubSeq(log[i], 1, Min({m.mlogLen, Len(log[i])})) \circ m.mentries] - /\ Reply([mtype |-> CatchupResponse, - mterm |-> m.mterm, - msuccess |-> TRUE, - mmatchIndex |-> Len(log[i]), - msource |-> i, - mdest |-> j, - mroundsLeft |-> m.mrounds - 1], - m) - /\ UNCHANGED <> - -\* Leader i receives a CatchupResponse from detached server j. -HandleCatchupResponse(i, j, m) == - \* A real system checks for progress every timeout interval. - \* Assume that if this response is called, the new server - \* has made progress. - /\ \/ /\ m.msuccess - /\ \/ /\ m.mmatchIndex /= commitIndex[i] - /\ m.mmatchIndex /= matchIndex[i][j] - \/ m.mmatchIndex = commitIndex[i] - /\ state[i] = Leader - /\ m.mterm = currentTerm[i] - /\ j \notin GetConfig(i) - /\ nextIndex' = [nextIndex EXCEPT ![i][j] = m.mmatchIndex + 1] - /\ matchIndex' = [matchIndex EXCEPT ![i][j] = m.mmatchIndex] - /\ \/ /\ m.mroundsLeft /= 0 - /\ Reply([mtype |-> CatchupRequest, - mterm |-> currentTerm[i], - mentries |-> SubSeq(log[i], - nextIndex[i][j], - commitIndex[i]), - mlogLen |-> nextIndex[i][j] - 1, - msource |-> i, - mdest |-> j, - mrounds |-> m.mroundsLeft], - m) - \/ /\ m.mroundsLeft = 0 - \* A real system makes sure the final call to this handler is - \* received after a timeout interval. - \* We assume that if a timeout happened, the message - \* has already been dropped. - /\ Reply([mtype |-> CheckOldConfig, - mterm |-> currentTerm[i], - madd |-> TRUE, - mserver |-> j, - msource |-> i, - mdest |-> i], m) - \/ /\ \/ \lnot m.msuccess - \/ /\ \/ m.mmatchIndex = commitIndex[i] - \/ m.mmatchIndex = matchIndex[i][j] - /\ m.mmatchIndex /= commitIndex[i] - \/ state[i] /= Leader - \/ m.mterm /= currentTerm[i] - \/ j \in GetConfig(i) - /\ Discard(m) - /\ UNCHANGED <> - /\ UNCHANGED <> - -\* Leader i receives a CheckOldConfig message. -HandleCheckOldConfig(i, m) == - \/ /\ state[i] /= Leader \/ m.mterm = currentTerm[i] - /\ Discard(m) - /\ UNCHANGED <> - \/ /\ state[i] = Leader /\ m.mterm = currentTerm[i] - /\ \/ /\ GetMaxConfigIndex(i) <= commitIndex[i] - \* We only modify the log if the config actually changed - /\ LET action == IF m.madd THEN [action |-> "AddServer", executedOn |->i, added |-> m.mserver] - ELSE [action |-> "RemoveServer", executedOn |-> i, removed |-> m.mserver] - newConfig == IF m.madd THEN UNION { GetConfig(i), {m.mserver} } - ELSE GetConfig(i) \ {m.mserver} - configChanged == GetConfig(i) /= newConfig - newEntry == [term |-> currentTerm[i], type |-> ConfigEntry, value |-> newConfig] - newLog == IF configChanged THEN Append(log[i], newEntry) ELSE log[i] - IN - /\ log' = [log EXCEPT ![i] = newLog] - /\ IF configChanged THEN DiscardWithMembershipChange(m, action) ELSE Discard(m) - /\ UNCHANGED <> - \/ /\ GetMaxConfigIndex(i) > commitIndex[i] - /\ Reply([mtype |-> CheckOldConfig, - mterm |-> currentTerm[i], - madd |-> m.madd, - mserver |-> m.mserver, - msource |-> i, - mdest |-> i], - m) - /\ UNCHANGED <> - /\ UNCHANGED <> + /\ UNCHANGED <> \* Any RPC with a newer term causes the recipient to advance its term first. \* @type: (Int, Int, MSG) => Bool; @@ -829,14 +698,14 @@ UpdateTerm(i, j, m) == /\ state' = [state EXCEPT ![i] = Follower] /\ votedFor' = [votedFor EXCEPT ![i] = Nil] \* messages is unchanged so m can be processed further. - /\ UNCHANGED <> + /\ UNCHANGED <> \* Responses with stale terms are ignored. \* @type: (Int, Int, MSG) => Bool; DropStaleResponse(i, j, m) == /\ m.mterm < currentTerm[i] /\ Discard(m) - /\ UNCHANGED <> + /\ UNCHANGED <> \* Receive a message. ReceiveDirect(m) == @@ -855,12 +724,6 @@ ReceiveDirect(m) == \/ /\ m.mtype = AppendEntriesResponse /\ \/ DropStaleResponse(i, j, m) \/ HandleAppendEntriesResponse(i, j, m) - \/ /\ m.mtype = CatchupRequest - /\ HandleCatchupRequest(i, j, m) - \/ /\ m.mtype = CatchupResponse - /\ HandleCatchupResponse(i, j, m) - \/ /\ m.mtype = CheckOldConfig - /\ HandleCheckOldConfig(i, m) \* @type: MSG => Bool; ReceiveWrapped(m) == @@ -893,7 +756,7 @@ DuplicateMessage(m) == \* Do not duplicate loopback messages \* /\ m.msource /= m.mdest /\ SendWithoutHistory(m) - /\ UNCHANGED <> + /\ UNCHANGED <> \* The network drops a message \* @type: MSG => Bool; @@ -901,7 +764,7 @@ DropMessage(m) == \* Do not drop loopback messages \* /\ m.msource /= m.mdest /\ DiscardWithoutHistory(m) - /\ UNCHANGED <> + /\ UNCHANGED <> ---- @@ -909,7 +772,7 @@ DropMessage(m) == NextAsync == \/ \E i,j \in Server : RequestVote(i, j) \/ \E i \in Server : BecomeLeader(i) - \/ \E i \in Server, v \in Value : ClientRequest(i, v) + \/ \E i \in Server: ClientRequest(i, 0) \/ \E i \in Server : AdvanceCommitIndex(i) \/ \E i,j \in Server : AppendEntries(i, j) \/ \E m \in DOMAIN messages : Receive(m) @@ -941,6 +804,7 @@ NextDynamic == \/ Next \/ \E i, j \in Server : AddNewServer(i, j) \/ \E i, j \in Server : DeleteServer(i, j) + \/ \E i \in Server : ApplyConfChange(i) \* The specification must start with the initial state and transition according \* to Next. @@ -1128,13 +992,13 @@ ElectionsUncontested == Cardinality({c \in DOMAIN state : state[c] = Candidate}) CleanStartUntilFirstRequest == ((history["hadNumLeaders"] < 1 /\ history["hadNumClientRequests"] < 1)) => /\ \A i \in Server: history["server"][i]["restarted"] = 0 - /\ Sum([i \in Server |-> history["server"][i]["timeout"]]) <= 1 + /\ FoldSeq(LAMBDA x,y: x+y, 0, [i \in Server |-> history["server"][i]["timeout"]]) <= 1 /\ ElectionsUncontested CleanStartUntilTwoLeaders == (history["hadNumLeaders"] < 2) => - /\ Sum([i \in Server |-> history["server"][i]["restarted"]]) <= 1 - /\ Sum([i \in Server |-> history["server"][i]["timeout"]]) <= 2 + /\ FoldSeq(LAMBDA x,y: x+y, 0, [i \in Server |-> history["server"][i]["restarted"]]) <= 1 + /\ FoldSeq(LAMBDA x,y: x+y, 0, [i \in Server |-> history["server"][i]["timeout"]]) <= 2 ----- diff --git a/tla/example.ndjson b/tla/example.ndjson new file mode 100644 index 0000000..662a593 --- /dev/null +++ b/tla/example.ndjson @@ -0,0 +1,700 @@ +{"level":"info","ts":"2023-10-12T11:15:09.270799+0800","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_LOG_LEVEL","variable-value":"debug"} +{"level":"info","ts":"2023-10-12T11:15:09.271354+0800","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_LOG_LEVEL","variable-value":"debug"} +{"level":"warn","ts":"2023-10-12T11:15:09.27154+0800","caller":"embed/config.go:708","msg":"Running http and grpc server on single port. This is not recommended for production."} +{"level":"warn","ts":"2023-10-12T11:15:09.271584+0800","caller":"embed/config.go:708","msg":"Running http and grpc server on single port. This is not recommended for production."} +{"level":"info","ts":"2023-10-12T11:15:09.27163+0800","caller":"etcdmain/etcd.go:64","msg":"Running: ","args":["bin/etcd","--name","infra1","--listen-client-urls","http://127.0.0.1:2379","--advertise-client-urls","http://127.0.0.1:2379","--listen-peer-urls","http://127.0.0.1:12380","--initial-advertise-peer-urls","http://127.0.0.1:12380","--initial-cluster-token","etcd-cluster-1","--initial-cluster","infra1=http://127.0.0.1:12380,infra2=http://127.0.0.1:22380,infra3=http://127.0.0.1:32380","--initial-cluster-state","new","--enable-pprof","--logger=zap","--log-outputs=stderr"]} +{"level":"info","ts":"2023-10-12T11:15:09.27167+0800","caller":"etcdmain/etcd.go:64","msg":"Running: ","args":["bin/etcd","--name","infra2","--listen-client-urls","http://127.0.0.1:22379","--advertise-client-urls","http://127.0.0.1:22379","--listen-peer-urls","http://127.0.0.1:22380","--initial-advertise-peer-urls","http://127.0.0.1:22380","--initial-cluster-token","etcd-cluster-1","--initial-cluster","infra1=http://127.0.0.1:12380,infra2=http://127.0.0.1:22380,infra3=http://127.0.0.1:32380","--initial-cluster-state","new","--enable-pprof","--logger=zap","--log-outputs=stderr"]} +{"level":"warn","ts":"2023-10-12T11:15:09.27169+0800","caller":"etcdmain/etcd.go:96","msg":"'data-dir' was empty; using default","data-dir":"infra1.etcd"} +{"level":"info","ts":"2023-10-12T11:15:09.271741+0800","caller":"etcdmain/etcd.go:124","msg":"Initialize and start etcd server","data-dir":"infra1.etcd","dir-type":"empty"} +{"level":"warn","ts":"2023-10-12T11:15:09.271789+0800","caller":"embed/config.go:708","msg":"Running http and grpc server on single port. This is not recommended for production."} +{"level":"info","ts":"2023-10-12T11:15:09.271816+0800","caller":"embed/etcd.go:125","msg":"configuring peer listeners","listen-peer-urls":["http://127.0.0.1:12380"]} +{"level":"info","ts":"2023-10-12T11:15:09.271897+0800","caller":"embed/etcd.go:133","msg":"configuring client listeners","listen-client-urls":["http://127.0.0.1:2379"]} +{"level":"info","ts":"2023-10-12T11:15:09.271911+0800","caller":"embed/etcd.go:626","msg":"pprof is enabled","path":"/debug/pprof"} +{"level":"info","ts":"2023-10-12T11:15:09.27196+0800","caller":"embed/etcd.go:313","msg":"starting an etcd server","etcd-version":"3.6.0-alpha.0","git-sha":"b57fe9e9d","go-version":"go1.21.1","go-os":"linux","go-arch":"amd64","max-cpu-set":8,"max-cpu-available":8,"member-initialized":false,"name":"infra1","data-dir":"infra1.etcd","wal-dir":"","wal-dir-dedicated":"","member-dir":"infra1.etcd/member","force-new-cluster":false,"heartbeat-interval":"100ms","election-timeout":"1s","wait-cluster-ready-timeout":"5s","initial-election-tick-advance":true,"snapshot-count":10000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://127.0.0.1:12380"],"listen-peer-urls":["http://127.0.0.1:12380"],"advertise-client-urls":["http://127.0.0.1:2379"],"listen-client-urls":["http://127.0.0.1:2379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"infra1=http://127.0.0.1:12380,infra2=http://127.0.0.1:22380,infra3=http://127.0.0.1:32380","initial-cluster-state":"new","initial-cluster-token":"etcd-cluster-1","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"periodic","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","discovery-token":"","discovery-endpoints":"","discovery-dial-timeout":"2s","discovery-request-timeout":"5s","discovery-keepalive-time":"2s","discovery-keepalive-timeout":"6s","discovery-insecure-transport":true,"discovery-insecure-skip-tls-verify":false,"discovery-cert":"","discovery-key":"","discovery-cacert":"","discovery-user":"","downgrade-check-interval":"5s","max-learners":1} +{"level":"info","ts":"2023-10-12T11:15:09.272018+0800","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_LOG_LEVEL","variable-value":"debug"} +{"level":"warn","ts":"2023-10-12T11:15:09.272097+0800","caller":"etcdmain/etcd.go:96","msg":"'data-dir' was empty; using default","data-dir":"infra2.etcd"} +{"level":"info","ts":"2023-10-12T11:15:09.272115+0800","caller":"etcdmain/etcd.go:124","msg":"Initialize and start etcd server","data-dir":"infra2.etcd","dir-type":"empty"} +{"level":"warn","ts":"2023-10-12T11:15:09.272134+0800","caller":"embed/config.go:708","msg":"Running http and grpc server on single port. This is not recommended for production."} +{"level":"info","ts":"2023-10-12T11:15:09.272144+0800","caller":"embed/etcd.go:125","msg":"configuring peer listeners","listen-peer-urls":["http://127.0.0.1:22380"]} +{"level":"warn","ts":"2023-10-12T11:15:09.272149+0800","caller":"embed/config.go:708","msg":"Running http and grpc server on single port. This is not recommended for production."} +{"level":"info","ts":"2023-10-12T11:15:09.272161+0800","caller":"etcdmain/etcd.go:64","msg":"Running: ","args":["bin/etcd","--name","infra3","--listen-client-urls","http://127.0.0.1:32379","--advertise-client-urls","http://127.0.0.1:32379","--listen-peer-urls","http://127.0.0.1:32380","--initial-advertise-peer-urls","http://127.0.0.1:32380","--initial-cluster-token","etcd-cluster-1","--initial-cluster","infra1=http://127.0.0.1:12380,infra2=http://127.0.0.1:22380,infra3=http://127.0.0.1:32380","--initial-cluster-state","new","--enable-pprof","--logger=zap","--log-outputs=stderr"]} +{"level":"warn","ts":"2023-10-12T11:15:09.272175+0800","caller":"etcdmain/etcd.go:96","msg":"'data-dir' was empty; using default","data-dir":"infra3.etcd"} +{"level":"info","ts":"2023-10-12T11:15:09.272187+0800","caller":"etcdmain/etcd.go:124","msg":"Initialize and start etcd server","data-dir":"infra3.etcd","dir-type":"empty"} +{"level":"warn","ts":"2023-10-12T11:15:09.272246+0800","caller":"embed/config.go:708","msg":"Running http and grpc server on single port. This is not recommended for production."} +{"level":"info","ts":"2023-10-12T11:15:09.272259+0800","caller":"embed/etcd.go:125","msg":"configuring peer listeners","listen-peer-urls":["http://127.0.0.1:32380"]} +{"level":"info","ts":"2023-10-12T11:15:09.272263+0800","caller":"embed/etcd.go:133","msg":"configuring client listeners","listen-client-urls":["http://127.0.0.1:22379"]} +{"level":"info","ts":"2023-10-12T11:15:09.272273+0800","caller":"embed/etcd.go:626","msg":"pprof is enabled","path":"/debug/pprof"} +{"level":"info","ts":"2023-10-12T11:15:09.272311+0800","caller":"embed/etcd.go:313","msg":"starting an etcd server","etcd-version":"3.6.0-alpha.0","git-sha":"b57fe9e9d","go-version":"go1.21.1","go-os":"linux","go-arch":"amd64","max-cpu-set":8,"max-cpu-available":8,"member-initialized":false,"name":"infra2","data-dir":"infra2.etcd","wal-dir":"","wal-dir-dedicated":"","member-dir":"infra2.etcd/member","force-new-cluster":false,"heartbeat-interval":"100ms","election-timeout":"1s","wait-cluster-ready-timeout":"5s","initial-election-tick-advance":true,"snapshot-count":10000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://127.0.0.1:22380"],"listen-peer-urls":["http://127.0.0.1:22380"],"advertise-client-urls":["http://127.0.0.1:22379"],"listen-client-urls":["http://127.0.0.1:22379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"infra1=http://127.0.0.1:12380,infra2=http://127.0.0.1:22380,infra3=http://127.0.0.1:32380","initial-cluster-state":"new","initial-cluster-token":"etcd-cluster-1","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"periodic","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","discovery-token":"","discovery-endpoints":"","discovery-dial-timeout":"2s","discovery-request-timeout":"5s","discovery-keepalive-time":"2s","discovery-keepalive-timeout":"6s","discovery-insecure-transport":true,"discovery-insecure-skip-tls-verify":false,"discovery-cert":"","discovery-key":"","discovery-cacert":"","discovery-user":"","downgrade-check-interval":"5s","max-learners":1} +{"level":"info","ts":"2023-10-12T11:15:09.272331+0800","caller":"embed/etcd.go:133","msg":"configuring client listeners","listen-client-urls":["http://127.0.0.1:32379"]} +{"level":"info","ts":"2023-10-12T11:15:09.272338+0800","caller":"embed/etcd.go:626","msg":"pprof is enabled","path":"/debug/pprof"} +{"level":"info","ts":"2023-10-12T11:15:09.272386+0800","caller":"embed/etcd.go:313","msg":"starting an etcd server","etcd-version":"3.6.0-alpha.0","git-sha":"b57fe9e9d","go-version":"go1.21.1","go-os":"linux","go-arch":"amd64","max-cpu-set":8,"max-cpu-available":8,"member-initialized":false,"name":"infra3","data-dir":"infra3.etcd","wal-dir":"","wal-dir-dedicated":"","member-dir":"infra3.etcd/member","force-new-cluster":false,"heartbeat-interval":"100ms","election-timeout":"1s","wait-cluster-ready-timeout":"5s","initial-election-tick-advance":true,"snapshot-count":10000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://127.0.0.1:32380"],"listen-peer-urls":["http://127.0.0.1:32380"],"advertise-client-urls":["http://127.0.0.1:32379"],"listen-client-urls":["http://127.0.0.1:32379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"infra1=http://127.0.0.1:12380,infra2=http://127.0.0.1:22380,infra3=http://127.0.0.1:32380","initial-cluster-state":"new","initial-cluster-token":"etcd-cluster-1","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"periodic","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","discovery-token":"","discovery-endpoints":"","discovery-dial-timeout":"2s","discovery-request-timeout":"5s","discovery-keepalive-time":"2s","discovery-keepalive-timeout":"6s","discovery-insecure-transport":true,"discovery-insecure-skip-tls-verify":false,"discovery-cert":"","discovery-key":"","discovery-cacert":"","discovery-user":"","downgrade-check-interval":"5s","max-learners":1} +{"level":"info","ts":"2023-10-12T11:15:09.276991+0800","caller":"storage/backend.go:80","msg":"opened backend db","path":"infra1.etcd/member/snap/db","took":"4.6926ms"} +{"level":"info","ts":"2023-10-12T11:15:09.276991+0800","caller":"storage/backend.go:80","msg":"opened backend db","path":"infra3.etcd/member/snap/db","took":"4.2418ms"} +{"level":"debug","ts":"2023-10-12T11:15:09.277071+0800","caller":"etcdserver/bootstrap.go:219","msg":"restore consistentIndex","index":0} +{"level":"debug","ts":"2023-10-12T11:15:09.277072+0800","caller":"etcdserver/bootstrap.go:219","msg":"restore consistentIndex","index":0} +{"level":"info","ts":"2023-10-12T11:15:09.279059+0800","caller":"storage/backend.go:80","msg":"opened backend db","path":"infra2.etcd/member/snap/db","took":"6.4224ms"} +{"level":"debug","ts":"2023-10-12T11:15:09.2791+0800","caller":"etcdserver/bootstrap.go:219","msg":"restore consistentIndex","index":0} +{"level":"info","ts":"2023-10-12T11:15:11.29087+0800","caller":"etcdserver/bootstrap.go:493","msg":"starting local member","local-member-id":"8211f1d0f64f3269","cluster-id":"ef37ad9dc622a7c4"} +{"level":"info","ts":"2023-10-12T11:15:11.29087+0800","caller":"etcdserver/bootstrap.go:493","msg":"starting local member","local-member-id":"fd422379fda50e48","cluster-id":"ef37ad9dc622a7c4"} +{"level":"info","ts":"2023-10-12T11:15:11.290951+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"8211f1d0f64f3269 switched to configuration voters=()"} +{"level":"info","ts":"2023-10-12T11:15:11.290957+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"fd422379fda50e48 switched to configuration voters=()"} +{"level":"info","ts":"2023-10-12T11:15:11.291043+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:875","msg":"8211f1d0f64f3269 became follower at term 0"} +{"level":"info","ts":"2023-10-12T11:15:11.291043+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:875","msg":"fd422379fda50e48 became follower at term 0"} +{"level":"info","ts":"2023-10-12T11:15:11.291055+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:483","msg":"newRaft fd422379fda50e48 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} +{"level":"info","ts":"2023-10-12T11:15:11.29106+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:483","msg":"newRaft 8211f1d0f64f3269 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} +{"level":"info","ts":"2023-10-12T11:15:11.291066+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:875","msg":"fd422379fda50e48 became follower at term 1"} +{"level":"info","ts":"2023-10-12T11:15:11.291096+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:875","msg":"8211f1d0f64f3269 became follower at term 1"} +{"level":"info","ts":"2023-10-12T11:15:11.291134+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"fd422379fda50e48 switched to configuration voters=(9372538179322589801)"} +{"level":"info","ts":"2023-10-12T11:15:11.291145+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"fd422379fda50e48 switched to configuration voters=(9372538179322589801 10501334649042878790)"} +{"level":"info","ts":"2023-10-12T11:15:11.291154+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"fd422379fda50e48 switched to configuration voters=(9372538179322589801 10501334649042878790 18249187646912138824)"} +{"level":"info","ts":"2023-10-12T11:15:11.291158+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"8211f1d0f64f3269 switched to configuration voters=(9372538179322589801)"} +{"level":"info","ts":"2023-10-12T11:15:11.29117+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"8211f1d0f64f3269 switched to configuration voters=(9372538179322589801 10501334649042878790)"} +{"level":"info","ts":"2023-10-12T11:15:11.291185+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"8211f1d0f64f3269 switched to configuration voters=(9372538179322589801 10501334649042878790 18249187646912138824)"} +{"level":"warn","ts":"2023-10-12T11:15:11.294301+0800","caller":"auth/store.go:1137","msg":"simple token is not cryptographically signed"} +{"level":"warn","ts":"2023-10-12T11:15:11.295334+0800","caller":"auth/store.go:1137","msg":"simple token is not cryptographically signed"} +{"level":"info","ts":"2023-10-12T11:15:11.297853+0800","caller":"etcdserver/bootstrap.go:493","msg":"starting local member","local-member-id":"91bc3c398fb3c146","cluster-id":"ef37ad9dc622a7c4"} +{"level":"info","ts":"2023-10-12T11:15:11.297863+0800","caller":"mvcc/kvstore.go:402","msg":"kvstore restored","current-rev":1} +{"level":"debug","ts":"2023-10-12T11:15:11.297908+0800","caller":"auth/range_perm_cache.go:137","msg":"Refreshing rangePermCache"} +{"level":"info","ts":"2023-10-12T11:15:11.297919+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"91bc3c398fb3c146 switched to configuration voters=()"} +{"level":"info","ts":"2023-10-12T11:15:11.297961+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:875","msg":"91bc3c398fb3c146 became follower at term 0"} +{"level":"info","ts":"2023-10-12T11:15:11.29797+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:483","msg":"newRaft 91bc3c398fb3c146 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} +{"level":"info","ts":"2023-10-12T11:15:11.297996+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:875","msg":"91bc3c398fb3c146 became follower at term 1"} +{"level":"info","ts":"2023-10-12T11:15:11.298034+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"91bc3c398fb3c146 switched to configuration voters=(9372538179322589801)"} +{"level":"info","ts":"2023-10-12T11:15:11.298065+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"91bc3c398fb3c146 switched to configuration voters=(9372538179322589801 10501334649042878790)"} +{"level":"info","ts":"2023-10-12T11:15:11.298075+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"91bc3c398fb3c146 switched to configuration voters=(9372538179322589801 10501334649042878790 18249187646912138824)"} +{"level":"info","ts":"2023-10-12T11:15:11.299627+0800","caller":"mvcc/kvstore.go:402","msg":"kvstore restored","current-rev":1} +{"level":"debug","ts":"2023-10-12T11:15:11.299874+0800","caller":"auth/range_perm_cache.go:137","msg":"Refreshing rangePermCache"} +{"level":"warn","ts":"2023-10-12T11:15:11.301006+0800","caller":"auth/store.go:1137","msg":"simple token is not cryptographically signed"} +{"level":"info","ts":"2023-10-12T11:15:11.304102+0800","caller":"storage/quota.go:93","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"} +{"level":"info","ts":"2023-10-12T11:15:11.304176+0800","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.304297+0800","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"8211f1d0f64f3269","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.304407+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"8211f1d0f64f3269","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.304449+0800","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.304468+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"8211f1d0f64f3269","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.304479+0800","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"8211f1d0f64f3269","remote-peer-id":"91bc3c398fb3c146","remote-peer-urls":["http://127.0.0.1:22380"]} +{"level":"info","ts":"2023-10-12T11:15:11.304504+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"8211f1d0f64f3269","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.304508+0800","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.304515+0800","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"8211f1d0f64f3269","remote-peer-id":"fd422379fda50e48"} +{"level":"debug","ts":"2023-10-12T11:15:11.304518+0800","caller":"rafthttp/stream.go:570","msg":"dial stream reader","from":"8211f1d0f64f3269","to":"91bc3c398fb3c146","address":"http://127.0.0.1:22380/raft/stream/msgapp/8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.304563+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"8211f1d0f64f3269","remote-peer-id":"91bc3c398fb3c146"} +{"level":"debug","ts":"2023-10-12T11:15:11.30478+0800","caller":"rafthttp/stream.go:570","msg":"dial stream reader","from":"8211f1d0f64f3269","to":"91bc3c398fb3c146","address":"http://127.0.0.1:22380/raft/stream/message/8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.304845+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"8211f1d0f64f3269","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.30491+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"8211f1d0f64f3269","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.305137+0800","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.305159+0800","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"8211f1d0f64f3269","remote-peer-id":"fd422379fda50e48","remote-peer-urls":["http://127.0.0.1:32380"]} +{"level":"info","ts":"2023-10-12T11:15:11.305206+0800","caller":"etcdserver/server.go:580","msg":"starting etcd server","local-member-id":"8211f1d0f64f3269","local-server-version":"3.6.0-alpha.0","cluster-version":"to_be_decided"} +{"level":"info","ts":"2023-10-12T11:15:11.30531+0800","caller":"embed/etcd.go:282","msg":"now serving peer/client/metrics","local-member-id":"8211f1d0f64f3269","initial-advertise-peer-urls":["http://127.0.0.1:12380"],"listen-peer-urls":["http://127.0.0.1:12380"],"advertise-client-urls":["http://127.0.0.1:2379"],"listen-client-urls":["http://127.0.0.1:2379"],"listen-metrics-urls":[]} +{"level":"info","ts":"2023-10-12T11:15:11.305317+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"8211f1d0f64f3269","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.305452+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"8211f1d0f64f3269","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.305463+0800","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"infra1.etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} +{"level":"debug","ts":"2023-10-12T11:15:11.305467+0800","caller":"rafthttp/stream.go:570","msg":"dial stream reader","from":"8211f1d0f64f3269","to":"fd422379fda50e48","address":"http://127.0.0.1:32380/raft/stream/message/8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.30549+0800","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"infra1.etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} +{"level":"info","ts":"2023-10-12T11:15:11.305497+0800","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"infra1.etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} +{"level":"debug","ts":"2023-10-12T11:15:11.305598+0800","caller":"rafthttp/stream.go:570","msg":"dial stream reader","from":"8211f1d0f64f3269","to":"fd422379fda50e48","address":"http://127.0.0.1:32380/raft/stream/msgapp/8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.305694+0800","caller":"etcdserver/server.go:481","msg":"starting initial election tick advance","election-ticks":10} +{"level":"info","ts":"2023-10-12T11:15:11.305708+0800","caller":"embed/etcd.go:607","msg":"serving peer traffic","address":"127.0.0.1:12380"} +{"level":"info","ts":"2023-10-12T11:15:11.305728+0800","caller":"mvcc/kvstore.go:402","msg":"kvstore restored","current-rev":1} +{"level":"info","ts":"2023-10-12T11:15:11.305754+0800","caller":"embed/etcd.go:579","msg":"cmux::serve","address":"127.0.0.1:12380"} +{"level":"debug","ts":"2023-10-12T11:15:11.305757+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":3} +{"level":"debug","ts":"2023-10-12T11:15:11.305781+0800","caller":"auth/range_perm_cache.go:137","msg":"Refreshing rangePermCache"} +{"level":"debug","ts":"2023-10-12T11:15:11.305782+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":1,"term":1,"type":"EntryConfChange"} +{"level":"debug","ts":"2023-10-12T11:15:11.306666+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ApplyConfChange","nid":9372538179322589801,"state":{"term":1,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"cc":{"newconf":[9372538179322589801,10501334649042878790,18249187646912138824]}}} +{"level":"info","ts":"2023-10-12T11:15:11.306793+0800","caller":"storage/quota.go:93","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"} +{"level":"info","ts":"2023-10-12T11:15:11.306844+0800","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.306884+0800","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"fd422379fda50e48","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.307014+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"fd422379fda50e48","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.307042+0800","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.307057+0800","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"fd422379fda50e48","remote-peer-id":"8211f1d0f64f3269","remote-peer-urls":["http://127.0.0.1:12380"]} +{"level":"info","ts":"2023-10-12T11:15:11.30706+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"fd422379fda50e48","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.307067+0800","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.307073+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"fd422379fda50e48","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.307075+0800","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"fd422379fda50e48","remote-peer-id":"91bc3c398fb3c146"} +{"level":"debug","ts":"2023-10-12T11:15:11.307089+0800","caller":"rafthttp/stream.go:570","msg":"dial stream reader","from":"fd422379fda50e48","to":"8211f1d0f64f3269","address":"http://127.0.0.1:12380/raft/stream/message/fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.30711+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"8211f1d0f64f3269 switched to configuration voters=(9372538179322589801 10501334649042878790 18249187646912138824)"} +{"level":"info","ts":"2023-10-12T11:15:11.307184+0800","caller":"membership/cluster.go:403","msg":"added member","cluster-id":"ef37ad9dc622a7c4","local-member-id":"8211f1d0f64f3269","added-peer-id":"8211f1d0f64f3269","added-peer-peer-urls":["http://127.0.0.1:12380"],"added-peer-is-learner":false} +{"level":"debug","ts":"2023-10-12T11:15:11.307216+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":2,"term":1,"type":"EntryConfChange"} +{"level":"debug","ts":"2023-10-12T11:15:11.30726+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ApplyConfChange","nid":9372538179322589801,"state":{"term":1,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"cc":{"newconf":[9372538179322589801,10501334649042878790,18249187646912138824]}}} +{"level":"info","ts":"2023-10-12T11:15:11.307276+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"8211f1d0f64f3269 switched to configuration voters=(9372538179322589801 10501334649042878790 18249187646912138824)"} +{"level":"info","ts":"2023-10-12T11:15:11.307289+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"fd422379fda50e48","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.307313+0800","caller":"membership/cluster.go:403","msg":"added member","cluster-id":"ef37ad9dc622a7c4","local-member-id":"8211f1d0f64f3269","added-peer-id":"91bc3c398fb3c146","added-peer-peer-urls":["http://127.0.0.1:22380"],"added-peer-is-learner":false} +{"level":"info","ts":"2023-10-12T11:15:11.307335+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"fd422379fda50e48","remote-peer-id":"91bc3c398fb3c146"} +{"level":"debug","ts":"2023-10-12T11:15:11.307339+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":3,"term":1,"type":"EntryConfChange"} +{"level":"info","ts":"2023-10-12T11:15:11.30735+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"fd422379fda50e48","remote-peer-id":"91bc3c398fb3c146"} +{"level":"debug","ts":"2023-10-12T11:15:11.307409+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ApplyConfChange","nid":9372538179322589801,"state":{"term":1,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"cc":{"newconf":[9372538179322589801,10501334649042878790,18249187646912138824]}}} +{"level":"info","ts":"2023-10-12T11:15:11.30744+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"8211f1d0f64f3269 switched to configuration voters=(9372538179322589801 10501334649042878790 18249187646912138824)"} +{"level":"debug","ts":"2023-10-12T11:15:11.307441+0800","caller":"rafthttp/stream.go:570","msg":"dial stream reader","from":"fd422379fda50e48","to":"8211f1d0f64f3269","address":"http://127.0.0.1:12380/raft/stream/msgapp/fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.307467+0800","caller":"membership/cluster.go:403","msg":"added member","cluster-id":"ef37ad9dc622a7c4","local-member-id":"8211f1d0f64f3269","added-peer-id":"fd422379fda50e48","added-peer-peer-urls":["http://127.0.0.1:32380"],"added-peer-is-learner":false} +{"level":"info","ts":"2023-10-12T11:15:11.307559+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"8211f1d0f64f3269","to":"fd422379fda50e48","stream-type":"stream Message"} +{"level":"info","ts":"2023-10-12T11:15:11.307573+0800","caller":"rafthttp/peer_status.go:53","msg":"peer became active","peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.307582+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"8211f1d0f64f3269","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.307611+0800","caller":"rafthttp/peer_status.go:53","msg":"peer became active","peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.30765+0800","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.307653+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"fd422379fda50e48","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.307679+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"fd422379fda50e48","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.307712+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"fd422379fda50e48","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.307721+0800","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"fd422379fda50e48","remote-peer-id":"91bc3c398fb3c146","remote-peer-urls":["http://127.0.0.1:22380"]} +{"level":"debug","ts":"2023-10-12T11:15:11.307752+0800","caller":"rafthttp/stream.go:570","msg":"dial stream reader","from":"fd422379fda50e48","to":"91bc3c398fb3c146","address":"http://127.0.0.1:22380/raft/stream/msgapp/fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.30777+0800","caller":"etcdserver/server.go:580","msg":"starting etcd server","local-member-id":"fd422379fda50e48","local-server-version":"3.6.0-alpha.0","cluster-version":"to_be_decided"} +{"level":"debug","ts":"2023-10-12T11:15:11.307794+0800","caller":"rafthttp/stream.go:570","msg":"dial stream reader","from":"fd422379fda50e48","to":"91bc3c398fb3c146","address":"http://127.0.0.1:22380/raft/stream/message/fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.307818+0800","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"infra3.etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} +{"level":"info","ts":"2023-10-12T11:15:11.307841+0800","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"infra3.etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} +{"level":"info","ts":"2023-10-12T11:15:11.307848+0800","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"infra3.etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} +{"level":"info","ts":"2023-10-12T11:15:11.307884+0800","caller":"etcdserver/server.go:481","msg":"starting initial election tick advance","election-ticks":10} +{"level":"info","ts":"2023-10-12T11:15:11.30795+0800","caller":"embed/etcd.go:607","msg":"serving peer traffic","address":"127.0.0.1:32380"} +{"level":"info","ts":"2023-10-12T11:15:11.307955+0800","caller":"embed/etcd.go:282","msg":"now serving peer/client/metrics","local-member-id":"fd422379fda50e48","initial-advertise-peer-urls":["http://127.0.0.1:32380"],"listen-peer-urls":["http://127.0.0.1:32380"],"advertise-client-urls":["http://127.0.0.1:32379"],"listen-client-urls":["http://127.0.0.1:32379"],"listen-metrics-urls":[]} +{"level":"info","ts":"2023-10-12T11:15:11.307982+0800","caller":"embed/etcd.go:579","msg":"cmux::serve","address":"127.0.0.1:32380"} +{"level":"info","ts":"2023-10-12T11:15:11.308006+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"fd422379fda50e48","remote-peer-id":"8211f1d0f64f3269"} +{"level":"debug","ts":"2023-10-12T11:15:11.308068+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":3} +{"level":"debug","ts":"2023-10-12T11:15:11.308115+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":1,"term":1,"type":"EntryConfChange"} +{"level":"debug","ts":"2023-10-12T11:15:11.308238+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ApplyConfChange","nid":18249187646912138824,"state":{"term":1,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"cc":{"newconf":[9372538179322589801,10501334649042878790,18249187646912138824]}}} +{"level":"info","ts":"2023-10-12T11:15:11.308492+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"8211f1d0f64f3269","to":"fd422379fda50e48","stream-type":"stream MsgApp v2"} +{"level":"info","ts":"2023-10-12T11:15:11.308568+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"8211f1d0f64f3269","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.309218+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"fd422379fda50e48","to":"8211f1d0f64f3269","stream-type":"stream Message"} +{"level":"info","ts":"2023-10-12T11:15:11.309268+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"fd422379fda50e48","to":"8211f1d0f64f3269","stream-type":"stream MsgApp v2"} +{"level":"info","ts":"2023-10-12T11:15:11.309275+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"fd422379fda50e48","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.309288+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"fd422379fda50e48","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.309293+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"8211f1d0f64f3269","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.309364+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"fd422379fda50e48 switched to configuration voters=(9372538179322589801 10501334649042878790 18249187646912138824)"} +{"level":"info","ts":"2023-10-12T11:15:11.309376+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"8211f1d0f64f3269","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.309477+0800","caller":"membership/cluster.go:403","msg":"added member","cluster-id":"ef37ad9dc622a7c4","local-member-id":"fd422379fda50e48","added-peer-id":"8211f1d0f64f3269","added-peer-peer-urls":["http://127.0.0.1:12380"],"added-peer-is-learner":false} +{"level":"debug","ts":"2023-10-12T11:15:11.309517+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":2,"term":1,"type":"EntryConfChange"} +{"level":"debug","ts":"2023-10-12T11:15:11.30961+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ApplyConfChange","nid":18249187646912138824,"state":{"term":1,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"cc":{"newconf":[9372538179322589801,10501334649042878790,18249187646912138824]}}} +{"level":"info","ts":"2023-10-12T11:15:11.309653+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"fd422379fda50e48 switched to configuration voters=(9372538179322589801 10501334649042878790 18249187646912138824)"} +{"level":"info","ts":"2023-10-12T11:15:11.309725+0800","caller":"membership/cluster.go:403","msg":"added member","cluster-id":"ef37ad9dc622a7c4","local-member-id":"fd422379fda50e48","added-peer-id":"91bc3c398fb3c146","added-peer-peer-urls":["http://127.0.0.1:22380"],"added-peer-is-learner":false} +{"level":"debug","ts":"2023-10-12T11:15:11.30976+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":3,"term":1,"type":"EntryConfChange"} +{"level":"debug","ts":"2023-10-12T11:15:11.309819+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ApplyConfChange","nid":18249187646912138824,"state":{"term":1,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"cc":{"newconf":[9372538179322589801,10501334649042878790,18249187646912138824]}}} +{"level":"info","ts":"2023-10-12T11:15:11.309855+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"fd422379fda50e48 switched to configuration voters=(9372538179322589801 10501334649042878790 18249187646912138824)"} +{"level":"info","ts":"2023-10-12T11:15:11.309912+0800","caller":"membership/cluster.go:403","msg":"added member","cluster-id":"ef37ad9dc622a7c4","local-member-id":"fd422379fda50e48","added-peer-id":"fd422379fda50e48","added-peer-peer-urls":["http://127.0.0.1:32380"],"added-peer-is-learner":false} +{"level":"info","ts":"2023-10-12T11:15:11.312583+0800","caller":"storage/quota.go:93","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"} +{"level":"info","ts":"2023-10-12T11:15:11.312634+0800","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.312667+0800","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"91bc3c398fb3c146","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.31281+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"91bc3c398fb3c146","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.312824+0800","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.312832+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"91bc3c398fb3c146","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.312846+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"91bc3c398fb3c146","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.312861+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"91bc3c398fb3c146","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.312874+0800","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"91bc3c398fb3c146","remote-peer-id":"8211f1d0f64f3269","remote-peer-urls":["http://127.0.0.1:12380"]} +{"level":"info","ts":"2023-10-12T11:15:11.312887+0800","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"fd422379fda50e48"} +{"level":"debug","ts":"2023-10-12T11:15:11.312888+0800","caller":"rafthttp/stream.go:570","msg":"dial stream reader","from":"91bc3c398fb3c146","to":"8211f1d0f64f3269","address":"http://127.0.0.1:12380/raft/stream/msgapp/91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.312895+0800","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"91bc3c398fb3c146","remote-peer-id":"fd422379fda50e48"} +{"level":"debug","ts":"2023-10-12T11:15:11.313098+0800","caller":"rafthttp/stream.go:570","msg":"dial stream reader","from":"91bc3c398fb3c146","to":"8211f1d0f64f3269","address":"http://127.0.0.1:12380/raft/stream/message/91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.313469+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"91bc3c398fb3c146","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.313555+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"91bc3c398fb3c146","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.313583+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"8211f1d0f64f3269","to":"91bc3c398fb3c146","stream-type":"stream MsgApp v2"} +{"level":"info","ts":"2023-10-12T11:15:11.313591+0800","caller":"rafthttp/peer_status.go:53","msg":"peer became active","peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.313597+0800","caller":"rafthttp/peer_status.go:53","msg":"peer became active","peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.313606+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"8211f1d0f64f3269","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.313607+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"91bc3c398fb3c146","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.313692+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"8211f1d0f64f3269","to":"91bc3c398fb3c146","stream-type":"stream Message"} +{"level":"info","ts":"2023-10-12T11:15:11.313718+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"8211f1d0f64f3269","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.313965+0800","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.314013+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"91bc3c398fb3c146","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.314049+0800","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"91bc3c398fb3c146","remote-peer-id":"fd422379fda50e48","remote-peer-urls":["http://127.0.0.1:32380"]} +{"level":"info","ts":"2023-10-12T11:15:11.314063+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"91bc3c398fb3c146","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.314075+0800","caller":"etcdserver/server.go:580","msg":"starting etcd server","local-member-id":"91bc3c398fb3c146","local-server-version":"3.6.0-alpha.0","cluster-version":"to_be_decided"} +{"level":"info","ts":"2023-10-12T11:15:11.314095+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"91bc3c398fb3c146","remote-peer-id":"fd422379fda50e48"} +{"level":"debug","ts":"2023-10-12T11:15:11.314101+0800","caller":"rafthttp/stream.go:570","msg":"dial stream reader","from":"91bc3c398fb3c146","to":"fd422379fda50e48","address":"http://127.0.0.1:32380/raft/stream/msgapp/91bc3c398fb3c146"} +{"level":"debug","ts":"2023-10-12T11:15:11.314122+0800","caller":"rafthttp/stream.go:570","msg":"dial stream reader","from":"91bc3c398fb3c146","to":"fd422379fda50e48","address":"http://127.0.0.1:32380/raft/stream/message/91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.314196+0800","caller":"embed/etcd.go:282","msg":"now serving peer/client/metrics","local-member-id":"91bc3c398fb3c146","initial-advertise-peer-urls":["http://127.0.0.1:22380"],"listen-peer-urls":["http://127.0.0.1:22380"],"advertise-client-urls":["http://127.0.0.1:22379"],"listen-client-urls":["http://127.0.0.1:22379"],"listen-metrics-urls":[]} +{"level":"info","ts":"2023-10-12T11:15:11.314216+0800","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"infra2.etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} +{"level":"info","ts":"2023-10-12T11:15:11.314279+0800","caller":"embed/etcd.go:607","msg":"serving peer traffic","address":"127.0.0.1:22380"} +{"level":"info","ts":"2023-10-12T11:15:11.31429+0800","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"infra2.etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} +{"level":"info","ts":"2023-10-12T11:15:11.314291+0800","caller":"embed/etcd.go:579","msg":"cmux::serve","address":"127.0.0.1:22380"} +{"level":"info","ts":"2023-10-12T11:15:11.314302+0800","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"infra2.etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} +{"level":"info","ts":"2023-10-12T11:15:11.314353+0800","caller":"etcdserver/server.go:481","msg":"starting initial election tick advance","election-ticks":10} +{"level":"debug","ts":"2023-10-12T11:15:11.314409+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":3} +{"level":"info","ts":"2023-10-12T11:15:11.314413+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"fd422379fda50e48","to":"91bc3c398fb3c146","stream-type":"stream MsgApp v2"} +{"level":"debug","ts":"2023-10-12T11:15:11.31442+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":1,"term":1,"type":"EntryConfChange"} +{"level":"info","ts":"2023-10-12T11:15:11.314426+0800","caller":"rafthttp/peer_status.go:53","msg":"peer became active","peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.314433+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"fd422379fda50e48","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.314478+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"fd422379fda50e48","to":"91bc3c398fb3c146","stream-type":"stream Message"} +{"level":"info","ts":"2023-10-12T11:15:11.314485+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"fd422379fda50e48","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.314493+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"91bc3c398fb3c146","to":"fd422379fda50e48","stream-type":"stream MsgApp v2"} +{"level":"info","ts":"2023-10-12T11:15:11.314498+0800","caller":"rafthttp/peer_status.go:53","msg":"peer became active","peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.314506+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"fd422379fda50e48","remote-peer-id":"91bc3c398fb3c146"} +{"level":"debug","ts":"2023-10-12T11:15:11.314511+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ApplyConfChange","nid":10501334649042878790,"state":{"term":1,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"cc":{"newconf":[9372538179322589801,10501334649042878790,18249187646912138824]}}} +{"level":"info","ts":"2023-10-12T11:15:11.314516+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"91bc3c398fb3c146","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.314529+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"91bc3c398fb3c146","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.314543+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"91bc3c398fb3c146","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.314575+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"91bc3c398fb3c146","to":"8211f1d0f64f3269","stream-type":"stream Message"} +{"level":"info","ts":"2023-10-12T11:15:11.314656+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"8211f1d0f64f3269","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.314666+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"8211f1d0f64f3269","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.314854+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"91bc3c398fb3c146","to":"8211f1d0f64f3269","stream-type":"stream MsgApp v2"} +{"level":"info","ts":"2023-10-12T11:15:11.314858+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"91bc3c398fb3c146","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.314879+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"91bc3c398fb3c146","remote-peer-id":"8211f1d0f64f3269"} +{"level":"info","ts":"2023-10-12T11:15:11.31488+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"fd422379fda50e48","remote-peer-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:11.314929+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"91bc3c398fb3c146","to":"fd422379fda50e48","stream-type":"stream Message"} +{"level":"info","ts":"2023-10-12T11:15:11.315016+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"91bc3c398fb3c146 switched to configuration voters=(9372538179322589801 10501334649042878790 18249187646912138824)"} +{"level":"info","ts":"2023-10-12T11:15:11.315049+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"91bc3c398fb3c146","remote-peer-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:11.315106+0800","caller":"membership/cluster.go:403","msg":"added member","cluster-id":"ef37ad9dc622a7c4","local-member-id":"91bc3c398fb3c146","added-peer-id":"8211f1d0f64f3269","added-peer-peer-urls":["http://127.0.0.1:12380"],"added-peer-is-learner":false} +{"level":"debug","ts":"2023-10-12T11:15:11.315124+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":2,"term":1,"type":"EntryConfChange"} +{"level":"debug","ts":"2023-10-12T11:15:11.315163+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ApplyConfChange","nid":10501334649042878790,"state":{"term":1,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"cc":{"newconf":[9372538179322589801,10501334649042878790,18249187646912138824]}}} +{"level":"info","ts":"2023-10-12T11:15:11.315181+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"91bc3c398fb3c146 switched to configuration voters=(9372538179322589801 10501334649042878790 18249187646912138824)"} +{"level":"info","ts":"2023-10-12T11:15:11.315211+0800","caller":"membership/cluster.go:403","msg":"added member","cluster-id":"ef37ad9dc622a7c4","local-member-id":"91bc3c398fb3c146","added-peer-id":"91bc3c398fb3c146","added-peer-peer-urls":["http://127.0.0.1:22380"],"added-peer-is-learner":false} +{"level":"debug","ts":"2023-10-12T11:15:11.31522+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":3,"term":1,"type":"EntryConfChange"} +{"level":"debug","ts":"2023-10-12T11:15:11.315248+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ApplyConfChange","nid":10501334649042878790,"state":{"term":1,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"cc":{"newconf":[9372538179322589801,10501334649042878790,18249187646912138824]}}} +{"level":"info","ts":"2023-10-12T11:15:11.315261+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1942","msg":"91bc3c398fb3c146 switched to configuration voters=(9372538179322589801 10501334649042878790 18249187646912138824)"} +{"level":"info","ts":"2023-10-12T11:15:11.315285+0800","caller":"membership/cluster.go:403","msg":"added member","cluster-id":"ef37ad9dc622a7c4","local-member-id":"91bc3c398fb3c146","added-peer-id":"fd422379fda50e48","added-peer-peer-urls":["http://127.0.0.1:32380"],"added-peer-is-learner":false} +{"level":"info","ts":"2023-10-12T11:15:11.356198+0800","caller":"etcdserver/server.go:504","msg":"initialized peer connections; fast-forwarding election ticks","local-member-id":"8211f1d0f64f3269","forward-ticks":8,"forward-duration":"800ms","election-ticks":10,"election-timeout":"1s","active-remote-members":2} +{"level":"info","ts":"2023-10-12T11:15:11.358109+0800","caller":"etcdserver/server.go:504","msg":"initialized peer connections; fast-forwarding election ticks","local-member-id":"fd422379fda50e48","forward-ticks":8,"forward-duration":"800ms","election-ticks":10,"election-timeout":"1s","active-remote-members":2} +{"level":"info","ts":"2023-10-12T11:15:11.364825+0800","caller":"etcdserver/server.go:504","msg":"initialized peer connections; fast-forwarding election ticks","local-member-id":"91bc3c398fb3c146","forward-ticks":8,"forward-duration":"800ms","election-ticks":10,"election-timeout":"1s","active-remote-members":2} +{"level":"info","ts":"2023-10-12T11:15:11.691855+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:969","msg":"fd422379fda50e48 is starting a new election at term 1"} +{"level":"info","ts":"2023-10-12T11:15:11.691975+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:909","msg":"fd422379fda50e48 became pre-candidate at term 1"} +{"level":"info","ts":"2023-10-12T11:15:11.692037+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1043","msg":"fd422379fda50e48 [logterm: 1, index: 3] sent MsgPreVote request to 8211f1d0f64f3269 at term 1"} +{"level":"info","ts":"2023-10-12T11:15:11.692063+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1043","msg":"fd422379fda50e48 [logterm: 1, index: 3] sent MsgPreVote request to 91bc3c398fb3c146 at term 1"} +{"level":"info","ts":"2023-10-12T11:15:11.692182+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1056","msg":"fd422379fda50e48 received MsgPreVoteResp from fd422379fda50e48 at term 1"} +{"level":"info","ts":"2023-10-12T11:15:11.692268+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1669","msg":"fd422379fda50e48 has received 1 MsgPreVoteResp votes and 0 vote rejections"} +{"level":"info","ts":"2023-10-12T11:15:11.692507+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1206","msg":"8211f1d0f64f3269 [logterm: 1, index: 3, vote: 0] cast MsgPreVote for fd422379fda50e48 [logterm: 1, index: 3] at term 1"} +{"level":"info","ts":"2023-10-12T11:15:11.692786+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1206","msg":"91bc3c398fb3c146 [logterm: 1, index: 3, vote: 0] cast MsgPreVote for fd422379fda50e48 [logterm: 1, index: 3] at term 1"} +{"level":"info","ts":"2023-10-12T11:15:11.692963+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1056","msg":"fd422379fda50e48 received MsgPreVoteResp from 8211f1d0f64f3269 at term 1"} +{"level":"info","ts":"2023-10-12T11:15:11.693057+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1669","msg":"fd422379fda50e48 has received 2 MsgPreVoteResp votes and 0 vote rejections"} +{"level":"info","ts":"2023-10-12T11:15:11.6931+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:891","msg":"fd422379fda50e48 became candidate at term 2"} +{"level":"debug","ts":"2023-10-12T11:15:11.69312+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"BecomeCandidate","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateCandidate","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"info","ts":"2023-10-12T11:15:11.693162+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1043","msg":"fd422379fda50e48 [logterm: 1, index: 3] sent MsgVote request to 8211f1d0f64f3269 at term 2"} +{"level":"debug","ts":"2023-10-12T11:15:11.693181+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendRequestVoteRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateCandidate","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVote","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":0,"logTerm":1,"index":3,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.693206+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1043","msg":"fd422379fda50e48 [logterm: 1, index: 3] sent MsgVote request to 91bc3c398fb3c146 at term 2"} +{"level":"debug","ts":"2023-10-12T11:15:11.693223+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendRequestVoteRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateCandidate","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVote","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":1,"index":3,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.693374+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendRequestVoteResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateCandidate","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVoteResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":0,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.696396+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveRequestVoteResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateCandidate","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVoteResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":0,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.696513+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1056","msg":"fd422379fda50e48 received MsgVoteResp from fd422379fda50e48 at term 2"} +{"level":"info","ts":"2023-10-12T11:15:11.696546+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1669","msg":"fd422379fda50e48 has received 1 MsgVoteResp votes and 0 vote rejections"} +{"level":"debug","ts":"2023-10-12T11:15:11.696801+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveRequestVoteRequest","nid":9372538179322589801,"state":{"term":1,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVote","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":0,"logTerm":1,"index":3,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.696866+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1093","msg":"8211f1d0f64f3269 [term: 1] received a MsgVote message with higher term from fd422379fda50e48 [term: 2]"} +{"level":"debug","ts":"2023-10-12T11:15:11.696893+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveRequestVoteRequest","nid":10501334649042878790,"state":{"term":1,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVote","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":1,"index":3,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.696906+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:875","msg":"8211f1d0f64f3269 became follower at term 2"} +{"level":"debug","ts":"2023-10-12T11:15:11.69694+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"BecomeFollower","nid":9372538179322589801,"state":{"term":2,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"info","ts":"2023-10-12T11:15:11.696957+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1093","msg":"91bc3c398fb3c146 [term: 1] received a MsgVote message with higher term from fd422379fda50e48 [term: 2]"} +{"level":"info","ts":"2023-10-12T11:15:11.696967+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1206","msg":"8211f1d0f64f3269 [logterm: 1, index: 3, vote: 0] cast MsgVote for fd422379fda50e48 [logterm: 1, index: 3] at term 2"} +{"level":"debug","ts":"2023-10-12T11:15:11.696987+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendRequestVoteResponse","nid":9372538179322589801,"state":{"term":2,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVoteResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":0,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.696991+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:875","msg":"91bc3c398fb3c146 became follower at term 2"} +{"level":"debug","ts":"2023-10-12T11:15:11.697006+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"BecomeFollower","nid":10501334649042878790,"state":{"term":2,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"info","ts":"2023-10-12T11:15:11.69703+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1206","msg":"91bc3c398fb3c146 [logterm: 1, index: 3, vote: 0] cast MsgVote for fd422379fda50e48 [logterm: 1, index: 3] at term 2"} +{"level":"debug","ts":"2023-10-12T11:15:11.697057+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendRequestVoteResponse","nid":10501334649042878790,"state":{"term":2,"vote":0,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVoteResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":0,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.699155+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveRequestVoteResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateCandidate","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVoteResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":0,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.699295+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1056","msg":"fd422379fda50e48 received MsgVoteResp from 91bc3c398fb3c146 at term 2"} +{"level":"info","ts":"2023-10-12T11:15:11.699328+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1669","msg":"fd422379fda50e48 has received 2 MsgVoteResp votes and 0 vote rejections"} +{"level":"debug","ts":"2023-10-12T11:15:11.699359+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"BecomeLeader","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.699386+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":4,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.699404+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:951","msg":"fd422379fda50e48 became leader at term 2"} +{"level":"debug","ts":"2023-10-12T11:15:11.699423+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":1,"logTerm":1,"index":3,"commit":3,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.699445+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":1,"logTerm":1,"index":3,"commit":3,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.699465+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/node.go:370","msg":"raft.node: fd422379fda50e48 elected leader fd422379fda50e48 at term 2"} +{"level":"debug","ts":"2023-10-12T11:15:11.699536+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Replicate","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.699624+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":5,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.699679+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveRequestVoteResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVoteResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":0,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.700126+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":1,"logTerm":1,"index":3,"commit":3,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.700235+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":4,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.70028+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/node.go:370","msg":"raft.node: 8211f1d0f64f3269 elected leader fd422379fda50e48 at term 2"} +{"level":"debug","ts":"2023-10-12T11:15:11.700466+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":1,"logTerm":1,"index":3,"commit":3,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.70059+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":4,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.700637+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/node.go:370","msg":"raft.node: 91bc3c398fb3c146 elected leader fd422379fda50e48 at term 2"} +{"level":"debug","ts":"2023-10-12T11:15:11.701449+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":4,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.701557+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.701597+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":5,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.701618+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.702717+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Replicate","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.702821+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":6,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.702866+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Replicate","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.702888+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":7,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.702909+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":4,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.702927+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.70295+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":3,"logTerm":2,"index":4,"commit":4,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.702975+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":4,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.702993+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.703012+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":3,"logTerm":2,"index":4,"commit":4,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.703125+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:11.703208+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":4,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.703235+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":3,"entry-index":4,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.704818+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":3,"logTerm":2,"index":4,"commit":4,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.704848+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":6,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.704933+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.704936+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":7,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.704958+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":7,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.704977+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.705063+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:11.70511+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":4,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.705127+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":3,"entry-index":4,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.705293+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":3},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":3,"logTerm":2,"index":4,"commit":4,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.705411+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":7,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.705484+0800","caller":"etcdserver/server.go:2313","msg":"setting up initial cluster version using v3 API","cluster-version":"3.6"} +{"level":"debug","ts":"2023-10-12T11:15:11.705581+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Replicate","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.705603+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:11.70562+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.705687+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":4,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.705715+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":3,"entry-index":4,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.705718+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":1,"logTerm":2,"index":7,"commit":4,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.705755+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":1,"logTerm":2,"index":7,"commit":4,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.706416+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":1,"logTerm":2,"index":7,"commit":4,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.70646+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":1,"logTerm":2,"index":7,"commit":4,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.706518+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.706528+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.707055+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":7,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.707136+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.707173+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":7},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":0,"logTerm":2,"index":8,"commit":7,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.707191+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":7},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":2,"index":8,"commit":7,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.707729+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":7},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":7,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.707809+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":7},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.708245+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":7},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.708331+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":7},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.708404+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":3} +{"level":"debug","ts":"2023-10-12T11:15:11.70843+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":5,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.708443+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":4,"entry-index":5,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.708458+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: cluster_member_attr_set: > "} +{"level":"debug","ts":"2023-10-12T11:15:11.708644+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":0,"logTerm":2,"index":8,"commit":7,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.708748+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":7},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.708878+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":3} +{"level":"debug","ts":"2023-10-12T11:15:11.708904+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":5,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.708915+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":4,"entry-index":5,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.708928+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: cluster_member_attr_set: > "} +{"level":"debug","ts":"2023-10-12T11:15:11.708937+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":7},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.708975+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":7},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.709052+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":0,"logTerm":2,"index":8,"commit":8,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.709074+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":2,"index":8,"commit":8,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.709134+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.709174+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:11.709198+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.709295+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":7},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":0,"logTerm":2,"index":8,"commit":8,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.709342+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.709598+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.709741+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":6,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.709765+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":5,"entry-index":6,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.709779+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: cluster_member_attr_set: > "} +{"level":"debug","ts":"2023-10-12T11:15:11.709854+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":7,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.709865+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":6,"entry-index":7,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.709877+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: cluster_member_attr_set: > "} +{"level":"info","ts":"2023-10-12T11:15:11.709926+0800","caller":"etcdserver/server.go:1749","msg":"published local member to cluster through raft","local-member-id":"fd422379fda50e48","local-member-attributes":"{Name:infra3 ClientURLs:[http://127.0.0.1:32379]}","cluster-id":"ef37ad9dc622a7c4","publish-timeout":"7s"} +{"level":"debug","ts":"2023-10-12T11:15:11.70993+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:11.70994+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":8,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.709961+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":7,"entry-index":8,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.709974+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: cluster_version_set: "} +{"level":"info","ts":"2023-10-12T11:15:11.709986+0800","caller":"embed/serve.go:112","msg":"ready to serve client requests"} +{"level":"info","ts":"2023-10-12T11:15:11.710047+0800","caller":"membership/cluster.go:546","msg":"set initial cluster version","cluster-id":"ef37ad9dc622a7c4","local-member-id":"fd422379fda50e48","cluster-version":"3.6"} +{"level":"debug","ts":"2023-10-12T11:15:11.710065+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":6,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.710086+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":5,"entry-index":6,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.710099+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: cluster_member_attr_set: > "} +{"level":"info","ts":"2023-10-12T11:15:11.710106+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel created"} +{"level":"info","ts":"2023-10-12T11:15:11.710114+0800","caller":"api/capability.go:77","msg":"enabled capabilities for version","cluster-version":"3.6"} +{"level":"info","ts":"2023-10-12T11:15:11.710146+0800","caller":"etcdserver/server.go:2333","msg":"cluster version is updated","cluster-version":"3.6"} +{"level":"debug","ts":"2023-10-12T11:15:11.710167+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":7,"term":2,"type":"EntryNormal"} +{"level":"info","ts":"2023-10-12T11:15:11.710168+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] original dial target is: \"127.0.0.1:32379\""} +{"level":"debug","ts":"2023-10-12T11:15:11.71018+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":6,"entry-index":7,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.71019+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: cluster_member_attr_set: > "} +{"level":"info","ts":"2023-10-12T11:15:11.710195+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] dial target \"127.0.0.1:32379\" parse failed: parse \"127.0.0.1:32379\": first path segment in URL cannot contain colon"} +{"level":"info","ts":"2023-10-12T11:15:11.710207+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] fallback to scheme \"passthrough\""} +{"level":"info","ts":"2023-10-12T11:15:11.710234+0800","caller":"version/monitor.go:116","msg":"cluster version differs from storage version.","cluster-version":"3.6.0","storage-version":"3.5.0"} +{"level":"debug","ts":"2023-10-12T11:15:11.710241+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"info","ts":"2023-10-12T11:15:11.710241+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] parsed dial target is: {URL:{Scheme:passthrough Opaque: User: Host: Path:/127.0.0.1:32379 RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}"} +{"level":"debug","ts":"2023-10-12T11:15:11.710251+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":8,"term":2,"type":"EntryNormal"} +{"level":"info","ts":"2023-10-12T11:15:11.710255+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel authority set to \"127.0.0.1:32379\""} +{"level":"debug","ts":"2023-10-12T11:15:11.710269+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":7,"entry-index":8,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.710282+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: cluster_version_set: "} +{"level":"info","ts":"2023-10-12T11:15:11.710289+0800","caller":"schema/migration.go:65","msg":"updated storage version","new-storage-version":"3.6.0"} +{"level":"info","ts":"2023-10-12T11:15:11.710316+0800","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} +{"level":"info","ts":"2023-10-12T11:15:11.710335+0800","caller":"membership/cluster.go:546","msg":"set initial cluster version","cluster-id":"ef37ad9dc622a7c4","local-member-id":"8211f1d0f64f3269","cluster-version":"3.6"} +{"level":"info","ts":"2023-10-12T11:15:11.710355+0800","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} +{"level":"info","ts":"2023-10-12T11:15:11.710391+0800","caller":"api/capability.go:77","msg":"enabled capabilities for version","cluster-version":"3.6"} +{"level":"info","ts":"2023-10-12T11:15:11.71043+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Resolver state updated: {\n \"Addresses\": [\n {\n \"Addr\": \"127.0.0.1:32379\",\n \"ServerName\": \"\",\n \"Attributes\": null,\n \"BalancerAttributes\": null,\n \"Type\": 0,\n \"Metadata\": null\n }\n ],\n \"ServiceConfig\": null,\n \"Attributes\": null\n} (resolver returned new addresses)"} +{"level":"info","ts":"2023-10-12T11:15:11.710465+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel switches to new LB policy \"pick_first\""} +{"level":"info","ts":"2023-10-12T11:15:11.710481+0800","caller":"version/monitor.go:116","msg":"cluster version differs from storage version.","cluster-version":"3.6.0","storage-version":"3.5.0"} +{"level":"info","ts":"2023-10-12T11:15:11.710503+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1 SubChannel #2] Subchannel created"} +{"level":"debug","ts":"2023-10-12T11:15:11.710512+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":4},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":2,"index":8,"commit":7,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.71052+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel Connectivity change to CONNECTING"} +{"level":"info","ts":"2023-10-12T11:15:11.710545+0800","caller":"schema/migration.go:65","msg":"updated storage version","new-storage-version":"3.6.0"} +{"level":"debug","ts":"2023-10-12T11:15:11.710552+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":7},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.710579+0800","caller":"etcdserver/server.go:1749","msg":"published local member to cluster through raft","local-member-id":"8211f1d0f64f3269","local-member-attributes":"{Name:infra1 ClientURLs:[http://127.0.0.1:2379]}","cluster-id":"ef37ad9dc622a7c4","publish-timeout":"7s"} +{"level":"debug","ts":"2023-10-12T11:15:11.710617+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":7},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":2,"index":8,"commit":8,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.710646+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.71067+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1 SubChannel #2] Subchannel Connectivity change to CONNECTING"} +{"level":"info","ts":"2023-10-12T11:15:11.710718+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1 SubChannel #2] Subchannel picks a new address \"127.0.0.1:32379\" to connect"} +{"level":"debug","ts":"2023-10-12T11:15:11.710755+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":3} +{"level":"info","ts":"2023-10-12T11:15:11.710773+0800","caller":"embed/serve.go:112","msg":"ready to serve client requests"} +{"level":"debug","ts":"2023-10-12T11:15:11.710775+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":5,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.710785+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":4,"entry-index":5,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.710801+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: cluster_member_attr_set: > "} +{"level":"info","ts":"2023-10-12T11:15:11.710851+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel created"} +{"level":"info","ts":"2023-10-12T11:15:11.710872+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] original dial target is: \"127.0.0.1:2379\""} +{"level":"info","ts":"2023-10-12T11:15:11.71091+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] dial target \"127.0.0.1:2379\" parse failed: parse \"127.0.0.1:2379\": first path segment in URL cannot contain colon"} +{"level":"info","ts":"2023-10-12T11:15:11.710927+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] fallback to scheme \"passthrough\""} +{"level":"info","ts":"2023-10-12T11:15:11.710982+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] parsed dial target is: {URL:{Scheme:passthrough Opaque: User: Host: Path:/127.0.0.1:2379 RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}"} +{"level":"info","ts":"2023-10-12T11:15:11.711064+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel authority set to \"127.0.0.1:2379\""} +{"level":"info","ts":"2023-10-12T11:15:11.711074+0800","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} +{"level":"info","ts":"2023-10-12T11:15:11.711099+0800","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} +{"level":"info","ts":"2023-10-12T11:15:11.711313+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Resolver state updated: {\n \"Addresses\": [\n {\n \"Addr\": \"127.0.0.1:2379\",\n \"ServerName\": \"\",\n \"Attributes\": null,\n \"BalancerAttributes\": null,\n \"Type\": 0,\n \"Metadata\": null\n }\n ],\n \"ServiceConfig\": null,\n \"Attributes\": null\n} (resolver returned new addresses)"} +{"level":"info","ts":"2023-10-12T11:15:11.711403+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel switches to new LB policy \"pick_first\""} +{"level":"info","ts":"2023-10-12T11:15:11.711465+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1 SubChannel #2] Subchannel created"} +{"level":"info","ts":"2023-10-12T11:15:11.711486+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel Connectivity change to CONNECTING"} +{"level":"info","ts":"2023-10-12T11:15:11.711714+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Server #3] Server created"} +{"level":"info","ts":"2023-10-12T11:15:11.711719+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1 SubChannel #2] Subchannel Connectivity change to CONNECTING"} +{"level":"info","ts":"2023-10-12T11:15:11.71176+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1 SubChannel #2] Subchannel picks a new address \"127.0.0.1:2379\" to connect"} +{"level":"info","ts":"2023-10-12T11:15:11.711906+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] pickfirstBalancer: UpdateSubConnState: 0xc000482828, {CONNECTING }"} +{"level":"debug","ts":"2023-10-12T11:15:11.711907+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":6,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.711924+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":5,"entry-index":6,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.711935+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: cluster_member_attr_set: > "} +{"level":"debug","ts":"2023-10-12T11:15:11.711985+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":7,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.711994+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":6,"entry-index":7,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.712002+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: cluster_member_attr_set: > "} +{"level":"debug","ts":"2023-10-12T11:15:11.712042+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:11.71205+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":8,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:11.71207+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":7,"entry-index":8,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:11.712081+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: cluster_version_set: "} +{"level":"info","ts":"2023-10-12T11:15:11.712122+0800","caller":"membership/cluster.go:546","msg":"set initial cluster version","cluster-id":"ef37ad9dc622a7c4","local-member-id":"91bc3c398fb3c146","cluster-version":"3.6"} +{"level":"info","ts":"2023-10-12T11:15:11.712172+0800","caller":"api/capability.go:77","msg":"enabled capabilities for version","cluster-version":"3.6"} +{"level":"info","ts":"2023-10-12T11:15:11.712237+0800","caller":"version/monitor.go:116","msg":"cluster version differs from storage version.","cluster-version":"3.6.0","storage-version":"3.5.0"} +{"level":"info","ts":"2023-10-12T11:15:11.712312+0800","caller":"schema/migration.go:65","msg":"updated storage version","new-storage-version":"3.6.0"} +{"level":"info","ts":"2023-10-12T11:15:11.712339+0800","caller":"etcdserver/server.go:1749","msg":"published local member to cluster through raft","local-member-id":"91bc3c398fb3c146","local-member-attributes":"{Name:infra2 ClientURLs:[http://127.0.0.1:22379]}","cluster-id":"ef37ad9dc622a7c4","publish-timeout":"7s"} +{"level":"info","ts":"2023-10-12T11:15:11.71244+0800","caller":"embed/serve.go:112","msg":"ready to serve client requests"} +{"level":"info","ts":"2023-10-12T11:15:11.71249+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel created"} +{"level":"info","ts":"2023-10-12T11:15:11.712507+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] original dial target is: \"127.0.0.1:22379\""} +{"level":"info","ts":"2023-10-12T11:15:11.712523+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] dial target \"127.0.0.1:22379\" parse failed: parse \"127.0.0.1:22379\": first path segment in URL cannot contain colon"} +{"level":"info","ts":"2023-10-12T11:15:11.712546+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] fallback to scheme \"passthrough\""} +{"level":"info","ts":"2023-10-12T11:15:11.712577+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] parsed dial target is: {URL:{Scheme:passthrough Opaque: User: Host: Path:/127.0.0.1:22379 RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}"} +{"level":"info","ts":"2023-10-12T11:15:11.712591+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel authority set to \"127.0.0.1:22379\""} +{"level":"info","ts":"2023-10-12T11:15:11.712629+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Server #3] Server created"} +{"level":"info","ts":"2023-10-12T11:15:11.712739+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Resolver state updated: {\n \"Addresses\": [\n {\n \"Addr\": \"127.0.0.1:22379\",\n \"ServerName\": \"\",\n \"Attributes\": null,\n \"BalancerAttributes\": null,\n \"Type\": 0,\n \"Metadata\": null\n }\n ],\n \"ServiceConfig\": null,\n \"Attributes\": null\n} (resolver returned new addresses)"} +{"level":"info","ts":"2023-10-12T11:15:11.71277+0800","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} +{"level":"info","ts":"2023-10-12T11:15:11.71278+0800","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} +{"level":"info","ts":"2023-10-12T11:15:11.712798+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel switches to new LB policy \"pick_first\""} +{"level":"info","ts":"2023-10-12T11:15:11.71284+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1 SubChannel #2] Subchannel created"} +{"level":"info","ts":"2023-10-12T11:15:11.712856+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel Connectivity change to CONNECTING"} +{"level":"info","ts":"2023-10-12T11:15:11.712962+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Server #3] Server created"} +{"level":"info","ts":"2023-10-12T11:15:11.714101+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] pickfirstBalancer: UpdateSubConnState: 0xc0004b0438, {CONNECTING }"} +{"level":"debug","ts":"2023-10-12T11:15:11.714293+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:11.714331+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":8,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:11.71464+0800","caller":"embed/serve.go:196","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"127.0.0.1:22379"} +{"level":"info","ts":"2023-10-12T11:15:11.714697+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Server #3 ListenSocket #4] ListenSocket created"} +{"level":"info","ts":"2023-10-12T11:15:11.714747+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1 SubChannel #2] Subchannel Connectivity change to CONNECTING"} +{"level":"info","ts":"2023-10-12T11:15:11.714768+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1 SubChannel #2] Subchannel picks a new address \"127.0.0.1:22379\" to connect"} +{"level":"info","ts":"2023-10-12T11:15:11.714933+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] pickfirstBalancer: UpdateSubConnState: 0xc0003db0e0, {CONNECTING }"} +{"level":"info","ts":"2023-10-12T11:15:11.715373+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1 SubChannel #2] Subchannel Connectivity change to READY"} +{"level":"info","ts":"2023-10-12T11:15:11.715407+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] pickfirstBalancer: UpdateSubConnState: 0xc0003db0e0, {READY }"} +{"level":"info","ts":"2023-10-12T11:15:11.715419+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel Connectivity change to READY"} +{"level":"info","ts":"2023-10-12T11:15:11.715463+0800","caller":"embed/serve.go:196","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"127.0.0.1:2379"} +{"level":"info","ts":"2023-10-12T11:15:11.715598+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Server #3 ListenSocket #5] ListenSocket created"} +{"level":"info","ts":"2023-10-12T11:15:11.716016+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1 SubChannel #2] Subchannel Connectivity change to READY"} +{"level":"info","ts":"2023-10-12T11:15:11.716095+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] pickfirstBalancer: UpdateSubConnState: 0xc000482828, {READY }"} +{"level":"info","ts":"2023-10-12T11:15:11.716141+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel Connectivity change to READY"} +{"level":"info","ts":"2023-10-12T11:15:11.716815+0800","caller":"embed/serve.go:196","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"127.0.0.1:32379"} +{"level":"info","ts":"2023-10-12T11:15:11.716983+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Server #3 ListenSocket #5] ListenSocket created"} +{"level":"info","ts":"2023-10-12T11:15:11.717265+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1 SubChannel #2] Subchannel Connectivity change to READY"} +{"level":"info","ts":"2023-10-12T11:15:11.71733+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] pickfirstBalancer: UpdateSubConnState: 0xc0004b0438, {READY }"} +{"level":"info","ts":"2023-10-12T11:15:11.717451+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[core] [Channel #1] Channel Connectivity change to READY"} +{"level":"debug","ts":"2023-10-12T11:15:15.591746+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Replicate","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:15.591791+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.591806+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":1,"logTerm":2,"index":8,"commit":8,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.591813+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":1,"logTerm":2,"index":8,"commit":8,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.591986+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":1,"logTerm":2,"index":8,"commit":8,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.592012+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.592081+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":1,"logTerm":2,"index":8,"commit":8,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.592127+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.592147+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":2,"index":9,"commit":8,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594112+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594166+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:15.594218+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":18249187646912138824,"to":18249187646912138824,"entries":0,"logTerm":0,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594252+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:15.594266+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":0,"logTerm":2,"index":9,"commit":9,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594315+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":2,"index":9,"commit":9,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594362+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594373+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:15.594421+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:15.59447+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":9,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:15.594479+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":8,"entry-index":9,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:15.59449+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: put: "} +{"level":"debug","ts":"2023-10-12T11:15:15.594546+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":9372538179322589801,"entries":0,"logTerm":2,"index":9,"commit":9,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594614+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":2,"index":9,"commit":8,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594619+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":9},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594633+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594643+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":8},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":2,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":2,"index":9,"commit":9,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594644+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:15.594649+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":9,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:15.59465+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":10501334649042878790,"state":{"term":2,"vote":18249187646912138824,"commit":9},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594654+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":8,"entry-index":9,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:15.594661+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: put: "} +{"level":"debug","ts":"2023-10-12T11:15:15.594748+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:15.594759+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":9,"term":2,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:15.594764+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":8,"entry-index":9,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:15.594773+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: put: "} +{"level":"debug","ts":"2023-10-12T11:15:15.594852+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.594865+0800","caller":"v3rpc/interceptor.go:186","msg":"request stats","start time":"2023-10-12T11:15:15.591569+0800","time spent":"3.2321ms","remote":"127.0.0.1:59402","response type":"/etcdserverpb.KV/Put","request count":1,"request size":10,"response count":0,"response size":28,"request content":"key:\"abc\" value_size:3 "} +{"level":"debug","ts":"2023-10-12T11:15:15.594942+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":0,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:15.595173+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":2,"from":9372538179322589801,"to":18249187646912138824,"entries":0,"logTerm":0,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:15.59582+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0002df380] Closing: read tcp 127.0.0.1:2379->127.0.0.1:59402: read: connection reset by peer"} +{"level":"info","ts":"2023-10-12T11:15:15.595878+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0002df380] loopyWriter exiting with error: transport closed by client"} +{"level":"debug","ts":"2023-10-12T11:15:19.615454+0800","caller":"v3rpc/interceptor.go:186","msg":"request stats","start time":"2023-10-12T11:15:19.615412+0800","time spent":"38.9µs","remote":"127.0.0.1:59418","response type":"/etcdserverpb.Maintenance/Status","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} +{"level":"info","ts":"2023-10-12T11:15:19.616229+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0004036c0] Closing: EOF"} +{"level":"info","ts":"2023-10-12T11:15:19.616331+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc000415520] Closing: EOF"} +{"level":"info","ts":"2023-10-12T11:15:19.616358+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0004036c0] loopyWriter exiting with error: transport closed by client"} +{"level":"info","ts":"2023-10-12T11:15:19.616503+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc000415520] loopyWriter exiting with error: transport closed by client"} +{"level":"debug","ts":"2023-10-12T11:15:19.617663+0800","caller":"v3rpc/interceptor.go:186","msg":"request stats","start time":"2023-10-12T11:15:19.617631+0800","time spent":"29.1µs","remote":"127.0.0.1:40544","response type":"/etcdserverpb.Maintenance/Status","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} +{"level":"info","ts":"2023-10-12T11:15:19.618188+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc00128c1a0] Closing: EOF"} +{"level":"info","ts":"2023-10-12T11:15:19.618229+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0011c8000] Closing: EOF"} +{"level":"info","ts":"2023-10-12T11:15:19.618293+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc00128c1a0] loopyWriter exiting with error: connection error: desc = \"transport is closing\""} +{"level":"info","ts":"2023-10-12T11:15:19.6183+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0011c8000] loopyWriter exiting with error: transport closed by client"} +{"level":"debug","ts":"2023-10-12T11:15:19.619241+0800","caller":"v3rpc/interceptor.go:186","msg":"request stats","start time":"2023-10-12T11:15:19.619158+0800","time spent":"80.6µs","remote":"127.0.0.1:34078","response type":"/etcdserverpb.Maintenance/Status","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} +{"level":"info","ts":"2023-10-12T11:15:19.620055+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc00050f380] Closing: EOF"} +{"level":"info","ts":"2023-10-12T11:15:19.620088+0800","caller":"etcdserver/server.go:1183","msg":"leadership transfer starting","local-member-id":"fd422379fda50e48","current-leader-member-id":"fd422379fda50e48","transferee-member-id":"fd422379fda50e48"} +{"level":"info","ts":"2023-10-12T11:15:19.620097+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc00050f380] loopyWriter exiting with error: connection error: desc = \"transport is closing\""} +{"level":"info","ts":"2023-10-12T11:15:19.620104+0800","caller":"etcdserver/server.go:1200","msg":"leadership transfer finished","local-member-id":"fd422379fda50e48","old-leader-member-id":"fd422379fda50e48","new-leader-member-id":"fd422379fda50e48","took":"16.1µs"} +{"level":"debug","ts":"2023-10-12T11:15:19.620131+0800","caller":"v3rpc/interceptor.go:186","msg":"request stats","start time":"2023-10-12T11:15:19.62008+0800","time spent":"49.5µs","remote":"127.0.0.1:34076","response type":"/etcdserverpb.Maintenance/MoveLeader","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} +{"level":"debug","ts":"2023-10-12T11:15:19.620186+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1624","msg":"fd422379fda50e48 is already leader. Ignored transferring leadership to self"} +{"level":"info","ts":"2023-10-12T11:15:19.620786+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0001036c0] Closing: read tcp 127.0.0.1:32379->127.0.0.1:34076: read: connection reset by peer"} +{"level":"info","ts":"2023-10-12T11:15:19.62086+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0001036c0] loopyWriter exiting with error: transport closed by client"} +{"level":"debug","ts":"2023-10-12T11:15:32.375971+0800","caller":"v3rpc/interceptor.go:186","msg":"request stats","start time":"2023-10-12T11:15:32.375467+0800","time spent":"499.6µs","remote":"127.0.0.1:59464","response type":"/etcdserverpb.Cluster/MemberList","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} +{"level":"info","ts":"2023-10-12T11:15:32.376683+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0003a3ba0] Closing: read tcp 127.0.0.1:2379->127.0.0.1:59464: read: connection reset by peer"} +{"level":"info","ts":"2023-10-12T11:15:32.376756+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0003a3ba0] loopyWriter exiting with error: transport closed by client"} +{"level":"info","ts":"2023-10-12T11:15:43.486732+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc00011cb60] Closing: EOF"} +{"level":"info","ts":"2023-10-12T11:15:43.48679+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc000103ba0] Closing: EOF"} +{"level":"info","ts":"2023-10-12T11:15:43.486799+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc00011cb60] loopyWriter exiting with error: connection error: desc = \"transport is closing\""} +{"level":"info","ts":"2023-10-12T11:15:43.486855+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc000103ba0] loopyWriter exiting with error: transport closed by client"} +{"level":"debug","ts":"2023-10-12T11:15:43.488735+0800","caller":"v3rpc/interceptor.go:186","msg":"request stats","start time":"2023-10-12T11:15:43.488691+0800","time spent":"40µs","remote":"127.0.0.1:59508","response type":"/etcdserverpb.Maintenance/Status","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} +{"level":"info","ts":"2023-10-12T11:15:43.489142+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc00133a000] Closing: EOF"} +{"level":"info","ts":"2023-10-12T11:15:43.48918+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc000e70b60] Closing: EOF"} +{"level":"info","ts":"2023-10-12T11:15:43.489203+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc00133a000] loopyWriter exiting with error: transport closed by client"} +{"level":"info","ts":"2023-10-12T11:15:43.489217+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc000e70b60] loopyWriter exiting with error: connection error: desc = \"transport is closing\""} +{"level":"debug","ts":"2023-10-12T11:15:43.49059+0800","caller":"v3rpc/interceptor.go:186","msg":"request stats","start time":"2023-10-12T11:15:43.490556+0800","time spent":"30.8µs","remote":"127.0.0.1:40634","response type":"/etcdserverpb.Maintenance/Status","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} +{"level":"info","ts":"2023-10-12T11:15:43.490933+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc00128cd00] Closing: EOF"} +{"level":"info","ts":"2023-10-12T11:15:43.491004+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc00128cd00] loopyWriter exiting with error: connection error: desc = \"transport is closing\""} +{"level":"info","ts":"2023-10-12T11:15:43.491187+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0011c8680] Closing: EOF"} +{"level":"info","ts":"2023-10-12T11:15:43.491254+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0011c8680] loopyWriter exiting with error: transport closed by client"} +{"level":"debug","ts":"2023-10-12T11:15:43.491817+0800","caller":"v3rpc/interceptor.go:186","msg":"request stats","start time":"2023-10-12T11:15:43.491787+0800","time spent":"27.3µs","remote":"127.0.0.1:34168","response type":"/etcdserverpb.Maintenance/Status","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} +{"level":"info","ts":"2023-10-12T11:15:43.492276+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc000415860] Closing: read tcp 127.0.0.1:32379->127.0.0.1:34168: read: connection reset by peer"} +{"level":"info","ts":"2023-10-12T11:15:43.492322+0800","caller":"etcdserver/server.go:1183","msg":"leadership transfer starting","local-member-id":"fd422379fda50e48","current-leader-member-id":"fd422379fda50e48","transferee-member-id":"91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:43.492329+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc000415860] loopyWriter exiting with error: transport closed by client"} +{"level":"info","ts":"2023-10-12T11:15:43.492337+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1628","msg":"fd422379fda50e48 [term 2] starts to transfer leadership to 91bc3c398fb3c146"} +{"level":"info","ts":"2023-10-12T11:15:43.492348+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1634","msg":"fd422379fda50e48 sends MsgTimeoutNow to 91bc3c398fb3c146 immediately as 91bc3c398fb3c146 already has up-to-date log"} +{"level":"info","ts":"2023-10-12T11:15:43.492511+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1730","msg":"91bc3c398fb3c146 [term 2] received MsgTimeoutNow from fd422379fda50e48 and starts an election to get leadership."} +{"level":"info","ts":"2023-10-12T11:15:43.492541+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:969","msg":"91bc3c398fb3c146 is starting a new election at term 2"} +{"level":"info","ts":"2023-10-12T11:15:43.492561+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:891","msg":"91bc3c398fb3c146 became candidate at term 3"} +{"level":"debug","ts":"2023-10-12T11:15:43.49257+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"BecomeCandidate","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateCandidate","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"info","ts":"2023-10-12T11:15:43.492586+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1043","msg":"91bc3c398fb3c146 [logterm: 2, index: 9] sent MsgVote request to 8211f1d0f64f3269 at term 3"} +{"level":"debug","ts":"2023-10-12T11:15:43.492593+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendRequestVoteRequest","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateCandidate","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVote","term":3,"from":10501334649042878790,"to":9372538179322589801,"entries":0,"logTerm":2,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.492601+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendRequestVoteResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateCandidate","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVoteResp","term":3,"from":10501334649042878790,"to":10501334649042878790,"entries":0,"logTerm":0,"index":0,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:43.492609+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1043","msg":"91bc3c398fb3c146 [logterm: 2, index: 9] sent MsgVote request to fd422379fda50e48 at term 3"} +{"level":"debug","ts":"2023-10-12T11:15:43.492615+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendRequestVoteRequest","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateCandidate","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVote","term":3,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":2,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:43.492622+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/node.go:376","msg":"raft.node: 91bc3c398fb3c146 lost leader fd422379fda50e48 at term 3"} +{"level":"debug","ts":"2023-10-12T11:15:43.494709+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveRequestVoteResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateCandidate","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVoteResp","term":3,"from":10501334649042878790,"to":10501334649042878790,"entries":0,"logTerm":0,"index":0,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:43.494746+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1056","msg":"91bc3c398fb3c146 received MsgVoteResp from 91bc3c398fb3c146 at term 3"} +{"level":"info","ts":"2023-10-12T11:15:43.494757+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1669","msg":"91bc3c398fb3c146 has received 1 MsgVoteResp votes and 0 vote rejections"} +{"level":"debug","ts":"2023-10-12T11:15:43.494896+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveRequestVoteRequest","nid":18249187646912138824,"state":{"term":2,"vote":18249187646912138824,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVote","term":3,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":2,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.494898+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveRequestVoteRequest","nid":9372538179322589801,"state":{"term":2,"vote":18249187646912138824,"commit":9},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVote","term":3,"from":10501334649042878790,"to":9372538179322589801,"entries":0,"logTerm":2,"index":9,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:43.494935+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1093","msg":"8211f1d0f64f3269 [term: 2] received a MsgVote message with higher term from 91bc3c398fb3c146 [term: 3]"} +{"level":"info","ts":"2023-10-12T11:15:43.494935+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1093","msg":"fd422379fda50e48 [term: 2] received a MsgVote message with higher term from 91bc3c398fb3c146 [term: 3]"} +{"level":"info","ts":"2023-10-12T11:15:43.494953+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:875","msg":"fd422379fda50e48 became follower at term 3"} +{"level":"debug","ts":"2023-10-12T11:15:43.494959+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"BecomeFollower","nid":18249187646912138824,"state":{"term":3,"vote":0,"commit":9},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"info","ts":"2023-10-12T11:15:43.49496+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:875","msg":"8211f1d0f64f3269 became follower at term 3"} +{"level":"debug","ts":"2023-10-12T11:15:43.494968+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"BecomeFollower","nid":9372538179322589801,"state":{"term":3,"vote":0,"commit":9},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"info","ts":"2023-10-12T11:15:43.494969+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1206","msg":"fd422379fda50e48 [logterm: 2, index: 9, vote: 0] cast MsgVote for 91bc3c398fb3c146 [logterm: 2, index: 9] at term 3"} +{"level":"debug","ts":"2023-10-12T11:15:43.494975+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendRequestVoteResponse","nid":18249187646912138824,"state":{"term":3,"vote":0,"commit":9},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVoteResp","term":3,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":0,"index":0,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:43.494978+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1206","msg":"8211f1d0f64f3269 [logterm: 2, index: 9, vote: 0] cast MsgVote for 91bc3c398fb3c146 [logterm: 2, index: 9] at term 3"} +{"level":"info","ts":"2023-10-12T11:15:43.494982+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/node.go:376","msg":"raft.node: fd422379fda50e48 lost leader fd422379fda50e48 at term 3"} +{"level":"debug","ts":"2023-10-12T11:15:43.494985+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendRequestVoteResponse","nid":9372538179322589801,"state":{"term":3,"vote":0,"commit":9},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVoteResp","term":3,"from":9372538179322589801,"to":10501334649042878790,"entries":0,"logTerm":0,"index":0,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:43.494993+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/node.go:376","msg":"raft.node: 8211f1d0f64f3269 lost leader fd422379fda50e48 at term 3"} +{"level":"debug","ts":"2023-10-12T11:15:43.49611+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveRequestVoteResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateCandidate","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVoteResp","term":3,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":0,"index":0,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:43.496144+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1056","msg":"91bc3c398fb3c146 received MsgVoteResp from fd422379fda50e48 at term 3"} +{"level":"info","ts":"2023-10-12T11:15:43.496155+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1669","msg":"91bc3c398fb3c146 has received 2 MsgVoteResp votes and 0 vote rejections"} +{"level":"debug","ts":"2023-10-12T11:15:43.496166+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"BecomeLeader","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:43.496175+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":10501334649042878790,"to":10501334649042878790,"entries":0,"logTerm":0,"index":10,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:43.496182+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:951","msg":"91bc3c398fb3c146 became leader at term 3"} +{"level":"debug","ts":"2023-10-12T11:15:43.496192+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":9372538179322589801,"entries":1,"logTerm":2,"index":9,"commit":9,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.4962+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":18249187646912138824,"entries":1,"logTerm":2,"index":9,"commit":9,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:43.496207+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/node.go:370","msg":"raft.node: 91bc3c398fb3c146 elected leader 91bc3c398fb3c146 at term 3"} +{"level":"debug","ts":"2023-10-12T11:15:43.496232+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveRequestVoteResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgVoteResp","term":3,"from":9372538179322589801,"to":10501334649042878790,"entries":0,"logTerm":0,"index":0,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.496402+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":9372538179322589801,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":9372538179322589801,"entries":1,"logTerm":2,"index":9,"commit":9,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.496417+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":18249187646912138824,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":18249187646912138824,"entries":1,"logTerm":2,"index":9,"commit":9,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.496437+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":18249187646912138824,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":0,"index":10,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.49644+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":9372538179322589801,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":9372538179322589801,"to":10501334649042878790,"entries":0,"logTerm":0,"index":10,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:43.496447+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/node.go:370","msg":"raft.node: fd422379fda50e48 elected leader 91bc3c398fb3c146 at term 3"} +{"level":"info","ts":"2023-10-12T11:15:43.496454+0800","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/node.go:370","msg":"raft.node: 8211f1d0f64f3269 elected leader 91bc3c398fb3c146 at term 3"} +{"level":"debug","ts":"2023-10-12T11:15:43.49732+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":10501334649042878790,"to":10501334649042878790,"entries":0,"logTerm":0,"index":10,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.497362+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:43.498047+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":0,"index":10,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.498087+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":9},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:43.498103+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":3,"index":10,"commit":10,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.498491+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":9372538179322589801,"to":10501334649042878790,"entries":0,"logTerm":0,"index":10,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.498532+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:43.498546+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":9372538179322589801,"entries":0,"logTerm":3,"index":10,"commit":10,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.498658+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:43.498685+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":10,"term":3,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:43.498695+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":9,"entry-index":10,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:43.498793+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":9372538179322589801,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":9372538179322589801,"entries":0,"logTerm":3,"index":10,"commit":10,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.498819+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":9372538179322589801,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":9372538179322589801,"to":10501334649042878790,"entries":0,"logTerm":0,"index":10,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.498851+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:43.49888+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":10,"term":3,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:43.498889+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":9,"entry-index":10,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:43.498951+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:43.498982+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":18249187646912138824,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":3,"index":10,"commit":10,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.498984+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":10,"term":3,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:43.498993+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":9,"entry-index":10,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:43.499003+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":18249187646912138824,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":0,"index":10,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.499021+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":9372538179322589801,"to":10501334649042878790,"entries":0,"logTerm":0,"index":10,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:43.499073+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":0,"index":10,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:43.59353+0800","caller":"etcdserver/server.go:1200","msg":"leadership transfer finished","local-member-id":"fd422379fda50e48","old-leader-member-id":"fd422379fda50e48","new-leader-member-id":"91bc3c398fb3c146","took":"101.2022ms"} +{"level":"debug","ts":"2023-10-12T11:15:43.593716+0800","caller":"v3rpc/interceptor.go:186","msg":"request stats","start time":"2023-10-12T11:15:43.492304+0800","time spent":"101.3938ms","remote":"127.0.0.1:34166","response type":"/etcdserverpb.Maintenance/MoveLeader","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} +{"level":"info","ts":"2023-10-12T11:15:43.596705+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0004b9520] Closing: read tcp 127.0.0.1:32379->127.0.0.1:34166: read: connection reset by peer"} +{"level":"info","ts":"2023-10-12T11:15:43.59698+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc0004b9520] loopyWriter exiting with error: transport closed by client"} +{"level":"debug","ts":"2023-10-12T11:15:49.805893+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Replicate","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:49.805943+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":10501334649042878790,"to":10501334649042878790,"entries":0,"logTerm":0,"index":11,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.805963+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":9372538179322589801,"entries":1,"logTerm":3,"index":10,"commit":10,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.805972+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":18249187646912138824,"entries":1,"logTerm":3,"index":10,"commit":10,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.806176+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":18249187646912138824,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":18249187646912138824,"entries":1,"logTerm":3,"index":10,"commit":10,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.806232+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":18249187646912138824,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":0,"index":11,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.806581+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":9372538179322589801,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":9372538179322589801,"entries":1,"logTerm":3,"index":10,"commit":10,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.806628+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":9372538179322589801,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":9372538179322589801,"to":10501334649042878790,"entries":0,"logTerm":0,"index":11,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.808285+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":9372538179322589801,"to":10501334649042878790,"entries":0,"logTerm":0,"index":11,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.808328+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:49.808404+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":0,"index":11,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.808421+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:49.808431+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":11},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":9372538179322589801,"entries":0,"logTerm":3,"index":11,"commit":11,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.808439+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesRequest","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":11},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":3,"index":11,"commit":11,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.808483+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":11},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":10501334649042878790,"to":10501334649042878790,"entries":0,"logTerm":0,"index":11,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.808513+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"Commit","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":11},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]]}} +{"level":"debug","ts":"2023-10-12T11:15:49.808598+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:49.808611+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":11,"term":3,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:49.808615+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":18249187646912138824,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":18249187646912138824,"entries":0,"logTerm":3,"index":11,"commit":11,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.808618+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":10,"entry-index":11,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:49.808624+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: put: "} +{"level":"debug","ts":"2023-10-12T11:15:49.808646+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesRequest","nid":9372538179322589801,"state":{"term":3,"vote":10501334649042878790,"commit":10},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgApp","term":3,"from":10501334649042878790,"to":9372538179322589801,"entries":0,"logTerm":3,"index":11,"commit":11,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.808652+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":18249187646912138824,"state":{"term":3,"vote":10501334649042878790,"commit":11},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":0,"index":11,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.808664+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"SendAppendEntriesResponse","nid":9372538179322589801,"state":{"term":3,"vote":10501334649042878790,"commit":11},"role":"StateFollower","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":9372538179322589801,"to":10501334649042878790,"entries":0,"logTerm":0,"index":11,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.808677+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:49.808682+0800","caller":"etcdserver/server.go:1818","msg":"Applying entries","num-entries":1} +{"level":"debug","ts":"2023-10-12T11:15:49.808682+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":11,"term":3,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:49.808686+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":10,"entry-index":11,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:49.808687+0800","caller":"etcdserver/server.go:1821","msg":"Applying entry","index":11,"term":3,"type":"EntryNormal"} +{"level":"debug","ts":"2023-10-12T11:15:49.808691+0800","caller":"etcdserver/server.go:1880","msg":"toApply entry normal","consistent-index":10,"entry-index":11,"should-applyV3":true} +{"level":"debug","ts":"2023-10-12T11:15:49.808692+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: put: "} +{"level":"debug","ts":"2023-10-12T11:15:49.808697+0800","caller":"etcdserver/server.go:1907","msg":"applyEntryNormal","raftReq":"header: put: "} +{"level":"debug","ts":"2023-10-12T11:15:49.808762+0800","caller":"v3rpc/interceptor.go:186","msg":"request stats","start time":"2023-10-12T11:15:49.805682+0800","time spent":"3.0719ms","remote":"127.0.0.1:59534","response type":"/etcdserverpb.KV/Put","request count":1,"request size":10,"response count":0,"response size":28,"request content":"key:\"abc\" value_size:3 "} +{"level":"debug","ts":"2023-10-12T11:15:49.80884+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":11},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":18249187646912138824,"to":10501334649042878790,"entries":0,"logTerm":0,"index":11,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"debug","ts":"2023-10-12T11:15:49.808873+0800","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/state_trace.go:124","msg":"","tag":"raft_trace","event":{"name":"ReceiveAppendEntriesResponse","nid":10501334649042878790,"state":{"term":3,"vote":10501334649042878790,"commit":11},"role":"StateLeader","conf":[[9372538179322589801,10501334649042878790,18249187646912138824],[]],"msg":{"type":"MsgAppResp","term":3,"from":9372538179322589801,"to":10501334649042878790,"entries":0,"logTerm":0,"index":11,"commit":0,"vote":0,"reject":false,"rejectHint":0}}} +{"level":"info","ts":"2023-10-12T11:15:49.809511+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc000616b60] Closing: read tcp 127.0.0.1:2379->127.0.0.1:59534: read: connection reset by peer"} +{"level":"info","ts":"2023-10-12T11:15:49.809629+0800","caller":"zapgrpc/zapgrpc.go:178","msg":"[transport] [server-transport 0xc000616b60] loopyWriter exiting with error: transport closed by client"} +{"level":"warn","ts":"2023-10-12T12:00:49.081798+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6827071s"} +{"level":"warn","ts":"2023-10-12T12:00:49.081832+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6827426s"} +{"level":"warn","ts":"2023-10-12T12:03:37.94959+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6767834s"} +{"level":"warn","ts":"2023-10-12T12:03:37.949634+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6768306s"} +{"level":"warn","ts":"2023-10-12T12:06:56.850395+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6691734s"} +{"level":"warn","ts":"2023-10-12T12:06:56.850431+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6692115s"} +{"level":"warn","ts":"2023-10-12T12:10:19.843155+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6609108s"} +{"level":"warn","ts":"2023-10-12T12:10:19.843217+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6609734s"} +{"level":"warn","ts":"2023-10-12T12:14:34.944499+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6530829s"} +{"level":"warn","ts":"2023-10-12T12:14:34.944577+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6531618s"} +{"level":"warn","ts":"2023-10-12T12:19:01.10105+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.7997314s"} +{"level":"warn","ts":"2023-10-12T12:19:01.101101+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.799783s"} +{"level":"warn","ts":"2023-10-12T12:22:49.838755+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6858017s"} +{"level":"warn","ts":"2023-10-12T12:22:49.838784+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6858324s"} +{"level":"warn","ts":"2023-10-12T12:25:42.927573+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6627607s"} +{"level":"warn","ts":"2023-10-12T12:25:42.927605+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6627936s"} +{"level":"warn","ts":"2023-10-12T12:29:38.938725+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6500699s"} +{"level":"warn","ts":"2023-10-12T12:29:38.938753+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6500999s"} +{"level":"warn","ts":"2023-10-12T12:32:16.286925+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6758242s"} +{"level":"warn","ts":"2023-10-12T12:32:16.286978+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6758778s"} +{"level":"warn","ts":"2023-10-12T12:35:55.486564+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.615376s"} +{"level":"warn","ts":"2023-10-12T12:35:55.486604+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6154183s"} +{"level":"warn","ts":"2023-10-12T12:39:45.946148+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.7135818s"} +{"level":"warn","ts":"2023-10-12T12:39:45.94624+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.7136751s"} +{"level":"warn","ts":"2023-10-12T12:42:42.849864+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6151237s"} +{"level":"warn","ts":"2023-10-12T12:42:42.849921+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6151837s"} +{"level":"warn","ts":"2023-10-12T12:45:30.927791+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.5892354s"} +{"level":"warn","ts":"2023-10-12T12:45:30.927918+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.5893638s"} +{"level":"warn","ts":"2023-10-12T12:50:10.194381+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"fd422379fda50e48","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6311121s"} +{"level":"warn","ts":"2023-10-12T12:50:10.194522+0800","caller":"etcdserver/raft.go:382","msg":"leader failed to send out heartbeat on time; took too long, leader is overloaded likely from slow disk","to":"8211f1d0f64f3269","heartbeat-interval":"100ms","expected-duration":"200ms","exceeded-duration":"2.6312563s"} diff --git a/tla/trace-preprocess-log.sh b/tla/trace-preprocess-log.sh new file mode 100755 index 0000000..a409cd5 --- /dev/null +++ b/tla/trace-preprocess-log.sh @@ -0,0 +1,4 @@ +#!/bin/bash + +sed -i -E 's/^[^{]+//' $1 +sort -t":" -k 3 $1 -o $1 \ No newline at end of file