search

tikv / pd

Placement driver for TiKV
Apache License 2.0
1.04k stars 717 forks source link

`TestEtcdClientSync` is flaky #8085

Open rleungx opened 4 months ago

rleungx commented 4 months ago

Flaky Test

Which jobs are failing

--- FAIL: TestEtcdClientSync (0.86s)
    etcdutil_test.go:185: 
            Error Trace:    /home/runner/work/pd/pd/pkg/utils/etcdutil/etcdutil_test.go:185
            Error:          Received unexpected error:
                            [PD:etcd:ErrEtcdMemberRemove]etcdserver: server stopped: etcdserver: server stopped
                            github.com/pingcap/errors.AddStack
                                /home/runner/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20211224045212-9687c2b0f87c/errors.go:174
                            github.com/pingcap/errors.(*Error).GenWithStackByCause
                                /home/runner/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20211224045212-9687c2b0f87c/normalize.go:307
                            github.com/tikv/pd/pkg/utils/etcdutil.RemoveEtcdMember
                                /home/runner/work/pd/pd/pkg/utils/etcdutil/etcdutil.go:136
                            github.com/tikv/pd/pkg/utils/etcdutil.TestEtcdClientSync
                                /home/runner/work/pd/pd/pkg/utils/etcdutil/etcdutil_test.go:184
                            testing.tRunner
                                /opt/hostedtoolcache/go/1.21.9/x64/src/testing/testing.go:1595
                            runtime.goexit
                                /opt/hostedtoolcache/go/1.21.9/x64/src/runtime/asm_amd64.s:1650
            Test:           TestEtcdClientSync

CI link

https://github.com/tikv/pd/actions/runs/8718669939/job/23916391513?pr=8082

Reason for failure (if possible)

Anything else

lhy1024 commented 4 months ago 
2024-04-23T06:55:55.9231651Z --- FAIL: TestEtcdClientSync (0.88s)
2024-04-23T06:55:55.9232127Z     etcdutil_test.go:199: 
2024-04-23T06:55:55.9232909Z            Error Trace:    /home/runner/work/pd/pd/pkg/utils/etcdutil/etcdutil_test.go:199
2024-04-23T06:55:55.9233719Z            Error:          Received unexpected error:
2024-04-23T06:55:55.9234787Z                            [PD:etcd:ErrEtcdMemberRemove]etcdserver: server stopped: etcdserver: server stopped
2024-04-23T06:55:55.9235639Z                            github.com/pingcap/errors.AddStack
2024-04-23T06:55:55.9237146Z                                /home/runner/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20211224045212-9687c2b0f87c/errors.go:174
2024-04-23T06:55:55.9238280Z                            github.com/pingcap/errors.(*Error).GenWithStackByCause
2024-04-23T06:55:55.9239879Z                                /home/runner/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20211224045212-9687c2b0f87c/normalize.go:307
2024-04-23T06:55:55.9241015Z                            github.com/tikv/pd/pkg/utils/etcdutil.RemoveEtcdMember
2024-04-23T06:55:55.9242025Z                                /home/runner/work/pd/pd/pkg/utils/etcdutil/etcdutil.go:136
2024-04-23T06:55:55.9243000Z                            github.com/tikv/pd/pkg/utils/etcdutil.TestEtcdClientSync
2024-04-23T06:55:55.9244077Z                                /home/runner/work/pd/pd/pkg/utils/etcdutil/etcdutil_test.go:198
2024-04-23T06:55:55.9244777Z                            testing.tRunner
2024-04-23T06:55:55.9245760Z                                /opt/hostedtoolcache/go/1.21.9/x64/src/testing/testing.go:1595
2024-04-23T06:55:55.9246460Z                            runtime.goexit
2024-04-23T06:55:55.9247287Z                                /opt/hostedtoolcache/go/1.21.9/x64/src/runtime/asm_amd64.s:1650
2024-04-23T06:55:55.9247988Z            Test:           TestEtcdClientSync

https://github.com/tikv/pd/actions/runs/8796064689/job/24138225547?pr=8116

okJiang commented 1 month ago

I tried this test on my local Mac, and every time I encountered this issue, here is the error log. I observed that after member 2(8195c4f470081d6c, "http://127.0.0.1:57908") exited, member 1(517aa5d5512611cd, "http://127.0.0.1:57902") also exited by itself, causing the error later on. However, I couldn't find the reason why member 1 exited along with member 2.

error.log Running tool: /usr/local/go/bin/go test -timeout 600s -run ^TestEtcdClientSync$ github.com/tikv/pd/pkg/utils/etcdutil -race --tags=intest {"level":"warn","ts":"2024-07-10T15:15:00.093994+0800","caller":"embed/config.go:622","msg":"Running http and grpc server on single port. This is not recommended for production."} {"level":"info","ts":"2024-07-10T15:15:00.094253+0800","caller":"embed/etcd.go:120","msg":"configuring peer listeners","listen-peer-urls":["http://127.0.0.1:57901"]} {"level":"info","ts":"2024-07-10T15:15:00.094359+0800","caller":"embed/etcd.go:130","msg":"configuring client listeners","listen-client-urls":["http://127.0.0.1:57902"]} {"level":"info","ts":"2024-07-10T15:15:00.09449+0800","caller":"embed/etcd.go:309","msg":"starting an etcd server","etcd-version":"3.4.31","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.21.2","go-os":"darwin","go-arch":"arm64","max-cpu-set":8,"max-cpu-available":8,"member-initialized":false,"name":"test_etcd_1720595700092998000","data-dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/001","wal-dir":"","wal-dir-dedicated":"","member-dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/001/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:57901"],"listen-peer-urls":["http://127.0.0.1:57901"],"advertise-client-urls":["http://127.0.0.1:57902"],"listen-client-urls":["http://127.0.0.1:57902"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"test_etcd_1720595700092998000=http://127.0.0.1:57901","initial-cluster-state":"new","initial-cluster-token":"etcd-cluster","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":false,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","auto-compaction-mode":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":""} 2024-07-10 15:15:00.094624 W | pkg/fileutil: check file permission: directory "/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/001" exist, but the permission is "drwxr-xr-x". The recommended permission is "-rwx------" to prevent possible unprivileged access to the data. {"level":"info","ts":"2024-07-10T15:15:00.106141+0800","caller":"etcdserver/backend.go:80","msg":"opened backend db","path":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/001/member/snap/db","took":"10.731375ms"} {"level":"info","ts":"2024-07-10T15:15:00.166421+0800","caller":"etcdserver/raft.go:537","msg":"starting local member","local-member-id":"517aa5d5512611cd","cluster-id":"7775bdc730413de5"} {"level":"info","ts":"2024-07-10T15:15:00.166814+0800","caller":"raft/raft.go:1523","msg":"517aa5d5512611cd switched to configuration voters=()"} {"level":"info","ts":"2024-07-10T15:15:00.166941+0800","caller":"raft/raft.go:706","msg":"517aa5d5512611cd became follower at term 0"} {"level":"info","ts":"2024-07-10T15:15:00.166975+0800","caller":"raft/raft.go:389","msg":"newRaft 517aa5d5512611cd [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} {"level":"info","ts":"2024-07-10T15:15:00.167003+0800","caller":"raft/raft.go:706","msg":"517aa5d5512611cd became follower at term 1"} {"level":"info","ts":"2024-07-10T15:15:00.167099+0800","caller":"raft/raft.go:1523","msg":"517aa5d5512611cd switched to configuration voters=(5871187399838929357)"} {"level":"warn","ts":"2024-07-10T15:15:00.181112+0800","caller":"auth/store.go:1391","msg":"simple token is not cryptographically signed"} {"level":"info","ts":"2024-07-10T15:15:00.201183+0800","caller":"etcdserver/quota.go:98","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"} {"level":"info","ts":"2024-07-10T15:15:00.211079+0800","caller":"etcdserver/server.go:831","msg":"starting etcd server","local-member-id":"517aa5d5512611cd","local-server-version":"3.4.31","cluster-version":"to_be_decided"} {"level":"info","ts":"2024-07-10T15:15:00.211337+0800","caller":"fileutil/purge.go:48","msg":"started to purge file","dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/001/member/snap","suffix":"snap.db","max":5,"interval":"30s"} {"level":"info","ts":"2024-07-10T15:15:00.211642+0800","caller":"fileutil/purge.go:48","msg":"started to purge file","dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/001/member/snap","suffix":"snap","max":5,"interval":"30s"} {"level":"info","ts":"2024-07-10T15:15:00.211424+0800","caller":"etcdserver/server.go:697","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"517aa5d5512611cd","forward-ticks":9,"forward-duration":"900ms","election-ticks":10,"election-timeout":"1s"} {"level":"info","ts":"2024-07-10T15:15:00.211696+0800","caller":"fileutil/purge.go:48","msg":"started to purge file","dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/001/member/wal","suffix":"wal","max":5,"interval":"30s"} {"level":"warn","ts":"2024-07-10T15:15:00.21159+0800","caller":"etcdserver/metrics.go:213","msg":"failed to get file descriptor usage","error":"cannot get FDUsage on darwin"} {"level":"info","ts":"2024-07-10T15:15:00.216362+0800","caller":"embed/etcd.go:605","msg":"serving peer traffic","address":"127.0.0.1:57901"} {"level":"info","ts":"2024-07-10T15:15:00.216395+0800","caller":"raft/raft.go:1523","msg":"517aa5d5512611cd switched to configuration voters=(5871187399838929357)"} {"level":"info","ts":"2024-07-10T15:15:00.216415+0800","caller":"embed/etcd.go:251","msg":"now serving peer/client/metrics","local-member-id":"517aa5d5512611cd","initial-advertise-peer-urls":["http://127.0.0.1:57901"],"listen-peer-urls":["http://127.0.0.1:57901"],"advertise-client-urls":["http://127.0.0.1:57902"],"listen-client-urls":["http://127.0.0.1:57902"],"listen-metrics-urls":[]} {"level":"info","ts":"2024-07-10T15:15:00.217221+0800","caller":"membership/cluster.go:395","msg":"added member","cluster-id":"7775bdc730413de5","local-member-id":"517aa5d5512611cd","added-peer-id":"517aa5d5512611cd","added-peer-peer-urls":["http://127.0.0.1:57901"]} {"level":"info","ts":"2024-07-10T15:15:00.769457+0800","caller":"raft/raft.go:929","msg":"517aa5d5512611cd is starting a new election at term 1"} {"level":"info","ts":"2024-07-10T15:15:00.769615+0800","caller":"raft/raft.go:719","msg":"517aa5d5512611cd became candidate at term 2"} {"level":"info","ts":"2024-07-10T15:15:00.769703+0800","caller":"raft/raft.go:830","msg":"517aa5d5512611cd received MsgVoteResp from 517aa5d5512611cd at term 2"} {"level":"info","ts":"2024-07-10T15:15:00.769786+0800","caller":"raft/raft.go:771","msg":"517aa5d5512611cd became leader at term 2"} {"level":"info","ts":"2024-07-10T15:15:00.769846+0800","caller":"raft/node.go:327","msg":"raft.node: 517aa5d5512611cd elected leader 517aa5d5512611cd at term 2"} {"level":"info","ts":"2024-07-10T15:15:00.775434+0800","caller":"etcdserver/server.go:2639","msg":"setting up initial cluster version","cluster-version":"3.4"} {"level":"info","ts":"2024-07-10T15:15:00.775708+0800","caller":"etcdserver/server.go:2140","msg":"published local member to cluster through raft","local-member-id":"517aa5d5512611cd","local-member-attributes":"{Name:test_etcd_1720595700092998000 ClientURLs:[http://127.0.0.1:57902]}","request-path":"/0/members/517aa5d5512611cd/attributes","cluster-id":"7775bdc730413de5","publish-timeout":"7s"} {"level":"info","ts":"2024-07-10T15:15:00.775793+0800","caller":"embed/serve.go:100","msg":"ready to serve client requests"} {"level":"info","ts":"2024-07-10T15:15:00.779025+0800","caller":"embed/serve.go:209","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"127.0.0.1:57902"} {"level":"info","ts":"2024-07-10T15:15:00.780134+0800","caller":"membership/cluster.go:561","msg":"set initial cluster version","cluster-id":"7775bdc730413de5","local-member-id":"517aa5d5512611cd","cluster-version":"3.4"} {"level":"info","ts":"2024-07-10T15:15:00.780257+0800","caller":"api/capability.go:77","msg":"enabled capabilities for version","cluster-version":"3.4"} {"level":"info","ts":"2024-07-10T15:15:00.780304+0800","caller":"etcdserver/server.go:2671","msg":"cluster version is updated","cluster-version":"3.4"} {"level":"info","ts":"2024-07-10T15:15:00.88642+0800","caller":"raft/raft.go:1523","msg":"517aa5d5512611cd switched to configuration voters=(5871187399838929357 9337585956553235820)"} {"level":"info","ts":"2024-07-10T15:15:00.886892+0800","caller":"membership/cluster.go:395","msg":"added member","cluster-id":"7775bdc730413de5","local-member-id":"517aa5d5512611cd","added-peer-id":"8195c4f470081d6c","added-peer-peer-urls":["http://127.0.0.1:57907"]} {"level":"info","ts":"2024-07-10T15:15:00.887251+0800","caller":"rafthttp/peer.go:128","msg":"starting remote peer","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:00.887437+0800","caller":"rafthttp/pipeline.go:71","msg":"started HTTP pipelining with remote peer","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:00.889254+0800","caller":"rafthttp/stream.go:166","msg":"started stream writer with remote peer","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:00.889863+0800","caller":"rafthttp/stream.go:166","msg":"started stream writer with remote peer","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:00.890329+0800","caller":"rafthttp/peer.go:134","msg":"started remote peer","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:00.890464+0800","caller":"rafthttp/transport.go:327","msg":"added remote peer","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c","remote-peer-urls":["http://127.0.0.1:57907"]} {"level":"info","ts":"2024-07-10T15:15:00.890405+0800","caller":"rafthttp/stream.go:406","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:00.890461+0800","caller":"rafthttp/stream.go:406","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:00.890539+0800","caller":"etcdserver/server.go:2068","msg":"applied a configuration change through raft","local-member-id":"517aa5d5512611cd","raft-conf-change":"ConfChangeAddNode","raft-conf-change-node-id":"8195c4f470081d6c"} {"level":"warn","ts":"2024-07-10T15:15:00.993573+0800","caller":"embed/config.go:622","msg":"Running http and grpc server on single port. This is not recommended for production."} {"level":"info","ts":"2024-07-10T15:15:00.993715+0800","caller":"embed/etcd.go:120","msg":"configuring peer listeners","listen-peer-urls":["http://127.0.0.1:57907"]} {"level":"info","ts":"2024-07-10T15:15:00.993919+0800","caller":"embed/etcd.go:130","msg":"configuring client listeners","listen-client-urls":["http://127.0.0.1:57908"]} {"level":"info","ts":"2024-07-10T15:15:00.994369+0800","caller":"embed/etcd.go:309","msg":"starting an etcd server","etcd-version":"3.4.31","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.21.2","go-os":"darwin","go-arch":"arm64","max-cpu-set":8,"max-cpu-available":8,"member-initialized":false,"name":"test_etcd_1720595700879944000","data-dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/002","wal-dir":"","wal-dir-dedicated":"","member-dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/002/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:57907"],"listen-peer-urls":["http://127.0.0.1:57907"],"advertise-client-urls":["http://127.0.0.1:57908"],"listen-client-urls":["http://127.0.0.1:57908"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"test_etcd_1720595700092998000=http://127.0.0.1:57901,test_etcd_1720595700879944000=http://127.0.0.1:57907","initial-cluster-state":"existing","initial-cluster-token":"etcd-cluster","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":false,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","auto-compaction-mode":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":""} 2024-07-10 15:15:00.994735 W | pkg/fileutil: check file permission: directory "/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/002" exist, but the permission is "drwxr-xr-x". The recommended permission is "-rwx------" to prevent possible unprivileged access to the data. {"level":"info","ts":"2024-07-10T15:15:01.000275+0800","caller":"etcdserver/backend.go:80","msg":"opened backend db","path":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/002/member/snap/db","took":"4.291667ms"} {"level":"info","ts":"2024-07-10T15:15:01.002179+0800","caller":"netutil/netutil.go:112","msg":"resolved URL Host","url":"http://127.0.0.1:57907","host":"127.0.0.1:57907","resolved-addr":"127.0.0.1:57907"} {"level":"info","ts":"2024-07-10T15:15:01.002299+0800","caller":"netutil/netutil.go:112","msg":"resolved URL Host","url":"http://127.0.0.1:57901","host":"127.0.0.1:57901","resolved-addr":"127.0.0.1:57901"} [2024/07/10 15:15:01.020 +08:00] [WARN] [retry_interceptor.go:62] ["retrying of unary invoker failed"] [target=etcd-endpoints://0xc000b46960/127.0.0.1:57902] [attempt=0] [error="rpc error: code = DeadlineExceeded desc = context deadline exceeded"] [2024/07/10 15:15:01.020 +08:00] [WARN] [health_checker.go:194] ["etcd endpoint is unhealthy"] [endpoint=http://127.0.0.1:57902] [took=100.324709ms] [source=default-etcd-client] {"level":"info","ts":"2024-07-10T15:15:01.041055+0800","caller":"etcdserver/raft.go:537","msg":"starting local member","local-member-id":"8195c4f470081d6c","cluster-id":"7775bdc730413de5"} {"level":"info","ts":"2024-07-10T15:15:01.041402+0800","caller":"raft/raft.go:1523","msg":"8195c4f470081d6c switched to configuration voters=()"} {"level":"info","ts":"2024-07-10T15:15:01.041452+0800","caller":"raft/raft.go:706","msg":"8195c4f470081d6c became follower at term 0"} {"level":"info","ts":"2024-07-10T15:15:01.041482+0800","caller":"raft/raft.go:389","msg":"newRaft 8195c4f470081d6c [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} {"level":"warn","ts":"2024-07-10T15:15:01.059998+0800","caller":"auth/store.go:1391","msg":"simple token is not cryptographically signed"} {"level":"info","ts":"2024-07-10T15:15:01.08523+0800","caller":"rafthttp/pipeline.go:71","msg":"started HTTP pipelining with remote peer","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.085289+0800","caller":"rafthttp/transport.go:294","msg":"added new remote peer","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd","remote-peer-urls":["http://127.0.0.1:57901"]} {"level":"info","ts":"2024-07-10T15:15:01.085487+0800","caller":"rafthttp/peer.go:128","msg":"starting remote peer","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.085559+0800","caller":"rafthttp/pipeline.go:71","msg":"started HTTP pipelining with remote peer","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.085677+0800","caller":"rafthttp/stream.go:166","msg":"started stream writer with remote peer","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.085766+0800","caller":"rafthttp/stream.go:166","msg":"started stream writer with remote peer","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.085949+0800","caller":"rafthttp/peer.go:134","msg":"started remote peer","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.085972+0800","caller":"rafthttp/stream.go:406","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.086008+0800","caller":"rafthttp/stream.go:406","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.086374+0800","caller":"rafthttp/transport.go:327","msg":"added remote peer","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd","remote-peer-urls":["http://127.0.0.1:57901"]} {"level":"info","ts":"2024-07-10T15:15:01.086446+0800","caller":"etcdserver/server.go:831","msg":"starting etcd server","local-member-id":"8195c4f470081d6c","local-server-version":"3.4.31","cluster-version":"to_be_decided"} {"level":"info","ts":"2024-07-10T15:15:01.086759+0800","caller":"etcdserver/server.go:719","msg":"starting initial election tick advance","election-ticks":10} {"level":"info","ts":"2024-07-10T15:15:01.086939+0800","caller":"fileutil/purge.go:48","msg":"started to purge file","dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/002/member/snap","suffix":"snap.db","max":5,"interval":"30s"} {"level":"info","ts":"2024-07-10T15:15:01.086979+0800","caller":"fileutil/purge.go:48","msg":"started to purge file","dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/002/member/snap","suffix":"snap","max":5,"interval":"30s"} {"level":"info","ts":"2024-07-10T15:15:01.087127+0800","caller":"fileutil/purge.go:48","msg":"started to purge file","dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/002/member/wal","suffix":"wal","max":5,"interval":"30s"} {"level":"warn","ts":"2024-07-10T15:15:01.08708+0800","caller":"etcdserver/metrics.go:213","msg":"failed to get file descriptor usage","error":"cannot get FDUsage on darwin"} {"level":"info","ts":"2024-07-10T15:15:01.088101+0800","caller":"rafthttp/stream.go:250","msg":"set message encoder","from":"517aa5d5512611cd","to":"517aa5d5512611cd","stream-type":"stream Message"} {"level":"info","ts":"2024-07-10T15:15:01.088109+0800","caller":"rafthttp/stream.go:250","msg":"set message encoder","from":"517aa5d5512611cd","to":"517aa5d5512611cd","stream-type":"stream MsgApp v2"} {"level":"info","ts":"2024-07-10T15:15:01.08814+0800","caller":"rafthttp/peer_status.go:51","msg":"peer became active","peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:01.088188+0800","caller":"rafthttp/peer_status.go:51","msg":"peer became active","peer-id":"517aa5d5512611cd"} {"level":"warn","ts":"2024-07-10T15:15:01.088239+0800","caller":"rafthttp/stream.go:277","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c"} {"level":"warn","ts":"2024-07-10T15:15:01.088198+0800","caller":"rafthttp/stream.go:277","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:01.088279+0800","caller":"rafthttp/stream.go:425","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.08831+0800","caller":"rafthttp/stream.go:425","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.08882+0800","caller":"embed/etcd.go:605","msg":"serving peer traffic","address":"127.0.0.1:57907"} {"level":"info","ts":"2024-07-10T15:15:01.088998+0800","caller":"embed/etcd.go:251","msg":"now serving peer/client/metrics","local-member-id":"8195c4f470081d6c","initial-advertise-peer-urls":["http://127.0.0.1:57907"],"listen-peer-urls":["http://127.0.0.1:57907"],"advertise-client-urls":["http://127.0.0.1:57908"],"listen-client-urls":["http://127.0.0.1:57908"],"listen-metrics-urls":[]} {"level":"info","ts":"2024-07-10T15:15:01.089086+0800","caller":"raft/raft.go:865","msg":"8195c4f470081d6c [term: 0] received a MsgHeartbeat message with higher term from 517aa5d5512611cd [term: 2]"} {"level":"info","ts":"2024-07-10T15:15:01.089128+0800","caller":"raft/raft.go:706","msg":"8195c4f470081d6c became follower at term 2"} {"level":"info","ts":"2024-07-10T15:15:01.089162+0800","caller":"raft/node.go:327","msg":"raft.node: 8195c4f470081d6c elected leader 517aa5d5512611cd at term 2"} {"level":"info","ts":"2024-07-10T15:15:01.091942+0800","caller":"rafthttp/stream.go:250","msg":"set message encoder","from":"8195c4f470081d6c","to":"8195c4f470081d6c","stream-type":"stream Message"} {"level":"warn","ts":"2024-07-10T15:15:01.091976+0800","caller":"rafthttp/stream.go:277","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.092044+0800","caller":"rafthttp/stream.go:425","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:01.092155+0800","caller":"rafthttp/stream.go:425","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:01.092278+0800","caller":"rafthttp/stream.go:250","msg":"set message encoder","from":"8195c4f470081d6c","to":"8195c4f470081d6c","stream-type":"stream MsgApp v2"} {"level":"warn","ts":"2024-07-10T15:15:01.092348+0800","caller":"rafthttp/stream.go:277","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.093145+0800","caller":"traceutil/trace.go:152","msg":"trace[234123624] linearizableReadLoop","detail":"{readStateIndex:5; appliedIndex:5; }","duration":"172.254334ms","start":"2024-07-10T15:15:00.920847+0800","end":"2024-07-10T15:15:01.093102+0800","steps":["trace[234123624] 'read index received' (duration: 172.249709ms)","trace[234123624] 'applied index is now lower than readState.Index' (duration: 3.125µs)"]} {"level":"info","ts":"2024-07-10T15:15:01.102068+0800","caller":"raft/raft.go:1523","msg":"8195c4f470081d6c switched to configuration voters=(5871187399838929357)"} {"level":"info","ts":"2024-07-10T15:15:01.102221+0800","caller":"membership/cluster.go:395","msg":"added member","cluster-id":"7775bdc730413de5","local-member-id":"8195c4f470081d6c","added-peer-id":"517aa5d5512611cd","added-peer-peer-urls":["http://127.0.0.1:57901"]} {"level":"info","ts":"2024-07-10T15:15:01.102407+0800","caller":"membership/cluster.go:561","msg":"set initial cluster version","cluster-id":"7775bdc730413de5","local-member-id":"8195c4f470081d6c","cluster-version":"3.4"} {"level":"info","ts":"2024-07-10T15:15:01.102611+0800","caller":"raft/raft.go:1523","msg":"8195c4f470081d6c switched to configuration voters=(5871187399838929357 9337585956553235820)"} {"level":"info","ts":"2024-07-10T15:15:01.10272+0800","caller":"membership/cluster.go:395","msg":"added member","cluster-id":"7775bdc730413de5","local-member-id":"8195c4f470081d6c","added-peer-id":"8195c4f470081d6c","added-peer-peer-urls":["http://127.0.0.1:57907"]} {"level":"info","ts":"2024-07-10T15:15:01.103152+0800","caller":"etcdserver/server.go:2140","msg":"published local member to cluster through raft","local-member-id":"8195c4f470081d6c","local-member-attributes":"{Name:test_etcd_1720595700879944000 ClientURLs:[http://127.0.0.1:57908]}","request-path":"/0/members/8195c4f470081d6c/attributes","cluster-id":"7775bdc730413de5","publish-timeout":"7s"} {"level":"info","ts":"2024-07-10T15:15:01.103166+0800","caller":"embed/serve.go:100","msg":"ready to serve client requests"} {"level":"info","ts":"2024-07-10T15:15:01.104392+0800","caller":"embed/serve.go:209","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"127.0.0.1:57908"} [2024/07/10 15:15:01.223 +08:00] [INFO] [health_checker.go:137] ["update endpoints"] [num-change=1->2] [last-endpoints="[http://127.0.0.1:57902]"] [endpoints="[http://127.0.0.1:57902,http://127.0.0.1:57908]"] [source=default-etcd-client] {"level":"info","ts":"2024-07-10T15:15:01.316656+0800","caller":"raft/raft.go:1523","msg":"517aa5d5512611cd switched to configuration voters=(5871187399838929357)"} {"level":"info","ts":"2024-07-10T15:15:01.316807+0800","caller":"raft/raft.go:1523","msg":"8195c4f470081d6c switched to configuration voters=(5871187399838929357)"} {"level":"info","ts":"2024-07-10T15:15:01.329993+0800","caller":"membership/cluster.go:425","msg":"removed member","cluster-id":"7775bdc730413de5","local-member-id":"517aa5d5512611cd","removed-remote-peer-id":"8195c4f470081d6c","removed-remote-peer-urls":["http://127.0.0.1:57907"]} {"level":"info","ts":"2024-07-10T15:15:01.330067+0800","caller":"rafthttp/peer.go:333","msg":"stopping remote peer","remote-peer-id":"8195c4f470081d6c"} {"level":"warn","ts":"2024-07-10T15:15:01.330166+0800","caller":"rafthttp/stream.go:291","msg":"closed TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","remote-peer-id":"8195c4f470081d6c"} {"level":"warn","ts":"2024-07-10T15:15:01.330205+0800","caller":"rafthttp/stream.go:301","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","remote-peer-id":"8195c4f470081d6c"} {"level":"warn","ts":"2024-07-10T15:15:01.330281+0800","caller":"rafthttp/stream.go:291","msg":"closed TCP streaming connection with remote peer","stream-writer-type":"stream Message","remote-peer-id":"8195c4f470081d6c"} {"level":"warn","ts":"2024-07-10T15:15:01.33029+0800","caller":"rafthttp/stream.go:436","msg":"lost TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd","error":"EOF"} {"level":"warn","ts":"2024-07-10T15:15:01.330314+0800","caller":"rafthttp/stream.go:301","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"stream Message","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:01.330377+0800","caller":"rafthttp/pipeline.go:86","msg":"stopped HTTP pipelining with remote peer","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c"} {"level":"warn","ts":"2024-07-10T15:15:01.330413+0800","caller":"rafthttp/stream.go:436","msg":"lost TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd","error":"EOF"} {"level":"warn","ts":"2024-07-10T15:15:01.330562+0800","caller":"rafthttp/stream.go:436","msg":"lost TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c","error":"context canceled"} {"level":"warn","ts":"2024-07-10T15:15:01.330606+0800","caller":"rafthttp/peer_status.go:68","msg":"peer became inactive (message send to peer failed)","peer-id":"8195c4f470081d6c","error":"failed to read 8195c4f470081d6c on stream MsgApp v2 (context canceled)"} {"level":"info","ts":"2024-07-10T15:15:01.330654+0800","caller":"rafthttp/stream.go:459","msg":"stopped stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c"} {"level":"warn","ts":"2024-07-10T15:15:01.33183+0800","caller":"rafthttp/stream.go:436","msg":"lost TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c","error":"context canceled"} {"level":"info","ts":"2024-07-10T15:15:01.331871+0800","caller":"rafthttp/stream.go:459","msg":"stopped stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"517aa5d5512611cd","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:01.331913+0800","caller":"rafthttp/peer.go:340","msg":"stopped remote peer","remote-peer-id":"8195c4f470081d6c"} {"level":"info","ts":"2024-07-10T15:15:01.331946+0800","caller":"rafthttp/transport.go:369","msg":"removed remote peer","local-member-id":"517aa5d5512611cd","removed-remote-peer-id":"8195c4f470081d6c"} {"level":"warn","ts":"2024-07-10T15:15:01.33226+0800","caller":"rafthttp/http.go:425","msg":"rejected stream from remote peer because it was removed","local-member-id":"517aa5d5512611cd","remote-peer-id-stream-handler":"517aa5d5512611cd","remote-peer-id-from":"8195c4f470081d6c"} {"level":"warn","ts":"2024-07-10T15:15:01.332449+0800","caller":"rafthttp/http.go:425","msg":"rejected stream from remote peer because it was removed","local-member-id":"517aa5d5512611cd","remote-peer-id-stream-handler":"517aa5d5512611cd","remote-peer-id-from":"8195c4f470081d6c"} {"level":"warn","ts":"2024-07-10T15:15:01.332459+0800","caller":"rafthttp/peer_status.go:68","msg":"peer became inactive (message send to peer failed)","peer-id":"517aa5d5512611cd","error":"failed to dial 517aa5d5512611cd on stream MsgApp v2 (the member has been permanently removed from the cluster)"} {"level":"warn","ts":"2024-07-10T15:15:01.33245+0800","caller":"etcdserver/server.go:1093","msg":"server error","error":"the member has been permanently removed from the cluster"} {"level":"warn","ts":"2024-07-10T15:15:01.332557+0800","caller":"etcdserver/server.go:1094","msg":"data-dir used by this member must be removed"} [2024/07/10 15:15:01.332 +08:00] [WARN] [retry_interceptor.go:62] ["retrying of unary invoker failed"] [target=etcd-endpoints://0xc000b46000/127.0.0.1:57902] [attempt=0] [error="rpc error: code = Unavailable desc = etcdserver: server stopped"] {"level":"info","ts":"2024-07-10T15:15:01.333138+0800","caller":"embed/etcd.go:375","msg":"closing etcd server","name":"test_etcd_1720595700879944000","data-dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/002","advertise-peer-urls":["http://127.0.0.1:57907"],"advertise-client-urls":["http://127.0.0.1:57908"]} {"level":"warn","ts":"2024-07-10T15:15:01.333217+0800","caller":"embed/serve.go:173","msg":"stopping insecure grpc server due to error","error":"accept tcp 127.0.0.1:57908: use of closed network connection"} [2024/07/10 15:15:01.333 +08:00] [WARN] [retry_interceptor.go:62] ["retrying of unary invoker failed"] [target=etcd-endpoints://0xc001c64000/127.0.0.1:57908] [attempt=0] [error="rpc error: code = Unavailable desc = error reading from server: EOF"] 2024/07/10 15:15:01 WARNING: [core] [Channel #17 SubChannel #18] grpc: addrConn.createTransport failed to connect to {Addr: "127.0.0.1:57908", ServerName: "127.0.0.1:57908", }. Err: connection error: desc = "transport: Error while dialing: dial tcp 127.0.0.1:57908: connect: connection refused" 2024/07/10 15:15:01 WARNING: [core] [Channel #3 SubChannel #21] grpc: addrConn.createTransport failed to connect to {Addr: "127.0.0.1:57908", ServerName: "127.0.0.1:57908", }. Err: connection error: desc = "transport: Error while dialing: dial tcp 127.0.0.1:57908: connect: connection refused" {"level":"info","ts":"2024-07-10T15:15:01.33418+0800","caller":"membership/cluster.go:425","msg":"removed member","cluster-id":"7775bdc730413de5","local-member-id":"8195c4f470081d6c","removed-remote-peer-id":"8195c4f470081d6c","removed-remote-peer-urls":["http://127.0.0.1:57907"]} 2024/07/10 15:15:01 WARNING: [core] [Server #15] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing" {"level":"info","ts":"2024-07-10T15:15:01.33431+0800","caller":"rafthttp/pipeline.go:86","msg":"stopped HTTP pipelining with remote peer","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"warn","ts":"2024-07-10T15:15:01.334339+0800","caller":"embed/serve.go:181","msg":"stopped insecure grpc server due to error","error":"accept tcp 127.0.0.1:57908: use of closed network connection"} {"level":"info","ts":"2024-07-10T15:15:01.334362+0800","caller":"rafthttp/peer.go:333","msg":"stopping remote peer","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.334411+0800","caller":"etcdserver/server.go:1557","msg":"skipped leadership transfer; local server is not leader","local-member-id":"8195c4f470081d6c","current-leader-member-id":"517aa5d5512611cd"} {"level":"warn","ts":"2024-07-10T15:15:01.334463+0800","caller":"rafthttp/stream.go:291","msg":"closed TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","remote-peer-id":"517aa5d5512611cd"} {"level":"warn","ts":"2024-07-10T15:15:01.334503+0800","caller":"rafthttp/stream.go:301","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","remote-peer-id":"517aa5d5512611cd"} {"level":"warn","ts":"2024-07-10T15:15:01.334567+0800","caller":"rafthttp/stream.go:291","msg":"closed TCP streaming connection with remote peer","stream-writer-type":"stream Message","remote-peer-id":"517aa5d5512611cd"} {"level":"warn","ts":"2024-07-10T15:15:01.334596+0800","caller":"rafthttp/stream.go:301","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"stream Message","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.334646+0800","caller":"rafthttp/pipeline.go:86","msg":"stopped HTTP pipelining with remote peer","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.334688+0800","caller":"rafthttp/stream.go:459","msg":"stopped stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.334736+0800","caller":"rafthttp/stream.go:459","msg":"stopped stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"8195c4f470081d6c","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.33477+0800","caller":"rafthttp/peer.go:340","msg":"stopped remote peer","remote-peer-id":"517aa5d5512611cd"} {"level":"info","ts":"2024-07-10T15:15:01.358291+0800","caller":"embed/etcd.go:584","msg":"stopping serving peer traffic","address":"127.0.0.1:57907"} {"level":"info","ts":"2024-07-10T15:15:01.358488+0800","caller":"embed/etcd.go:591","msg":"stopped serving peer traffic","address":"127.0.0.1:57907"} {"level":"info","ts":"2024-07-10T15:15:01.358535+0800","caller":"embed/etcd.go:379","msg":"closed etcd server","name":"test_etcd_1720595700879944000","data-dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/002","advertise-peer-urls":["http://127.0.0.1:57907"],"advertise-client-urls":["http://127.0.0.1:57908"]} {"level":"info","ts":"2024-07-10T15:15:01.35859+0800","caller":"embed/etcd.go:375","msg":"closing etcd server","name":"test_etcd_1720595700092998000","data-dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/001","advertise-peer-urls":["http://127.0.0.1:57901"],"advertise-client-urls":["http://127.0.0.1:57902"]} {"level":"warn","ts":"2024-07-10T15:15:01.358672+0800","caller":"embed/serve.go:173","msg":"stopping insecure grpc server due to error","error":"accept tcp 127.0.0.1:57902: use of closed network connection"} {"level":"warn","ts":"2024-07-10T15:15:01.358812+0800","caller":"embed/serve.go:181","msg":"stopped insecure grpc server due to error","error":"accept tcp 127.0.0.1:57902: use of closed network connection"} {"level":"info","ts":"2024-07-10T15:15:01.358883+0800","caller":"etcdserver/server.go:1570","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"517aa5d5512611cd","current-leader-member-id":"517aa5d5512611cd"} 2024/07/10 15:15:01 WARNING: [core] [Channel #3 SubChannel #4] grpc: addrConn.createTransport failed to connect to {Addr: "127.0.0.1:57902", ServerName: "127.0.0.1:57902", }. Err: connection error: desc = "transport: Error while dialing: dial tcp 127.0.0.1:57902: connect: connection refused" 2024/07/10 15:15:01 WARNING: [core] [Channel #9 SubChannel #10] grpc: addrConn.createTransport failed to connect to {Addr: "127.0.0.1:57902", ServerName: "127.0.0.1:57902", }. Err: connection error: desc = "transport: Error while dialing: dial tcp 127.0.0.1:57902: connect: connection refused" {"level":"info","ts":"2024-07-10T15:15:01.382173+0800","caller":"embed/etcd.go:584","msg":"stopping serving peer traffic","address":"127.0.0.1:57901"} {"level":"info","ts":"2024-07-10T15:15:01.382352+0800","caller":"embed/etcd.go:591","msg":"stopped serving peer traffic","address":"127.0.0.1:57901"} {"level":"info","ts":"2024-07-10T15:15:01.382419+0800","caller":"embed/etcd.go:379","msg":"closed etcd server","name":"test_etcd_1720595700092998000","data-dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/001","advertise-peer-urls":["http://127.0.0.1:57901"],"advertise-client-urls":["http://127.0.0.1:57902"]} [2024/07/10 15:15:01.382 +08:00] [WARN] [retry_interceptor.go:62] ["retrying of unary invoker failed"] [target=etcd-endpoints://0xc001c64000/127.0.0.1:57908] [attempt=1] [error="rpc error: code = Canceled desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:57908: connect: connection refused\""] [2024/07/10 15:15:01.382 +08:00] [WARN] [retry_interceptor.go:62] ["retrying of unary invoker failed"] [target=etcd-endpoints://0xc000b46000/127.0.0.1:57902] [attempt=0] [error="rpc error: code = Canceled desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:57902: connect: connection refused\""] [2024/07/10 15:15:01.382 +08:00] [WARN] [health_checker.go:194] ["etcd endpoint is unhealthy"] [endpoint=http://127.0.0.1:57908] [took=63.472375ms] [source=default-etcd-client] [2024/07/10 15:15:01.382 +08:00] [INFO] [health_checker.go:299] ["evicted etcd endpoint found"] [endpoint=http://127.0.0.1:57908] [source=default-etcd-client] {"level":"info","ts":"2024-07-10T15:15:01.382669+0800","caller":"embed/etcd.go:375","msg":"closing etcd server","name":"test_etcd_1720595700092998000","data-dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/001","advertise-peer-urls":["http://127.0.0.1:57901"],"advertise-client-urls":["http://127.0.0.1:57902"]} [2024/07/10 15:15:01.382 +08:00] [INFO] [health_checker.go:137] ["update endpoints"] [num-change=2->1] [last-endpoints="[http://127.0.0.1:57902,http://127.0.0.1:57908]"] [endpoints="[http://127.0.0.1:57902]"] [source=default-etcd-client] {"level":"info","ts":"2024-07-10T15:15:01.38274+0800","caller":"etcdserver/server.go:1570","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"517aa5d5512611cd","current-leader-member-id":"517aa5d5512611cd"} [2024/07/10 15:15:01.382 +08:00] [ERROR] [health_checker.go:455] ["failed to list members"] [source=default-etcd-client] [error="[PD:etcd:ErrEtcdMemberList]context canceled: context canceled"] [errorVerbose="[PD:etcd:ErrEtcdMemberList]context canceled: context canceled\ngithub.com/pingcap/errors.AddStack\n\t/Users/jiangxianjie/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20211224045212-9687c2b0f87c/errors.go:174\ngithub.com/pingcap/errors.(*Error).GenWithStackByCause\n\t/Users/jiangxianjie/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20211224045212-9687c2b0f87c/normalize.go:307\ngithub.com/tikv/pd/pkg/utils/etcdutil.ListEtcdMembers\n\t/Users/jiangxianjie/Code/okjiang/pd/pkg/utils/etcdutil/etcdutil.go:125\ngithub.com/tikv/pd/pkg/utils/etcdutil.(*healthChecker).syncURLs\n\t/Users/jiangxianjie/Code/okjiang/pd/pkg/utils/etcdutil/health_checker.go:453\ngithub.com/tikv/pd/pkg/utils/etcdutil.(*healthChecker).update\n\t/Users/jiangxianjie/Code/okjiang/pd/pkg/utils/etcdutil/health_checker.go:349\ngithub.com/tikv/pd/pkg/utils/etcdutil.(*healthChecker).syncer\n\t/Users/jiangxianjie/Code/okjiang/pd/pkg/utils/etcdutil/health_checker.go:100\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_arm64.s:1197"] [stack="github.com/tikv/pd/pkg/utils/etcdutil.(*healthChecker).syncURLs\n\t/Users/jiangxianjie/Code/okjiang/pd/pkg/utils/etcdutil/health_checker.go:455\ngithub.com/tikv/pd/pkg/utils/etcdutil.(*healthChecker).update\n\t/Users/jiangxianjie/Code/okjiang/pd/pkg/utils/etcdutil/health_checker.go:349\ngithub.com/tikv/pd/pkg/utils/etcdutil.(*healthChecker).syncer\n\t/Users/jiangxianjie/Code/okjiang/pd/pkg/utils/etcdutil/health_checker.go:100"] [2024/07/10 15:15:01.382 +08:00] [INFO] [health_checker.go:113] ["etcd client is closed, exit the health inspector goroutine"] [source=default-etcd-client] {"level":"info","ts":"2024-07-10T15:15:01.382798+0800","caller":"embed/etcd.go:584","msg":"stopping serving peer traffic","address":"127.0.0.1:57901"} [2024/07/10 15:15:01.382 +08:00] [WARN] [health_checker.go:351] ["no available etcd endpoint returned by etcd cluster"] [source=default-etcd-client] [2024/07/10 15:15:01.382 +08:00] [INFO] [health_checker.go:96] ["etcd client is closed, exit the endpoint syncer goroutine"] [source=default-etcd-client] {"level":"info","ts":"2024-07-10T15:15:01.382858+0800","caller":"embed/etcd.go:591","msg":"stopped serving peer traffic","address":"127.0.0.1:57901"} {"level":"info","ts":"2024-07-10T15:15:01.382888+0800","caller":"embed/etcd.go:379","msg":"closed etcd server","name":"test_etcd_1720595700092998000","data-dir":"/var/folders/3f/xpw0q2k93p1cdcrrv_w_cglm0000gn/T/TestEtcdClientSync1085617163/001","advertise-peer-urls":["http://127.0.0.1:57901"],"advertise-client-urls":["http://127.0.0.1:57902"]} --- FAIL: TestEtcdClientSync (1.29s) /Users/jiangxianjie/Code/okjiang/pd/pkg/utils/etcdutil/etcdutil_test.go:199: Error Trace: /Users/jiangxianjie/Code/okjiang/pd/pkg/utils/etcdutil/etcdutil_test.go:199 Error: Received unexpected error: [PD:etcd:ErrEtcdMemberRemove]etcdserver: server stopped: etcdserver: server stopped github.com/pingcap/errors.AddStack /Users/jiangxianjie/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20211224045212-9687c2b0f87c/errors.go:174 github.com/pingcap/errors.(*Error).GenWithStackByCause /Users/jiangxianjie/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20211224045212-9687c2b0f87c/normalize.go:307 github.com/tikv/pd/pkg/utils/etcdutil.RemoveEtcdMember /Users/jiangxianjie/Code/okjiang/pd/pkg/utils/etcdutil/etcdutil.go:136 github.com/tikv/pd/pkg/utils/etcdutil.TestEtcdClientSync /Users/jiangxianjie/Code/okjiang/pd/pkg/utils/etcdutil/etcdutil_test.go:198 testing.tRunner /usr/local/go/src/testing/testing.go:1595 runtime.goexit /usr/local/go/src/runtime/asm_arm64.s:1197 Test: TestEtcdClientSync FAIL FAIL github.com/tikv/pd/pkg/utils/etcdutil 4.488s FAIL

Also, I did not replicate this issue on a Linux machine.