Comments (5)
node1 log:
{"level":"warn","ts":"2024-04-22T17:17:57.604776+0800","caller":"embed/config.go:679","msg":"Running http and grpc server on single port. This is not recommended for production."}
{"level":"info","ts":"2024-04-22T17:17:57.604845+0800","caller":"embed/etcd.go:127","msg":"configuring peer listeners","listen-peer-urls":["http://127.0.0.1:31303"]}
{"level":"info","ts":"2024-04-22T17:17:57.60496+0800","caller":"embed/etcd.go:135","msg":"configuring client listeners","listen-client-urls":["http://127.0.0.1:41303"]}
{"level":"info","ts":"2024-04-22T17:17:57.605038+0800","caller":"embed/etcd.go:308","msg":"starting an etcd server","etcd-version":"3.5.13","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.20.5","go-os":"linux","go-arch":"amd64","max-cpu-set":4,"max-cpu-available":32,"member-initialized":false,"name":"cs0","data-dir":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs0_31302/data","wal-dir":"","wal-dir-dedicated":"","member-dir":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs0_31302/data/member","force-new-cluster":false,"heartbeat-interval":"100ms","election-timeout":"1s","initial-election-tick-advance":true,"snapshot-count":100000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://127.0.0.1:31303"],"listen-peer-urls":["http://127.0.0.1:31303"],"advertise-client-urls":["http://127.0.0.1:41303"],"listen-client-urls":["http://127.0.0.1:41303"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"cs0=http://127.0.0.1:31303","initial-cluster-state":"new","initial-cluster-token":"cluster1","quota-backend-bytes":8589934592,"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":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"}
{"level":"warn","ts":"2024-04-22T17:17:57.60511+0800","caller":"fileutil/fileutil.go:53","msg":"check file permission","error":"directory \"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs0_31302/data\" exist, but the permission is \"drwxrwxrwx\". The recommended permission is \"-rwx------\" to prevent possible unprivileged access to the data"}
{"level":"info","ts":"2024-04-22T17:17:57.606092+0800","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs0_31302/data/member/snap/db","took":"793.357µs"}
{"level":"info","ts":"2024-04-22T17:17:57.606898+0800","caller":"etcdserver/raft.go:495","msg":"starting local member","local-member-id":"459d9a5e5c0b19ce","cluster-id":"d782b9400782601d"}
{"level":"info","ts":"2024-04-22T17:17:57.606958+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce switched to configuration voters=()"}
{"level":"info","ts":"2024-04-22T17:17:57.606997+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became follower at term 0"}
{"level":"info","ts":"2024-04-22T17:17:57.607013+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 459d9a5e5c0b19ce [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"}
{"level":"info","ts":"2024-04-22T17:17:57.607027+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became follower at term 1"}
{"level":"info","ts":"2024-04-22T17:17:57.607073+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce switched to configuration voters=(5016335290022435278)"}
{"level":"warn","ts":"2024-04-22T17:17:57.607675+0800","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"}
{"level":"info","ts":"2024-04-22T17:17:57.609287+0800","caller":"mvcc/kvstore.go:407","msg":"kvstore restored","current-rev":1}
{"level":"info","ts":"2024-04-22T17:17:57.609572+0800","caller":"etcdserver/quota.go:117","msg":"enabled backend quota","quota-name":"v3-applier","quota-size-bytes":8589934592,"quota-size":"8.6 GB"}
{"level":"info","ts":"2024-04-22T17:17:57.609776+0800","caller":"etcdserver/server.go:867","msg":"starting etcd server","local-member-id":"459d9a5e5c0b19ce","local-server-version":"3.5.13","cluster-version":"to_be_decided"}
{"level":"info","ts":"2024-04-22T17:17:57.609878+0800","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs0_31302/data/member/snap","suffix":"snap.db","max":5,"interval":"30s"}
{"level":"info","ts":"2024-04-22T17:17:57.60994+0800","caller":"etcdserver/server.go:751","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"459d9a5e5c0b19ce","forward-ticks":9,"forward-duration":"900ms","election-ticks":10,"election-timeout":"1s"}
{"level":"info","ts":"2024-04-22T17:17:57.609972+0800","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs0_31302/data/member/snap","suffix":"snap","max":5,"interval":"30s"}
{"level":"info","ts":"2024-04-22T17:17:57.60999+0800","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs0_31302/data/member/wal","suffix":"wal","max":5,"interval":"30s"}
{"level":"info","ts":"2024-04-22T17:17:57.610185+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce switched to configuration voters=(5016335290022435278)"}
{"level":"info","ts":"2024-04-22T17:17:57.61031+0800","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"d782b9400782601d","local-member-id":"459d9a5e5c0b19ce","added-peer-id":"459d9a5e5c0b19ce","added-peer-peer-urls":["http://127.0.0.1:31303"]}
{"level":"info","ts":"2024-04-22T17:17:57.611734+0800","caller":"embed/etcd.go:597","msg":"serving peer traffic","address":"127.0.0.1:31303"}
{"level":"info","ts":"2024-04-22T17:17:57.611756+0800","caller":"embed/etcd.go:569","msg":"cmux::serve","address":"127.0.0.1:31303"}
{"level":"info","ts":"2024-04-22T17:17:57.611755+0800","caller":"embed/etcd.go:277","msg":"now serving peer/client/metrics","local-member-id":"459d9a5e5c0b19ce","initial-advertise-peer-urls":["http://127.0.0.1:31303"],"listen-peer-urls":["http://127.0.0.1:31303"],"advertise-client-urls":["http://127.0.0.1:41303"],"listen-client-urls":["http://127.0.0.1:41303"],"listen-metrics-urls":[]}
{"level":"info","ts":"2024-04-22T17:17:58.208041+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 1"}
{"level":"info","ts":"2024-04-22T17:17:58.208101+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 1"}
{"level":"info","ts":"2024-04-22T17:17:58.208126+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 1"}
{"level":"info","ts":"2024-04-22T17:17:58.20815+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became candidate at term 2"}
{"level":"info","ts":"2024-04-22T17:17:58.208162+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgVoteResp from 459d9a5e5c0b19ce at term 2"}
{"level":"info","ts":"2024-04-22T17:17:58.208183+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became leader at term 2"}
{"level":"info","ts":"2024-04-22T17:17:58.208198+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 459d9a5e5c0b19ce elected leader 459d9a5e5c0b19ce at term 2"}
{"level":"info","ts":"2024-04-22T17:17:58.208616+0800","caller":"etcdserver/server.go:2110","msg":"published local member to cluster through raft","local-member-id":"459d9a5e5c0b19ce","local-member-attributes":"{Name:cs0 ClientURLs:[http://127.0.0.1:41303]}","request-path":"/0/members/459d9a5e5c0b19ce/attributes","cluster-id":"d782b9400782601d","publish-timeout":"7s"}
{"level":"info","ts":"2024-04-22T17:17:58.208654+0800","caller":"embed/serve.go:103","msg":"ready to serve client requests"}
{"level":"info","ts":"2024-04-22T17:17:58.208701+0800","caller":"etcdserver/server.go:2620","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"}
{"level":"info","ts":"2024-04-22T17:17:58.209023+0800","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"d782b9400782601d","local-member-id":"459d9a5e5c0b19ce","cluster-version":"3.5"}
{"level":"info","ts":"2024-04-22T17:17:58.20913+0800","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"}
{"level":"info","ts":"2024-04-22T17:17:58.209165+0800","caller":"etcdserver/server.go:2644","msg":"cluster version is updated","cluster-version":"3.5"}
{"level":"info","ts":"2024-04-22T17:17:58.209894+0800","caller":"embed/serve.go:187","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"127.0.0.1:41303"}
{"level":"info","ts":"2024-04-22T17:17:58.392861+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce switched to configuration voters=(5016335290022435278 5360057788862619714)"}
{"level":"info","ts":"2024-04-22T17:17:58.392975+0800","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"d782b9400782601d","local-member-id":"459d9a5e5c0b19ce","added-peer-id":"4a62c02900b8e042","added-peer-peer-urls":["http://127.0.0.1:31305"]}
{"level":"info","ts":"2024-04-22T17:17:58.393012+0800","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:17:58.393042+0800","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:17:58.393845+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:17:58.39393+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:17:58.393975+0800","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:17:58.393985+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:17:58.394011+0800","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042","remote-peer-urls":["http://127.0.0.1:31305"]}
{"level":"info","ts":"2024-04-22T17:17:58.394038+0800","caller":"etcdserver/server.go:1988","msg":"applied a configuration change through raft","local-member-id":"459d9a5e5c0b19ce","raft-conf-change":"ConfChangeAddNode","raft-conf-change-node-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:17:58.394052+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"warn","ts":"2024-04-22T17:17:58.925956+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:17:59.42615+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:17:59.927221+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:00.207412+0800","logger":"raft","caller":"etcdserver/zap_raft.go:85","msg":"459d9a5e5c0b19ce stepped down to follower since quorum is not active"}
{"level":"info","ts":"2024-04-22T17:18:00.207484+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became follower at term 2"}
{"level":"info","ts":"2024-04-22T17:18:00.207502+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 459d9a5e5c0b19ce lost leader 459d9a5e5c0b19ce at term 2"}
{"level":"warn","ts":"2024-04-22T17:18:00.427837+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:00.427884+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce no leader at term 2; dropping index reading msg"}
{"level":"warn","ts":"2024-04-22T17:18:00.928296+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:00.928386+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce no leader at term 2; dropping index reading msg"}
{"level":"info","ts":"2024-04-22T17:18:01.408166+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 2"}
{"level":"info","ts":"2024-04-22T17:18:01.408193+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 2"}
{"level":"info","ts":"2024-04-22T17:18:01.40821+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 2"}
{"level":"info","ts":"2024-04-22T17:18:01.408233+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 2, index: 10] sent MsgPreVote request to 4a62c02900b8e042 at term 2"}
{"level":"warn","ts":"2024-04-22T17:18:01.428433+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:01.929145+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:02.429927+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:02.607572+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 2"}
{"level":"info","ts":"2024-04-22T17:18:02.607604+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 2"}
{"level":"info","ts":"2024-04-22T17:18:02.607621+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 2"}
{"level":"info","ts":"2024-04-22T17:18:02.607644+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 2, index: 10] sent MsgPreVote request to 4a62c02900b8e042 at term 2"}
{"level":"warn","ts":"2024-04-22T17:18:02.93035+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:03.213658+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000428145s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:03.213717+0800","caller":"traceutil/trace.go:171","msg":"trace[361968137] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000521681s","start":"2024-04-22T17:18:00.213181+0800","end":"2024-04-22T17:18:03.213702+0800","steps":["trace[361968137] 'agreement among raft nodes before linearized reading' (duration: 3.000425796s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:03.213762+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:00.213159+0800","time spent":"3.000586411s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:03.213763+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000607371s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:03.213817+0800","caller":"traceutil/trace.go:171","msg":"trace[1117269466] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000694495s","start":"2024-04-22T17:18:00.213115+0800","end":"2024-04-22T17:18:03.21381+0800","steps":["trace[1117269466] 'agreement among raft nodes before linearized reading' (duration: 3.00063206s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:03.21385+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:00.213095+0800","time spent":"3.000743014s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:03.213664+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000542762s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:03.21388+0800","caller":"traceutil/trace.go:171","msg":"trace[671394069] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000807278s","start":"2024-04-22T17:18:00.213067+0800","end":"2024-04-22T17:18:03.213874+0800","steps":["trace[671394069] 'agreement among raft nodes before linearized reading' (duration: 3.000560791s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:03.213909+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:00.213048+0800","time spent":"3.000848183s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:03.220166+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000226137s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"warn","ts":"2024-04-22T17:18:03.220177+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.00033433s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:03.220194+0800","caller":"traceutil/trace.go:171","msg":"trace[1554173965] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000289521s","start":"2024-04-22T17:18:00.219898+0800","end":"2024-04-22T17:18:03.220187+0800","steps":["trace[1554173965] 'agreement among raft nodes before linearized reading' (duration: 3.000252252s)"],"step_count":1}
{"level":"info","ts":"2024-04-22T17:18:03.220216+0800","caller":"traceutil/trace.go:171","msg":"trace[152497238] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000385538s","start":"2024-04-22T17:18:00.219817+0800","end":"2024-04-22T17:18:03.220202+0800","steps":["trace[152497238] 'agreement among raft nodes before linearized reading' (duration: 3.000345007s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:03.220231+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:00.219888+0800","time spent":"3.000331576s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:03.220254+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:00.219795+0800","time spent":"3.000445543s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:03.22029+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000374468s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:03.220314+0800","caller":"traceutil/trace.go:171","msg":"trace[743179172] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000414604s","start":"2024-04-22T17:18:00.219894+0800","end":"2024-04-22T17:18:03.220308+0800","steps":["trace[743179172] 'agreement among raft nodes before linearized reading' (duration: 3.000384233s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:03.220343+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:00.219885+0800","time spent":"3.000445734s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:03.394843+0800","caller":"rafthttp/probing_status.go:68","msg":"prober detected unhealthy status","round-tripper-name":"ROUND_TRIPPER_RAFT_MESSAGE","remote-peer-id":"4a62c02900b8e042","rtt":"0s"}
{"level":"warn","ts":"2024-04-22T17:18:03.394852+0800","caller":"rafthttp/probing_status.go:68","msg":"prober detected unhealthy status","round-tripper-name":"ROUND_TRIPPER_SNAPSHOT","remote-peer-id":"4a62c02900b8e042","rtt":"0s"}
{"level":"warn","ts":"2024-04-22T17:18:03.431173+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:03.807741+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 2"}
{"level":"info","ts":"2024-04-22T17:18:03.807764+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 2"}
{"level":"info","ts":"2024-04-22T17:18:03.807781+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 2"}
{"level":"info","ts":"2024-04-22T17:18:03.807802+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 2, index: 10] sent MsgPreVote request to 4a62c02900b8e042 at term 2"}
{"level":"warn","ts":"2024-04-22T17:18:03.931762+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:04.43249+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:04.93336+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150329,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:05.007714+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 2"}
{"level":"info","ts":"2024-04-22T17:18:05.00774+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 2"}
{"level":"info","ts":"2024-04-22T17:18:05.007757+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 2"}
{"level":"info","ts":"2024-04-22T17:18:05.00778+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 2, index: 10] sent MsgPreVote request to 4a62c02900b8e042 at term 2"}
{"level":"warn","ts":"2024-04-22T17:18:05.426039+0800","caller":"etcdserver/v3_server.go:920","msg":"timed out waiting for read index response (local node might have slow network)","timeout":"7s"}
{"level":"info","ts":"2024-04-22T17:18:05.43092+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"459d9a5e5c0b19ce","to":"4a62c02900b8e042","stream-type":"stream MsgApp v2"}
{"level":"info","ts":"2024-04-22T17:18:05.430957+0800","caller":"rafthttp/peer_status.go:53","msg":"peer became active","peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:05.430983+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:05.430919+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"459d9a5e5c0b19ce","to":"4a62c02900b8e042","stream-type":"stream Message"}
{"level":"info","ts":"2024-04-22T17:18:05.431026+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:05.434072+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:05.434408+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"warn","ts":"2024-04-22T17:18:05.926516+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150332,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:06.207745+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 2"}
{"level":"info","ts":"2024-04-22T17:18:06.207803+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 2"}
{"level":"info","ts":"2024-04-22T17:18:06.207823+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 2"}
{"level":"info","ts":"2024-04-22T17:18:06.207846+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 2, index: 10] sent MsgPreVote request to 4a62c02900b8e042 at term 2"}
{"level":"warn","ts":"2024-04-22T17:18:06.214093+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000130641s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"warn","ts":"2024-04-22T17:18:06.214128+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000162229s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:06.214137+0800","caller":"traceutil/trace.go:171","msg":"trace[1098956073] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000207319s","start":"2024-04-22T17:18:03.213915+0800","end":"2024-04-22T17:18:06.214122+0800","steps":["trace[1098956073] 'agreement among raft nodes before linearized reading' (duration: 3.000158154s)"],"step_count":1}
{"level":"info","ts":"2024-04-22T17:18:06.214158+0800","caller":"traceutil/trace.go:171","msg":"trace[1165385538] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000210178s","start":"2024-04-22T17:18:03.21394+0800","end":"2024-04-22T17:18:06.214151+0800","steps":["trace[1165385538] 'agreement among raft nodes before linearized reading' (duration: 3.000176968s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:06.214191+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:03.213902+0800","time spent":"3.000262602s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:06.214092+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000099332s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:06.214261+0800","caller":"traceutil/trace.go:171","msg":"trace[1838094217] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000328679s","start":"2024-04-22T17:18:03.213924+0800","end":"2024-04-22T17:18:06.214253+0800","steps":["trace[1838094217] 'agreement among raft nodes before linearized reading' (duration: 3.000116739s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:06.214295+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:03.213913+0800","time spent":"3.00036835s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:06.214195+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:03.213931+0800","time spent":"3.000251248s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:06.215538+0800","caller":"etcdserver/server.go:1207","msg":"Failed to check current member's leadership","error":"context deadline exceeded"}
{"level":"warn","ts":"2024-04-22T17:18:06.220438+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.999925494s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:06.220492+0800","caller":"traceutil/trace.go:171","msg":"trace[466535682] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000025953s","start":"2024-04-22T17:18:03.220454+0800","end":"2024-04-22T17:18:06.22048+0800","steps":["trace[466535682] 'agreement among raft nodes before linearized reading' (duration: 2.999937266s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:06.220518+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.999991822s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context canceled"}
{"level":"warn","ts":"2024-04-22T17:18:06.220537+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:03.220444+0800","time spent":"3.000074669s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"info","ts":"2024-04-22T17:18:06.220561+0800","caller":"traceutil/trace.go:171","msg":"trace[505609705] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000043363s","start":"2024-04-22T17:18:03.220499+0800","end":"2024-04-22T17:18:06.220542+0800","steps":["trace[505609705] 'agreement among raft nodes before linearized reading' (duration: 3.000004636s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:06.220599+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:03.22049+0800","time spent":"3.000097002s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:06.427038+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150332,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:06.928041+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150332,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:07.408013+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 2"}
{"level":"info","ts":"2024-04-22T17:18:07.408046+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 2"}
{"level":"info","ts":"2024-04-22T17:18:07.40807+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 2"}
{"level":"info","ts":"2024-04-22T17:18:07.408092+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 2, index: 10] sent MsgPreVote request to 4a62c02900b8e042 at term 2"}
{"level":"info","ts":"2024-04-22T17:18:07.408417+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 4a62c02900b8e042 at term 2"}
{"level":"info","ts":"2024-04-22T17:18:07.408464+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce has received 2 MsgPreVoteResp votes and 0 vote rejections"}
{"level":"info","ts":"2024-04-22T17:18:07.408483+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became candidate at term 3"}
{"level":"info","ts":"2024-04-22T17:18:07.408495+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgVoteResp from 459d9a5e5c0b19ce at term 3"}
{"level":"info","ts":"2024-04-22T17:18:07.408523+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 2, index: 10] sent MsgVote request to 4a62c02900b8e042 at term 3"}
{"level":"info","ts":"2024-04-22T17:18:07.409093+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgVoteResp from 4a62c02900b8e042 at term 3"}
{"level":"info","ts":"2024-04-22T17:18:07.409117+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce has received 2 MsgVoteResp votes and 0 vote rejections"}
{"level":"info","ts":"2024-04-22T17:18:07.409135+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became leader at term 3"}
{"level":"info","ts":"2024-04-22T17:18:07.409151+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 459d9a5e5c0b19ce elected leader 459d9a5e5c0b19ce at term 3"}
{"level":"info","ts":"2024-04-22T17:18:07.410894+0800","caller":"etcdserver/v3_server.go:900","msg":"first commit in current term: resending ReadIndex request"}
{"level":"warn","ts":"2024-04-22T17:18:07.411644+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:04.217745+0800","time spent":"3.193890755s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.Lease/LeaseRevoke","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""}
{"level":"warn","ts":"2024-04-22T17:18:07.411745+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.197236086s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"range_response_count:0 size:4"}
{"level":"warn","ts":"2024-04-22T17:18:07.411756+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.197260991s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"range_response_count:0 size:4"}
{"level":"warn","ts":"2024-04-22T17:18:07.411783+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:06.215841+0800","time spent":"1.195937461s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.Lease/LeaseGrant","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""}
{"level":"info","ts":"2024-04-22T17:18:07.411797+0800","caller":"traceutil/trace.go:171","msg":"trace[1553799546] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; response_count:0; response_revision:5; }","duration":"1.197328091s","start":"2024-04-22T17:18:06.214458+0800","end":"2024-04-22T17:18:07.411786+0800","steps":["trace[1553799546] 'agreement among raft nodes before linearized reading' (duration: 1.197257032s)"],"step_count":1}
{"level":"info","ts":"2024-04-22T17:18:07.411786+0800","caller":"traceutil/trace.go:171","msg":"trace[1296618246] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; response_count:0; response_revision:5; }","duration":"1.197316382s","start":"2024-04-22T17:18:06.214458+0800","end":"2024-04-22T17:18:07.411775+0800","steps":["trace[1296618246] 'agreement among raft nodes before linearized reading' (duration: 1.197244516s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:07.411835+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:06.214448+0800","time spent":"1.197374268s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":27,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:07.411865+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:06.214442+0800","time spent":"1.197408318s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":27,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:07.411746+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.19721943s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"range_response_count:0 size:4"}
{"level":"info","ts":"2024-04-22T17:18:07.41193+0800","caller":"traceutil/trace.go:171","msg":"trace[136447207] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; response_count:0; response_revision:5; }","duration":"1.197445704s","start":"2024-04-22T17:18:06.214468+0800","end":"2024-04-22T17:18:07.411914+0800","steps":["trace[136447207] 'agreement among raft nodes before linearized reading' (duration: 1.197223641s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:07.411964+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:06.214452+0800","time spent":"1.197499294s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":27,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:07.427599+0800","caller":"rafthttp/stream.go:421","msg":"lost TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042","error":"unexpected EOF"}
{"level":"warn","ts":"2024-04-22T17:18:07.42764+0800","caller":"rafthttp/peer_status.go:66","msg":"peer became inactive (message send to peer failed)","peer-id":"4a62c02900b8e042","error":"failed to read 4a62c02900b8e042 on stream MsgApp v2 (unexpected EOF)"}
{"level":"warn","ts":"2024-04-22T17:18:07.427633+0800","caller":"rafthttp/stream.go:421","msg":"lost TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042","error":"unexpected EOF"}
{"level":"warn","ts":"2024-04-22T17:18:07.707581+0800","caller":"rafthttp/stream.go:223","msg":"lost TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"warn","ts":"2024-04-22T17:18:07.925024+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:08.425276+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:08.925896+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:09.407523+0800","logger":"raft","caller":"etcdserver/zap_raft.go:85","msg":"459d9a5e5c0b19ce stepped down to follower since quorum is not active"}
{"level":"info","ts":"2024-04-22T17:18:09.407567+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became follower at term 3"}
{"level":"info","ts":"2024-04-22T17:18:09.407584+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 459d9a5e5c0b19ce lost leader 459d9a5e5c0b19ce at term 3"}
{"level":"warn","ts":"2024-04-22T17:18:09.426105+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:09.426149+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce no leader at term 3; dropping index reading msg"}
{"level":"warn","ts":"2024-04-22T17:18:09.926767+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:09.92685+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce no leader at term 3; dropping index reading msg"}
{"level":"warn","ts":"2024-04-22T17:18:10.427081+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:10.427156+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce no leader at term 3; dropping index reading msg"}
{"level":"warn","ts":"2024-04-22T17:18:10.927762+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:10.927815+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce no leader at term 3; dropping index reading msg"}
{"level":"warn","ts":"2024-04-22T17:18:11.213318+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.999810196s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:11.213362+0800","caller":"traceutil/trace.go:171","msg":"trace[1897195003] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"2.999920698s","start":"2024-04-22T17:18:08.21343+0800","end":"2024-04-22T17:18:11.213351+0800","steps":["trace[1897195003] 'agreement among raft nodes before linearized reading' (duration: 2.999835621s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:11.21341+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:08.2134+0800","time spent":"2.999994244s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:11.213446+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.999967717s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:11.213477+0800","caller":"traceutil/trace.go:171","msg":"trace[919627813] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000061526s","start":"2024-04-22T17:18:08.213407+0800","end":"2024-04-22T17:18:11.213469+0800","steps":["trace[919627813] 'agreement among raft nodes before linearized reading' (duration: 3.000007474s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:11.213511+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:08.213395+0800","time spent":"3.000103156s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:11.213533+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000071921s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context canceled"}
{"level":"info","ts":"2024-04-22T17:18:11.213561+0800","caller":"traceutil/trace.go:171","msg":"trace[231844140] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000143462s","start":"2024-04-22T17:18:08.213411+0800","end":"2024-04-22T17:18:11.213555+0800","steps":["trace[231844140] 'agreement among raft nodes before linearized reading' (duration: 3.000107863s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:11.213602+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:08.213379+0800","time spent":"3.000210361s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"info","ts":"2024-04-22T17:18:11.307556+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 3"}
{"level":"info","ts":"2024-04-22T17:18:11.307581+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 3"}
{"level":"info","ts":"2024-04-22T17:18:11.307597+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 3"}
{"level":"info","ts":"2024-04-22T17:18:11.307619+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 3, index: 21] sent MsgPreVote request to 4a62c02900b8e042 at term 3"}
{"level":"warn","ts":"2024-04-22T17:18:11.428309+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:11.929173+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:12.417401+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000383617s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"warn","ts":"2024-04-22T17:18:12.417453+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.00043251s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:12.417473+0800","caller":"traceutil/trace.go:171","msg":"trace[848221980] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000514522s","start":"2024-04-22T17:18:09.416939+0800","end":"2024-04-22T17:18:12.417454+0800","steps":["trace[848221980] 'agreement among raft nodes before linearized reading' (duration: 3.000392131s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:12.417483+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000475063s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context canceled"}
{"level":"info","ts":"2024-04-22T17:18:12.417498+0800","caller":"traceutil/trace.go:171","msg":"trace[1099071586] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000544489s","start":"2024-04-22T17:18:09.416941+0800","end":"2024-04-22T17:18:12.417486+0800","steps":["trace[1099071586] 'agreement among raft nodes before linearized reading' (duration: 3.000462967s)"],"step_count":1}
{"level":"info","ts":"2024-04-22T17:18:12.417518+0800","caller":"traceutil/trace.go:171","msg":"trace[919186991] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000545533s","start":"2024-04-22T17:18:09.416965+0800","end":"2024-04-22T17:18:12.41751+0800","steps":["trace[919186991] 'agreement among raft nodes before linearized reading' (duration: 3.000501569s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:12.417527+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:09.416921+0800","time spent":"3.000588373s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:12.417547+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:09.416931+0800","time spent":"3.000600683s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:12.417557+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:09.416947+0800","time spent":"3.000592792s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:12.429957+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:12.930116+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:13.207642+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 3"}
{"level":"info","ts":"2024-04-22T17:18:13.207665+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 3"}
{"level":"info","ts":"2024-04-22T17:18:13.20768+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 3"}
{"level":"info","ts":"2024-04-22T17:18:13.207701+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 3, index: 21] sent MsgPreVote request to 4a62c02900b8e042 at term 3"}
{"level":"warn","ts":"2024-04-22T17:18:13.39467+0800","caller":"rafthttp/stream.go:194","msg":"lost TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"warn","ts":"2024-04-22T17:18:13.431215+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:13.931754+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150364,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:14.213884+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000189994s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:14.213941+0800","caller":"traceutil/trace.go:171","msg":"trace[773792623] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000303129s","start":"2024-04-22T17:18:11.213623+0800","end":"2024-04-22T17:18:14.213926+0800","steps":["trace[773792623] 'agreement among raft nodes before linearized reading' (duration: 3.000214419s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:14.213966+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000361309s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context canceled"}
{"level":"warn","ts":"2024-04-22T17:18:14.213993+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:11.213606+0800","time spent":"3.000371138s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"info","ts":"2024-04-22T17:18:14.214012+0800","caller":"traceutil/trace.go:171","msg":"trace[814073918] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000437761s","start":"2024-04-22T17:18:11.213565+0800","end":"2024-04-22T17:18:14.214003+0800","steps":["trace[814073918] 'agreement among raft nodes before linearized reading' (duration: 3.000380478s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:14.21405+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:11.213547+0800","time spent":"3.000488885s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:14.213965+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000334156s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:14.214085+0800","caller":"traceutil/trace.go:171","msg":"trace[442476737] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000515876s","start":"2024-04-22T17:18:11.213563+0800","end":"2024-04-22T17:18:14.214079+0800","steps":["trace[442476737] 'agreement among raft nodes before linearized reading' (duration: 3.000353409s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:14.214117+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:11.213547+0800","time spent":"3.00055627s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:14.425666+0800","caller":"etcdserver/v3_server.go:920","msg":"timed out waiting for read index response (local node might have slow network)","timeout":"7s"}
{"level":"warn","ts":"2024-04-22T17:18:14.42574+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"7.001112799s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/db/dbConfig\" ","response":"","error":"etcdserver: request timed out"}
{"level":"info","ts":"2024-04-22T17:18:14.425776+0800","caller":"traceutil/trace.go:171","msg":"trace[855314522] range","detail":"{range_begin:/db/dbConfig; range_end:; }","duration":"7.001165278s","start":"2024-04-22T17:18:07.424596+0800","end":"2024-04-22T17:18:14.425762+0800","steps":["trace[855314522] 'agreement among raft nodes before linearized reading' (duration: 7.001122523s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:14.42581+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:07.424588+0800","time spent":"7.001210669s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":14,"response count":0,"response size":0,"request content":"key:\"/db/dbConfig\" "}
{"level":"warn","ts":"2024-04-22T17:18:14.719594+0800","caller":"etcdserver/server.go:1207","msg":"Failed to check current member's leadership","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:14.784689+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"459d9a5e5c0b19ce","to":"4a62c02900b8e042","stream-type":"stream Message"}
{"level":"info","ts":"2024-04-22T17:18:14.784735+0800","caller":"rafthttp/peer_status.go:53","msg":"peer became active","peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:14.784757+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:14.785376+0800","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"459d9a5e5c0b19ce","to":"4a62c02900b8e042","stream-type":"stream MsgApp v2"}
{"level":"info","ts":"2024-04-22T17:18:14.785403+0800","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:14.788008+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:14.788099+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"warn","ts":"2024-04-22T17:18:14.794832+0800","caller":"rafthttp/peer_status.go:66","msg":"peer became inactive (message send to peer failed)","peer-id":"4a62c02900b8e042","error":"failed to write 4a62c02900b8e042 on pipeline (EOF)"}
{"level":"warn","ts":"2024-04-22T17:18:14.794958+0800","caller":"rafthttp/stream.go:421","msg":"lost TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042","error":"unexpected EOF"}
{"level":"warn","ts":"2024-04-22T17:18:14.795008+0800","caller":"rafthttp/stream.go:421","msg":"lost TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042","error":"unexpected EOF"}
{"level":"warn","ts":"2024-04-22T17:18:14.926453+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:15.107867+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 3"}
{"level":"info","ts":"2024-04-22T17:18:15.107893+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 3"}
{"level":"info","ts":"2024-04-22T17:18:15.107909+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 3"}
{"level":"info","ts":"2024-04-22T17:18:15.107929+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 3, index: 21] sent MsgPreVote request to 4a62c02900b8e042 at term 3"}
{"level":"warn","ts":"2024-04-22T17:18:15.413266+0800","caller":"etcdserver/server.go:1207","msg":"Failed to check current member's leadership","error":"context deadline exceeded"}
{"level":"warn","ts":"2024-04-22T17:18:15.41786+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000047619s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:15.417904+0800","caller":"traceutil/trace.go:171","msg":"trace[1405603094] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.00011304s","start":"2024-04-22T17:18:12.41778+0800","end":"2024-04-22T17:18:15.417894+0800","steps":["trace[1405603094] 'agreement among raft nodes before linearized reading' (duration: 3.000045082s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:15.417955+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:12.417741+0800","time spent":"3.00020092s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:15.417868+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000121365s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:15.417996+0800","caller":"traceutil/trace.go:171","msg":"trace[1260432315] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000283279s","start":"2024-04-22T17:18:12.4177+0800","end":"2024-04-22T17:18:15.417984+0800","steps":["trace[1260432315] 'agreement among raft nodes before linearized reading' (duration: 3.000146912s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:15.418056+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:12.417677+0800","time spent":"3.00034511s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:15.426627+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:15.926869+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:16.427094+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:16.927466+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:17.008195+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 3"}
{"level":"info","ts":"2024-04-22T17:18:17.008224+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 3"}
{"level":"info","ts":"2024-04-22T17:18:17.00824+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 3"}
{"level":"info","ts":"2024-04-22T17:18:17.008263+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 3, index: 21] sent MsgPreVote request to 4a62c02900b8e042 at term 3"}
{"level":"warn","ts":"2024-04-22T17:18:17.008395+0800","caller":"rafthttp/stream.go:223","msg":"lost TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"warn","ts":"2024-04-22T17:18:17.214265+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.999866041s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:17.214304+0800","caller":"traceutil/trace.go:171","msg":"trace[288510074] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"2.999954394s","start":"2024-04-22T17:18:14.214339+0800","end":"2024-04-22T17:18:17.214294+0800","steps":["trace[288510074] 'agreement among raft nodes before linearized reading' (duration: 2.999887803s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:17.214353+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:14.214325+0800","time spent":"3.000014368s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:17.214263+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000134835s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"warn","ts":"2024-04-22T17:18:17.214382+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000035524s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:17.214404+0800","caller":"traceutil/trace.go:171","msg":"trace[1189092232] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000321405s","start":"2024-04-22T17:18:14.214076+0800","end":"2024-04-22T17:18:17.214397+0800","steps":["trace[1189092232] 'agreement among raft nodes before linearized reading' (duration: 3.000164594s)"],"step_count":1}
{"level":"info","ts":"2024-04-22T17:18:17.214437+0800","caller":"traceutil/trace.go:171","msg":"trace[667517372] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000099656s","start":"2024-04-22T17:18:14.214311+0800","end":"2024-04-22T17:18:17.214411+0800","steps":["trace[667517372] 'agreement among raft nodes before linearized reading' (duration: 3.000034675s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:17.214454+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:14.21406+0800","time spent":"3.000380723s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:17.21448+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:14.214289+0800","time spent":"3.000176986s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:17.428072+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:17.928995+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:17.983864+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000362299s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:17.983898+0800","caller":"traceutil/trace.go:171","msg":"trace[802432559] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000425532s","start":"2024-04-22T17:18:14.983464+0800","end":"2024-04-22T17:18:17.98389+0800","steps":["trace[802432559] 'agreement among raft nodes before linearized reading' (duration: 3.000381094s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:17.983944+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:14.983453+0800","time spent":"3.000476354s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:18.419004+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000869064s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:18.419052+0800","caller":"traceutil/trace.go:171","msg":"trace[213874998] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000955808s","start":"2024-04-22T17:18:15.418084+0800","end":"2024-04-22T17:18:18.41904+0800","steps":["trace[213874998] 'agreement among raft nodes before linearized reading' (duration: 3.000882947s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:18.419092+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:15.418075+0800","time spent":"3.001003601s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:18.419004+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000842532s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:18.419141+0800","caller":"traceutil/trace.go:171","msg":"trace[1620500328] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.0010143s","start":"2024-04-22T17:18:15.41812+0800","end":"2024-04-22T17:18:18.419134+0800","steps":["trace[1620500328] 'agreement among raft nodes before linearized reading' (duration: 3.000854942s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:18.419172+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:15.41811+0800","time spent":"3.001051066s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:18.429705+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:18.907756+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 3"}
{"level":"info","ts":"2024-04-22T17:18:18.907788+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 3"}
{"level":"info","ts":"2024-04-22T17:18:18.907804+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 3"}
{"level":"info","ts":"2024-04-22T17:18:18.907827+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 3, index: 21] sent MsgPreVote request to 4a62c02900b8e042 at term 3"}
{"level":"warn","ts":"2024-04-22T17:18:18.930738+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:19.431448+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:19.931696+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:20.06129+0800","caller":"rafthttp/stream.go:194","msg":"lost TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"warn","ts":"2024-04-22T17:18:20.21452+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.999953545s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:20.214566+0800","caller":"traceutil/trace.go:171","msg":"trace[1367233977] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000034722s","start":"2024-04-22T17:18:17.214518+0800","end":"2024-04-22T17:18:20.214553+0800","steps":["trace[1367233977] 'agreement among raft nodes before linearized reading' (duration: 2.999972175s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:20.214606+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:17.214507+0800","time spent":"3.000084957s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:20.214518+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.999998331s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:20.214644+0800","caller":"traceutil/trace.go:171","msg":"trace[903216851] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000171196s","start":"2024-04-22T17:18:17.214464+0800","end":"2024-04-22T17:18:20.214636+0800","steps":["trace[903216851] 'agreement among raft nodes before linearized reading' (duration: 3.000016783s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:20.214673+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:17.214452+0800","time spent":"3.000209952s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:20.214681+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000113365s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context canceled"}
{"level":"info","ts":"2024-04-22T17:18:20.214749+0800","caller":"traceutil/trace.go:171","msg":"trace[1739170339] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000231859s","start":"2024-04-22T17:18:17.214502+0800","end":"2024-04-22T17:18:20.214734+0800","steps":["trace[1739170339] 'agreement among raft nodes before linearized reading' (duration: 3.00011979s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:20.214798+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:17.214496+0800","time spent":"3.000286035s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:20.43264+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:20.807951+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 3"}
{"level":"info","ts":"2024-04-22T17:18:20.807983+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 3"}
{"level":"info","ts":"2024-04-22T17:18:20.807999+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 3"}
{"level":"info","ts":"2024-04-22T17:18:20.808021+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 3, index: 21] sent MsgPreVote request to 4a62c02900b8e042 at term 3"}
{"level":"warn","ts":"2024-04-22T17:18:20.932994+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150365,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:21.419507+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000205373s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"warn","ts":"2024-04-22T17:18:21.419519+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000261861s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:21.419585+0800","caller":"traceutil/trace.go:171","msg":"trace[124561635] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000374067s","start":"2024-04-22T17:18:18.419198+0800","end":"2024-04-22T17:18:21.419573+0800","steps":["trace[124561635] 'agreement among raft nodes before linearized reading' (duration: 3.000281473s)"],"step_count":1}
{"level":"info","ts":"2024-04-22T17:18:21.419552+0800","caller":"traceutil/trace.go:171","msg":"trace[377809962] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000290934s","start":"2024-04-22T17:18:18.41925+0800","end":"2024-04-22T17:18:21.419541+0800","steps":["trace[377809962] 'agreement among raft nodes before linearized reading' (duration: 3.000217318s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:21.419682+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:18.419241+0800","time spent":"3.000420107s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:21.419632+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:18.419187+0800","time spent":"3.000430836s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:21.425839+0800","caller":"etcdserver/v3_server.go:920","msg":"timed out waiting for read index response (local node might have slow network)","timeout":"7s"}
{"level":"warn","ts":"2024-04-22T17:18:21.425888+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"13.21107828s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/proxy/proxyConfirmCorrupt\" ","response":"","error":"etcdserver: request timed out"}
{"level":"info","ts":"2024-04-22T17:18:21.425939+0800","caller":"traceutil/trace.go:171","msg":"trace[31115499] range","detail":"{range_begin:/proxy/proxyConfirmCorrupt; range_end:; }","duration":"13.211144543s","start":"2024-04-22T17:18:08.214786+0800","end":"2024-04-22T17:18:21.425931+0800","steps":["trace[31115499] 'agreement among raft nodes before linearized reading' (duration: 13.211089261s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:21.425969+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:08.214778+0800","time spent":"13.21118189s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/proxy/proxyConfirmCorrupt\" "}
{"level":"warn","ts":"2024-04-22T17:18:21.425894+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"13.211117309s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/db/dbConfirmCorrupt\" ","response":"","error":"etcdserver: request timed out"}
{"level":"info","ts":"2024-04-22T17:18:21.426019+0800","caller":"traceutil/trace.go:171","msg":"trace[441788239] range","detail":"{range_begin:/db/dbConfirmCorrupt; range_end:; }","duration":"13.211258829s","start":"2024-04-22T17:18:08.214751+0800","end":"2024-04-22T17:18:21.42601+0800","steps":["trace[441788239] 'agreement among raft nodes before linearized reading' (duration: 13.211130122s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:21.426056+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:08.214742+0800","time spent":"13.211303841s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":22,"response count":0,"response size":0,"request content":"key:\"/db/dbConfirmCorrupt\" "}
{"level":"warn","ts":"2024-04-22T17:18:21.425897+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"13.211116659s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/replicator/replicatorConfirmCorrupt\" ","response":"","error":"etcdserver: request timed out"}
{"level":"info","ts":"2024-04-22T17:18:21.426093+0800","caller":"traceutil/trace.go:171","msg":"trace[295357257] range","detail":"{range_begin:/replicator/replicatorConfirmCorrupt; range_end:; }","duration":"13.211324248s","start":"2024-04-22T17:18:08.214756+0800","end":"2024-04-22T17:18:21.426081+0800","steps":["trace[295357257] 'agreement among raft nodes before linearized reading' (duration: 13.211127904s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:21.426125+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:08.214748+0800","time spent":"13.211366383s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":38,"response count":0,"response size":0,"request content":"key:\"/replicator/replicatorConfirmCorrupt\" "}
{"level":"warn","ts":"2024-04-22T17:18:21.926192+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150369,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:22.414674+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:15.413591+0800","time spent":"7.001077984s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.Lease/LeaseGrant","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""}
{"level":"warn","ts":"2024-04-22T17:18:22.42714+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150369,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:22.707503+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 3"}
{"level":"info","ts":"2024-04-22T17:18:22.707535+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 3"}
{"level":"info","ts":"2024-04-22T17:18:22.707559+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 3"}
{"level":"info","ts":"2024-04-22T17:18:22.707586+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 3, index: 21] sent MsgPreVote request to 4a62c02900b8e042 at term 3"}
{"level":"warn","ts":"2024-04-22T17:18:22.927204+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150369,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:23.214873+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000041505s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:23.214917+0800","caller":"traceutil/trace.go:171","msg":"trace[752302598] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000121164s","start":"2024-04-22T17:18:20.214782+0800","end":"2024-04-22T17:18:23.214903+0800","steps":["trace[752302598] 'agreement among raft nodes before linearized reading' (duration: 3.00005323s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:23.214948+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000135133s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context canceled"}
{"level":"warn","ts":"2024-04-22T17:18:23.214967+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:20.214773+0800","time spent":"3.000173713s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"info","ts":"2024-04-22T17:18:23.214978+0800","caller":"traceutil/trace.go:171","msg":"trace[2038801721] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000188285s","start":"2024-04-22T17:18:20.214783+0800","end":"2024-04-22T17:18:23.214971+0800","steps":["trace[2038801721] 'agreement among raft nodes before linearized reading' (duration: 3.000148103s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:23.215007+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000239747s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"warn","ts":"2024-04-22T17:18:23.215011+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:20.214774+0800","time spent":"3.000225635s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"info","ts":"2024-04-22T17:18:23.21503+0800","caller":"traceutil/trace.go:171","msg":"trace[1946329831] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000288827s","start":"2024-04-22T17:18:20.214735+0800","end":"2024-04-22T17:18:23.215024+0800","steps":["trace[1946329831] 'agreement among raft nodes before linearized reading' (duration: 3.000261384s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:23.215068+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:20.214722+0800","time spent":"3.000329618s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:23.428189+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150369,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:23.928748+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150369,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:24.429056+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150369,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:24.512835+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:19.512393+0800","time spent":"5.000437447s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.Lease/LeaseRevoke","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""}
{"level":"info","ts":"2024-04-22T17:18:24.607714+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 3"}
{"level":"info","ts":"2024-04-22T17:18:24.607741+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 3"}
{"level":"info","ts":"2024-04-22T17:18:24.607758+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 3"}
{"level":"info","ts":"2024-04-22T17:18:24.60778+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 3, index: 21] sent MsgPreVote request to 4a62c02900b8e042 at term 3"}
{"level":"warn","ts":"2024-04-22T17:18:24.929573+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150369,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:25.430011+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150369,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:25.930192+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150369,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:26.215769+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000684517s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"warn","ts":"2024-04-22T17:18:26.215779+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.000548544s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:26.215823+0800","caller":"traceutil/trace.go:171","msg":"trace[1203576879] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000767962s","start":"2024-04-22T17:18:23.215042+0800","end":"2024-04-22T17:18:26.21581+0800","steps":["trace[1203576879] 'agreement among raft nodes before linearized reading' (duration: 3.000681218s)"],"step_count":1}
{"level":"info","ts":"2024-04-22T17:18:26.215837+0800","caller":"traceutil/trace.go:171","msg":"trace[1872773363] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000648309s","start":"2024-04-22T17:18:23.215176+0800","end":"2024-04-22T17:18:26.215824+0800","steps":["trace[1872773363] 'agreement among raft nodes before linearized reading' (duration: 3.000559316s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:26.215871+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:23.215031+0800","time spent":"3.000826048s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:26.215896+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:23.215168+0800","time spent":"3.00071384s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:26.215777+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.00062177s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context deadline exceeded"}
{"level":"info","ts":"2024-04-22T17:18:26.215959+0800","caller":"traceutil/trace.go:171","msg":"trace[240111777] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"3.000831317s","start":"2024-04-22T17:18:23.215117+0800","end":"2024-04-22T17:18:26.215949+0800","steps":["trace[240111777] 'agreement among raft nodes before linearized reading' (duration: 3.000638629s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:26.215999+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:23.215109+0800","time spent":"3.000875899s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:26.430596+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150369,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:26.507247+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce is starting a new election at term 3"}
{"level":"info","ts":"2024-04-22T17:18:26.507285+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce became pre-candidate at term 3"}
{"level":"info","ts":"2024-04-22T17:18:26.507303+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce received MsgPreVoteResp from 459d9a5e5c0b19ce at term 3"}
{"level":"info","ts":"2024-04-22T17:18:26.507325+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"459d9a5e5c0b19ce [logterm: 3, index: 21] sent MsgPreVote request to 4a62c02900b8e042 at term 3"}
{"level":"warn","ts":"2024-04-22T17:18:26.9313+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150369,"retry-timeout":"500ms"}
{"level":"warn","ts":"2024-04-22T17:18:27.431947+0800","caller":"etcdserver/v3_server.go:908","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":1859580948208150369,"retry-timeout":"500ms"}
{"level":"info","ts":"2024-04-22T17:18:27.83729+0800","caller":"embed/etcd.go:375","msg":"closing etcd server","name":"cs0","data-dir":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs0_31302/data","advertise-peer-urls":["http://127.0.0.1:31303"],"advertise-client-urls":["http://127.0.0.1:41303"]}
{"level":"warn","ts":"2024-04-22T17:18:27.837344+0800","caller":"embed/serve.go:160","msg":"stopping insecure grpc server due to error","error":"accept tcp 127.0.0.1:41303: use of closed network connection"}
{"level":"warn","ts":"2024-04-22T17:18:27.837499+0800","caller":"embed/serve.go:162","msg":"stopped insecure grpc server due to error","error":"accept tcp 127.0.0.1:41303: use of closed network connection"}
{"level":"info","ts":"2024-04-22T17:18:27.837554+0800","caller":"etcdserver/server.go:1504","msg":"skipped leadership transfer; local server is not leader","local-member-id":"459d9a5e5c0b19ce","current-leader-member-id":"0"}
{"level":"warn","ts":"2024-04-22T17:18:27.837583+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:22.439405+0800","time spent":"5.398172874s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.Lease/LeaseGrant","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""}
{"level":"warn","ts":"2024-04-22T17:18:27.837635+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"8.325244161s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader/\" range_end:\"/cs/leader0\" limit:1 sort_order:ASCEND sort_target:CREATE ","response":"","error":"context canceled"}
{"level":"warn","ts":"2024-04-22T17:18:27.837658+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:24.513055+0800","time spent":"3.324600677s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.Lease/LeaseGrant","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""}
{"level":"info","ts":"2024-04-22T17:18:27.837669+0800","caller":"traceutil/trace.go:171","msg":"trace[842287068] range","detail":"{range_begin:/cs/leader/; range_end:/cs/leader0; }","duration":"8.325332028s","start":"2024-04-22T17:18:19.512326+0800","end":"2024-04-22T17:18:27.837658+0800","steps":["trace[842287068] 'agreement among raft nodes before linearized reading' (duration: 8.325262094s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:27.837714+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:19.512315+0800","time spent":"8.325384013s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":32,"response count":0,"response size":0,"request content":"key:\"/cs/leader/\" range_end:\"/cs/leader0\" limit:1 sort_order:ASCEND sort_target:CREATE "}
{"level":"warn","ts":"2024-04-22T17:18:27.83773+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.621506407s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context canceled"}
{"level":"info","ts":"2024-04-22T17:18:27.837764+0800","caller":"traceutil/trace.go:171","msg":"trace[1064522004] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"1.621582488s","start":"2024-04-22T17:18:26.216172+0800","end":"2024-04-22T17:18:27.837754+0800","steps":["trace[1064522004] 'agreement among raft nodes before linearized reading' (duration: 1.621527191s)"],"step_count":1}
{"level":"warn","ts":"2024-04-22T17:18:27.837799+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:26.216157+0800","time spent":"1.621627636s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:27.837814+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.621605785s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context canceled"}
{"level":"warn","ts":"2024-04-22T17:18:27.837802+0800","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.621596986s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD ","response":"","error":"context canceled"}
{"level":"info","ts":"2024-04-22T17:18:27.837845+0800","caller":"traceutil/trace.go:171","msg":"trace[1617585279] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"1.621664265s","start":"2024-04-22T17:18:26.216174+0800","end":"2024-04-22T17:18:27.837838+0800","steps":["trace[1617585279] 'agreement among raft nodes before linearized reading' (duration: 1.621624866s)"],"step_count":1}
{"level":"info","ts":"2024-04-22T17:18:27.83786+0800","caller":"traceutil/trace.go:171","msg":"trace[2045591900] range","detail":"{range_begin:/cs/leader; range_end:/cs/leades; }","duration":"1.62168666s","start":"2024-04-22T17:18:26.216166+0800","end":"2024-04-22T17:18:27.837853+0800","steps":["trace[2045591900] 'agreement among raft nodes before linearized reading' (duration: 1.621618684s)"],"step_count":1}
{"level":"info","ts":"2024-04-22T17:18:27.837866+0800","caller":"rafthttp/peer.go:330","msg":"stopping remote peer","remote-peer-id":"4a62c02900b8e042"}
{"level":"warn","ts":"2024-04-22T17:18:27.837878+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:26.216164+0800","time spent":"1.621701753s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"warn","ts":"2024-04-22T17:18:27.837892+0800","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-04-22T17:18:26.216151+0800","time spent":"1.621728539s","remote":"127.0.0.1:39294","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":0,"response size":0,"request content":"key:\"/cs/leader\" range_end:\"/cs/leades\" sort_order:ASCEND sort_target:MOD "}
{"level":"info","ts":"2024-04-22T17:18:27.837889+0800","caller":"rafthttp/stream.go:294","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:27.837923+0800","caller":"rafthttp/stream.go:294","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"stream Message","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:27.837961+0800","caller":"rafthttp/pipeline.go:85","msg":"stopped HTTP pipelining with remote peer","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:27.837983+0800","caller":"rafthttp/stream.go:442","msg":"stopped stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:27.838013+0800","caller":"rafthttp/stream.go:442","msg":"stopped stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"459d9a5e5c0b19ce","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:27.838034+0800","caller":"rafthttp/peer.go:335","msg":"stopped remote peer","remote-peer-id":"4a62c02900b8e042"}
{"level":"info","ts":"2024-04-22T17:18:27.838564+0800","caller":"embed/etcd.go:579","msg":"stopping serving peer traffic","address":"127.0.0.1:31303"}
{"level":"info","ts":"2024-04-22T17:18:27.838636+0800","caller":"embed/etcd.go:584","msg":"stopped serving peer traffic","address":"127.0.0.1:31303"}
{"level":"info","ts":"2024-04-22T17:18:27.838654+0800","caller":"embed/etcd.go:377","msg":"closed etcd server","name":"cs0","data-dir":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs0_31302/data","advertise-peer-urls":["http://127.0.0.1:31303"],"advertise-client-urls":["http://127.0.0.1:41303"]}
from etcd.
node2 log:
{"level":"warn","ts":"2024-04-22T17:18:07.777469+0800","caller":"embed/config.go:679","msg":"Running http and grpc server on single port. This is not recommended for production."}
{"level":"info","ts":"2024-04-22T17:18:07.777544+0800","caller":"embed/etcd.go:127","msg":"configuring peer listeners","listen-peer-urls":["http://127.0.0.1:31305"]}
{"level":"info","ts":"2024-04-22T17:18:07.777667+0800","caller":"embed/etcd.go:135","msg":"configuring client listeners","listen-client-urls":["http://127.0.0.1:41305"]}
{"level":"info","ts":"2024-04-22T17:18:07.777749+0800","caller":"embed/etcd.go:308","msg":"starting an etcd server","etcd-version":"3.5.13","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.20.5","go-os":"linux","go-arch":"amd64","max-cpu-set":4,"max-cpu-available":32,"member-initialized":false,"name":"cs1","data-dir":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs1_31304/data","wal-dir":"","wal-dir-dedicated":"","member-dir":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs1_31304/data/member","force-new-cluster":false,"heartbeat-interval":"100ms","election-timeout":"1s","initial-election-tick-advance":true,"snapshot-count":100000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://127.0.0.1:31305"],"listen-peer-urls":["http://127.0.0.1:31305"],"advertise-client-urls":["http://127.0.0.1:41305"],"listen-client-urls":["http://127.0.0.1:41305"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"cs0=http://127.0.0.1:31303,cs1=http://127.0.0.1:31305","initial-cluster-state":"existing","initial-cluster-token":"cluster1","quota-backend-bytes":8589934592,"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":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"}
{"level":"warn","ts":"2024-04-22T17:18:07.777824+0800","caller":"fileutil/fileutil.go:53","msg":"check file permission","error":"directory \"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs1_31304/data\" exist, but the permission is \"drwxrwxrwx\". The recommended permission is \"-rwx------\" to prevent possible unprivileged access to the data"}
{"level":"info","ts":"2024-04-22T17:18:07.778514+0800","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs1_31304/data/member/snap/db","took":"513.503µs"}
{"level":"info","ts":"2024-04-22T17:18:07.779304+0800","caller":"netutil/netutil.go:112","msg":"resolved URL Host","url":"http://127.0.0.1:31305","host":"127.0.0.1:31305","resolved-addr":"127.0.0.1:31305"}
{"level":"info","ts":"2024-04-22T17:18:07.779355+0800","caller":"netutil/netutil.go:112","msg":"resolved URL Host","url":"http://127.0.0.1:31303","host":"127.0.0.1:31303","resolved-addr":"127.0.0.1:31303"}
{"level":"warn","ts":"2024-04-22T17:18:14.779922+0800","caller":"etcdserver/cluster_util.go:442","msg":"failed to convert response","address":"http://127.0.0.1:31303/downgrade/enabled","remote-member-id":"459d9a5e5c0b19ce","error":"strconv.ParseBool: parsing \"failed linearized read: context deadline exceeded\\n\": invalid syntax"}
{"level":"warn","ts":"2024-04-22T17:18:14.779967+0800","caller":"etcdserver/cluster_util.go:392","msg":"failed to get downgrade enabled status","remote-member-id":"459d9a5e5c0b19ce","error":"strconv.ParseBool: parsing \"failed linearized read: context deadline exceeded\\n\": invalid syntax"}
{"level":"info","ts":"2024-04-22T17:18:14.780906+0800","caller":"etcdserver/raft.go:495","msg":"starting local member","local-member-id":"4a62c02900b8e042","cluster-id":"d782b9400782601d"}
{"level":"info","ts":"2024-04-22T17:18:14.780959+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"4a62c02900b8e042 switched to configuration voters=()"}
{"level":"info","ts":"2024-04-22T17:18:14.781006+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"4a62c02900b8e042 became follower at term 0"}
{"level":"info","ts":"2024-04-22T17:18:14.781023+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 4a62c02900b8e042 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"}
{"level":"warn","ts":"2024-04-22T17:18:14.781358+0800","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"}
{"level":"info","ts":"2024-04-22T17:18:14.78318+0800","caller":"mvcc/kvstore.go:407","msg":"kvstore restored","current-rev":1}
{"level":"info","ts":"2024-04-22T17:18:14.783463+0800","caller":"etcdserver/quota.go:117","msg":"enabled backend quota","quota-name":"v3-applier","quota-size-bytes":8589934592,"quota-size":"8.6 GB"}
{"level":"info","ts":"2024-04-22T17:18:14.783674+0800","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"4a62c02900b8e042","remote-peer-id":"459d9a5e5c0b19ce"}
{"level":"info","ts":"2024-04-22T17:18:14.783694+0800","caller":"rafthttp/transport.go:286","msg":"added new remote peer","local-member-id":"4a62c02900b8e042","remote-peer-id":"459d9a5e5c0b19ce","remote-peer-urls":["http://127.0.0.1:31303"]}
{"level":"info","ts":"2024-04-22T17:18:14.783714+0800","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"459d9a5e5c0b19ce"}
{"level":"info","ts":"2024-04-22T17:18:14.783778+0800","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"4a62c02900b8e042","remote-peer-id":"459d9a5e5c0b19ce"}
{"level":"info","ts":"2024-04-22T17:18:14.783963+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"4a62c02900b8e042","remote-peer-id":"459d9a5e5c0b19ce"}
{"level":"info","ts":"2024-04-22T17:18:14.784045+0800","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"4a62c02900b8e042","remote-peer-id":"459d9a5e5c0b19ce"}
{"level":"info","ts":"2024-04-22T17:18:14.784117+0800","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"459d9a5e5c0b19ce"}
{"level":"info","ts":"2024-04-22T17:18:14.784135+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"4a62c02900b8e042","remote-peer-id":"459d9a5e5c0b19ce"}
{"level":"info","ts":"2024-04-22T17:18:14.784183+0800","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"4a62c02900b8e042","remote-peer-id":"459d9a5e5c0b19ce","remote-peer-urls":["http://127.0.0.1:31303"]}
{"level":"info","ts":"2024-04-22T17:18:14.784199+0800","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"4a62c02900b8e042","remote-peer-id":"459d9a5e5c0b19ce"}
{"level":"info","ts":"2024-04-22T17:18:14.784222+0800","caller":"etcdserver/server.go:867","msg":"starting etcd server","local-member-id":"4a62c02900b8e042","local-server-version":"3.5.13","cluster-version":"to_be_decided"}
{"level":"info","ts":"2024-04-22T17:18:14.784384+0800","caller":"etcdserver/server.go:767","msg":"starting initial election tick advance","election-ticks":10}
{"level":"info","ts":"2024-04-22T17:18:14.78439+0800","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs1_31304/data/member/snap","suffix":"snap.db","max":5,"interval":"30s"}
{"level":"info","ts":"2024-04-22T17:18:14.784444+0800","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs1_31304/data/member/snap","suffix":"snap","max":5,"interval":"30s"}
{"level":"info","ts":"2024-04-22T17:18:14.784462+0800","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/home/chenyangyang.cy/redis-config-server/tests/tmp/cases.rebalance_mock/cluster1_cs1_31304/data/member/wal","suffix":"wal","max":5,"interval":"30s"}
{"level":"info","ts":"2024-04-22T17:18:14.78469+0800","caller":"rafthttp/peer_status.go:53","msg":"peer became active","peer-id":"459d9a5e5c0b19ce"}
{"level":"info","ts":"2024-04-22T17:18:14.78472+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"4a62c02900b8e042","remote-peer-id":"459d9a5e5c0b19ce"}
{"level":"info","ts":"2024-04-22T17:18:14.78472+0800","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"4a62c02900b8e042","remote-peer-id":"459d9a5e5c0b19ce"}
{"level":"info","ts":"2024-04-22T17:18:14.787634+0800","caller":"embed/etcd.go:277","msg":"now serving peer/client/metrics","local-member-id":"4a62c02900b8e042","initial-advertise-peer-urls":["http://127.0.0.1:31305"],"listen-peer-urls":["http://127.0.0.1:31305"],"advertise-client-urls":["http://127.0.0.1:41305"],"listen-client-urls":["http://127.0.0.1:41305"],"listen-metrics-urls":[]}
{"level":"info","ts":"2024-04-22T17:18:14.787646+0800","caller":"embed/etcd.go:597","msg":"serving peer traffic","address":"127.0.0.1:31305"}
{"level":"info","ts":"2024-04-22T17:18:14.78768+0800","caller":"embed/etcd.go:569","msg":"cmux::serve","address":"127.0.0.1:31305"}
{"level":"info","ts":"2024-04-22T17:18:14.787941+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"4a62c02900b8e042 [term: 0] received a MsgHeartbeat message with higher term from 459d9a5e5c0b19ce [term: 3]"}
{"level":"info","ts":"2024-04-22T17:18:14.787972+0800","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"4a62c02900b8e042 became follower at term 3"}
{"level":"panic","ts":"2024-04-22T17:18:14.787986+0800","logger":"raft","caller":"etcdserver/zap_raft.go:101","msg":"tocommit(21) is out of range [lastIndex(0)]. Was the raft log corrupted, truncated, or lost?","stacktrace":"go.etcd.io/etcd/server/v3/etcdserver.(*zapRaftLogger).Panicf\n\t/home/chenyangyang.cy/redis-config-server/build/go/pkg/mod/go.etcd.io/etcd/server/[email protected]/etcdserver/zap_raft.go:101\ngo.etcd.io/etcd/raft/v3.(*raftLog).commitTo\n\t/home/chenyangyang.cy/redis-config-server/build/go/pkg/mod/go.etcd.io/etcd/raft/[email protected]/log.go:237\ngo.etcd.io/etcd/raft/v3.(*raft).handleHeartbeat\n\t/home/chenyangyang.cy/redis-config-server/build/go/pkg/mod/go.etcd.io/etcd/raft/[email protected]/raft.go:1508\ngo.etcd.io/etcd/raft/v3.stepFollower\n\t/home/chenyangyang.cy/redis-config-server/build/go/pkg/mod/go.etcd.io/etcd/raft/[email protected]/raft.go:1434\ngo.etcd.io/etcd/raft/v3.(*raft).Step\n\t/home/chenyangyang.cy/redis-config-server/build/go/pkg/mod/go.etcd.io/etcd/raft/[email protected]/raft.go:975\ngo.etcd.io/etcd/raft/v3.(*node).run\n\t/home/chenyangyang.cy/redis-config-server/build/go/pkg/mod/go.etcd.io/etcd/raft/[email protected]/node.go:356"}
from etcd.
cc @ahrtr @fuweid @siyuanfoundation
from etcd.
A known issue etcd-io/raft#18
from etcd.
Also refer etcd-io/raft#29
from etcd.
Related Issues (20)
- Reduce log spam on missing member HOT 4
- etcd leader info status wrong HOT 2
- Failpoint `raftAfterSave=sleep(1s)` is flaking in robustness test HOT 8
- Enabling authentication causes noisy logs for every /readyz call HOT 9
- Plan to release etcd v3.5.15 HOT 20
- Filtering GET request via With{Min,Max}{Create,Mod}Rev has wrong result Count HOT 4
- Bump go to 1.21.12 / 1.22.5 HOT 9
- [robustness tests] Flakiness due to Progress notify does not match for beforeSendWatchResponse=sleep(1s)
- Failure to get list of machines HOT 2
- Code that relies on gRPC metadata formatting should be fixed HOT 11
- Bootstraping etcd using DNS in a DHCP network HOT 2
- etcd cluster error HOT 1
- dial-timeout option does not take effect on the watch command. HOT 1
- HashKV should compute the hash of all MVCC keys up to a given revision HOT 6
- Completion command is not included in releases of etcdctl HOT 1
- Etcd compilation process error HOT 4
- Etcd send a corrupt snapshot or missing hash snapshot to a snapshot api call which causes the restoration to fail. HOT 7
- option go_package in proto files HOT 4
- Client v3 and GRPC versions conflict HOT 3
- Member remains learner after promotion HOT 1
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from etcd.