Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

integration/clientv3/naming TestEtcdGrpcResolverRoundRobin #15794

Closed
fuweid opened this issue Apr 28, 2023 · 3 comments · Fixed by #15795 or #15868
Closed

integration/clientv3/naming TestEtcdGrpcResolverRoundRobin #15794

fuweid opened this issue Apr 28, 2023 · 3 comments · Fixed by #15795 or #15868
Assignees
@jmhbnz
Labels
area/testing type/flake

Comments

@fuweid
Copy link
Member

fuweid commented Apr 28, 2023 •
edited
Loading

Which github workflows are flaking?

test (linux-amd64-integration-2-cpu)

Which tests are flaking?

integration/clientv3/naming TestEtcdGrpcResolverRoundRobin

Github Action link

https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#logs

#15792 (comment)

Reason for failure (if possible)

No response

Anything else we need to know?

Log 
=== FAIL: integration/clientv3/naming TestEtcdGrpcResolverRoundRobin (0.28s)
    logger.go:130: 2023-04-28T13:32:12.807Z	INFO	grpc	[[core] [Server #45] Server created]
    logger.go:130: 2023-04-28T13:32:12.807Z	INFO	grpc	[[core] [Server #45 ListenSocket #46] ListenSocket created]
    logger.go:130: 2023-04-28T13:32:12.807Z	INFO	grpc	[[core] [Server #47] Server created]
    cluster.go:538: Creating listener with addr: 127.0.0.1:2102006507
    cluster.go:538: Creating listener with addr: 127.0.0.1:2102106507
    logger.go:130: 2023-04-28T13:32:12.807Z	INFO	grpc	[[core] [Server #47 ListenSocket #48] ListenSocket created]
    logger.go:130: 2023-04-28T13:32:12.807Z	INFO	m0	LISTEN GRPC	{"member": "m0", "grpcAddr": "localhost:m0", "m.Name": "m0", "workdir": "/tmp/TestEtcdGrpcResolverRoundRobin1056756463/001"}
    logger.go:130: 2023-04-28T13:32:12.807Z	INFO	m0	LISTEN GRPC SUCCESS	{"member": "m0", "grpcAddr": "unix://localhost:m0", "m.Name": "m0", "workdir": "/tmp/TestEtcdGrpcResolverRoundRobin1056756463/001", "port": "m0"}
    cluster.go:538: Creating listener with addr: 127.0.0.1:2102306507
    cluster.go:538: Creating listener with addr: 127.0.0.1:2102406507
    logger.go:130: 2023-04-28T13:32:12.808Z	INFO	m1	LISTEN GRPC	{"member": "m1", "grpcAddr": "localhost:m1", "m.Name": "m1", "workdir": "/tmp/TestEtcdGrpcResolverRoundRobin1056756463/001"}
    logger.go:130: 2023-04-28T13:32:12.808Z	INFO	m1	LISTEN GRPC SUCCESS	{"member": "m1", "grpcAddr": "unix://localhost:m1", "m.Name": "m1", "workdir": "/tmp/TestEtcdGrpcResolverRoundRobin1056756463/001", "port": "m1"}
    cluster.go:538: Creating listener with addr: 127.0.0.1:2102606507
    cluster.go:538: Creating listener with addr: 127.0.0.1:2102706507
    logger.go:130: 2023-04-28T13:32:12.808Z	INFO	m2	LISTEN GRPC	{"member": "m2", "grpcAddr": "localhost:m2", "m.Name": "m2", "workdir": "/tmp/TestEtcdGrpcResolverRoundRobin1056756463/001"}
    logger.go:130: 2023-04-28T13:32:12.808Z	INFO	m2	LISTEN GRPC SUCCESS	{"member": "m2", "grpcAddr": "unix://localhost:m2", "m.Name": "m2", "workdir": "/tmp/TestEtcdGrpcResolverRoundRobin1056756463/001", "port": "m2"}
    cluster.go:219: Launching new cluster...
    logger.go:130: 2023-04-28T13:32:12.808Z	INFO	m2	launching a member	{"member": "m2", "name": "m2", "advertise-peer-urls": ["unix://127.0.0.1:2102606507"], "listen-client-urls": ["unix://127.0.0.1:2102706507"], "grpc-url": "unix://localhost:m2"}
    logger.go:130: 2023-04-28T13:32:12.808Z	INFO	m1	launching a member	{"member": "m1", "name": "m1", "advertise-peer-urls": ["unix://127.0.0.1:2102306507"], "listen-client-urls": ["unix://127.0.0.1:2102406507"], "grpc-url": "unix://localhost:m1"}
    logger.go:130: 2023-04-28T13:32:12.809Z	INFO	m0	launching a member	{"member": "m0", "name": "m0", "advertise-peer-urls": ["unix://127.0.0.1:2102006507"], "listen-client-urls": ["unix://127.0.0.1:2102106507"], "grpc-url": "unix://localhost:m0"}
    logger.go:130: 2023-04-28T13:32:12.812Z	INFO	m1	opened backend db	{"member": "m1", "path": "/tmp/TestEtcdGrpcResolverRoundRobin1056756463/003/etcd3358637776/member/snap/db", "took": "2.709389ms"}
    logger.go:130: 2023-04-28T13:32:12.813Z	INFO	m2	opened backend db	{"member": "m2", "path": "/tmp/TestEtcdGrpcResolverRoundRobin1056756463/004/etcd4014812382/member/snap/db", "took": "3.013288ms"}
    logger.go:130: 2023-04-28T13:32:12.814Z	INFO	m0	opened backend db	{"member": "m0", "path": "/tmp/TestEtcdGrpcResolverRoundRobin1056756463/002/etcd3886094302/member/snap/db", "took": "2.928189ms"}
    logger.go:130: 2023-04-28T13:32:12.838Z	INFO	m2	starting local member	{"member": "m2", "local-member-id": "adcb8499dd134171", "cluster-id": "6399ddc30b6c70be"}
    logger.go:130: 2023-04-28T13:32:12.838Z	INFO	m2.raft	adcb8499dd134171 switched to configuration voters=()	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.838Z	INFO	m2.raft	adcb8499dd134171 became follower at term 0	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.838Z	INFO	m2.raft	newRaft adcb8499dd134171 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.838Z	INFO	m2.raft	adcb8499dd134171 became follower at term 1	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.838Z	INFO	m2.raft	adcb8499dd134171 switched to configuration voters=(12523248985207685489)	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.839Z	INFO	m2.raft	adcb8499dd134171 switched to configuration voters=(12523248985207685489 13320913545053971953)	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.839Z	INFO	m2.raft	adcb8499dd134171 switched to configuration voters=(12523248985207685489 13320913545053971953 181052[169](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:170)73289555528)	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.840Z	INFO	m1	starting local member	{"member": "m1", "local-member-id": "b8dd644ac0a1a5f1", "cluster-id": "6399ddc30b6c70be"}
    logger.go:130: 2023-04-28T13:32:12.840Z	INFO	m1.raft	b8dd644ac0a1a5f1 switched to configuration voters=()	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.840Z	INFO	m1.raft	b8dd644ac0a1a5f1 became follower at term 0	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.841Z	INFO	m1.raft	newRaft b8dd644ac0a1a5f1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.841Z	INFO	m1.raft	b8dd644ac0a1a5f1 became follower at term 1	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.841Z	INFO	m1.raft	b8dd644ac0a1a5f1 switched to configuration voters=(12523248985207685489)	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.841Z	INFO	m1.raft	b8dd644ac0a1a5f1 switched to configuration voters=(12523248985207685489 13320913545053971953)	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.841Z	INFO	m1.raft	b8dd644ac0a1a5f1 switched to configuration voters=(12523248985207685489 13320913545053971953 18105216973289555528)	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.843Z	WARN	m2	simple token is not cryptographically signed	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.845Z	WARN	m1	simple token is not cryptographically signed	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.845Z	INFO	m2	kvstore restored	{"member": "m2", "current-rev": 1}
    logger.go:130: 2023-04-28T13:32:12.846Z	INFO	m0	starting local member	{"member": "m0", "local-member-id": "fb42a6e9624c0648", "cluster-id": "6399ddc30b6c70be"}
    logger.go:130: 2023-04-28T13:32:12.846Z	INFO	m0.raft	fb42a6e9624c0648 switched to configuration voters=()	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.846Z	INFO	m0.raft	fb42a6e9624c0648 became follower at term 0	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.847Z	INFO	m0.raft	newRaft fb42a6e9624c0648 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.847Z	INFO	m0.raft	fb42a6e9624c0648 became follower at term 1	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.847Z	INFO	m1	kvstore restored	{"member": "m1", "current-rev": 1}
    logger.go:130: 2023-04-28T13:32:12.847Z	INFO	m0.raft	fb42a6e9624c0648 switched to configuration voters=(12523248985207685489)	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.848Z	INFO	m0.raft	fb42a6e9624c0648 switched to configuration voters=(12523248985207685489 13320913545053971953)	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.848Z	INFO	m2	starting remote peer	{"member": "m2", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.848Z	INFO	m2	started HTTP pipelining with remote peer	{"member": "m2", "local-member-id": "adcb8499dd134[171](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:172)", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.849Z	INFO	m2	started remote peer	{"member": "m2", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.850Z	INFO	m2	added remote peer	{"member": "m2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "b8dd644ac0a1a5f1", "remote-peer-urls": ["unix://127.0.0.1:2102306507"]}
    logger.go:130: 2023-04-28T13:32:12.850Z	INFO	m2	starting remote peer	{"member": "m2", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.850Z	INFO	m2	started HTTP pipelining with remote peer	{"member": "m2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.853Z	INFO	m0.raft	fb42a6e9624c0648 switched to configuration voters=(12523248985207685489 13320913545053971953 [181](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:182)05216973289555528)	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.854Z	INFO	m2	started stream writer with remote peer	{"member": "m2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.854Z	INFO	m2	started stream writer with remote peer	{"member": "m2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.854Z	INFO	m2	started stream reader with remote peer	{"member": "m2", "stream-reader-type": "stream MsgApp v2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.855Z	INFO	m1	starting remote peer	{"member": "m1", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.855Z	INFO	m1	started HTTP pipelining with remote peer	{"member": "m1", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.858Z	INFO	m1	started remote peer	{"member": "m1", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.858Z	INFO	m1	added remote peer	{"member": "m1", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "adcb8499dd134171", "remote-peer-urls": ["unix://127.0.0.1:2102606507"]}
    logger.go:130: 2023-04-28T13:32:12.858Z	INFO	m1	starting remote peer	{"member": "m1", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.858Z	INFO	m1	started HTTP pipelining with remote peer	{"member": "m1", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.861Z	INFO	m1	started remote peer	{"member": "m1", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.861Z	INFO	m1	added remote peer	{"member": "m1", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "fb42a6e9624c0648", "remote-peer-urls": ["unix://127.0.0.1:2102006507"]}
    logger.go:130: 2023-04-28T13:32:12.861Z	INFO	m1	starting etcd server	{"member": "m1", "local-member-id": "b8dd644ac0a1a5f1", "local-server-version": "3.6.0-alpha.0", "cluster-version": "to_be_decided"}
    logger.go:130: 2023-04-28T13:32:12.861Z	INFO	grpc	[[core] [Server #49] Server created]
    logger.go:130: 2023-04-28T13:32:12.863Z	INFO	m1	started stream writer with remote peer	{"member": "m1", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.864Z	INFO	m1	started stream writer with remote peer	{"member": "m1", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.864Z	INFO	m1	started stream reader with remote peer	{"member": "m1", "stream-reader-type": "stream MsgApp v2", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.864Z	INFO	m1	started stream reader with remote peer	{"member": "m1", "stream-reader-type": "stream Message", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.864Z	INFO	m1	started stream writer with remote peer	{"member": "m1", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.865Z	INFO	m2	started stream writer with remote peer	{"member": "m2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.865Z	INFO	m2	started stream reader with remote peer	{"member": "m2", "stream-reader-type": "stream Message", "local-member-id": "adcb8499dd134171", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.866Z	INFO	m2	started stream writer with remote peer	{"member": "m2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.867Z	INFO	m1	started stream writer with remote peer	{"member": "m1", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.867Z	INFO	m1	started stream reader with remote peer	{"member": "m1", "stream-reader-type": "stream MsgApp v2", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.867Z	INFO	m1	started stream reader with remote peer	{"member": "m1", "stream-reader-type": "stream Message", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.867Z	INFO	m1	starting initial election tick advance	{"member": "m1", "election-ticks": 10}
    logger.go:130: 2023-04-28T13:32:12.868Z	INFO	grpc	[[core] [Server #49 ListenSocket #50] ListenSocket created]
    logger.go:130: 2023-04-28T13:32:12.869Z	INFO	grpc	[[core] [Channel #51] Channel created]
    logger.go:130: 2023-04-28T13:32:12.869Z	INFO	grpc	[[core] [Channel #51] original dial target is: "etcd-endpoints://0xc000b6a3c0/localhost:m1"]
    logger.go:130: 2023-04-28T13:32:12.869Z	INFO	grpc	[[core] [Channel #51] parsed dial target is: {Scheme:etcd-endpoints Authority:0xc000b6a3c0 Endpoint:localhost:m1 URL:{Scheme:etcd-endpoints Opaque: User: Host:0xc000b6a3c0 Path:/localhost:m1 RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}]
    logger.go:130: 2023-04-28T13:32:12.869Z	INFO	grpc	[[core] [Channel #51] Channel authority set to "localhost:m1"]
    logger.go:130: 2023-04-28T13:32:12.870Z	INFO	grpc	[[core] [Channel #51] Resolver state updated: {
          "Addresses": [
            {
              "Addr": "unix:localhost:m1",
              "ServerName": "localhost",
              "Attributes": null,
              "BalancerAttributes": null,
              "Type": 0,
              "Metadata": null
            }
          ],
          "ServiceConfig": {
            "Config": {
              "Config": null,
              "LB": "round_robin",
              "Methods": {}
            },
            "Err": null
          },
          "Attributes": null
        } (service config updated; resolver returned new addresses)]
    logger.go:130: 2023-04-28T13:32:12.870Z	INFO	grpc	[[core] [Channel #51] Channel switches to new LB policy "round_robin"]
    logger.go:130: 2023-04-28T13:32:12.870Z	INFO	grpc	[[balancer] base.baseBalancer: got new ClientConn state:  {{[{
          "Addr": "unix:localhost:m1",
          "ServerName": "localhost",
          "Attributes": null,
          "BalancerAttributes": null,
          "Type": 0,
          "Metadata": null
        }] 0xc0012c3360 <nil>} <nil>}]
    logger.go:130: 2023-04-28T13:32:12.870Z	INFO	grpc	[[core] [Channel #51 SubChannel #52] Subchannel created]
    logger.go:130: 2023-04-28T13:32:12.870Z	INFO	grpc	[[roundrobin] roundrobinPicker: Build called with info: {map[]}]
    logger.go:130: 2023-04-28T13:32:12.870Z	INFO	grpc	[[core] [Channel #51] Channel Connectivity change to CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.871Z	WARN	m0	simple token is not cryptographically signed	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.871Z	INFO	m1	set message encoder	{"member": "m1", "from": "b8dd644ac0a1a5f1", "to": "adcb8499dd134171", "stream-type": "stream Message"}
    logger.go:130: 2023-04-28T13:32:12.871Z	INFO	m1	peer became active	{"member": "m1", "peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.871Z	INFO	m1	established TCP streaming connection with remote peer	{"member": "m1", "stream-writer-type": "stream Message", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.872Z	INFO	grpc	[[core] [Channel #51 SubChannel #52] Subchannel Connectivity change to CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.872Z	INFO	grpc	[[core] [Channel #51 SubChannel #52] Subchannel picks a new address "unix:localhost:m1" to connect]
    logger.go:130: 2023-04-28T13:32:12.874Z	INFO	m2	started remote peer	{"member": "m2", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.874Z	INFO	m2	added remote peer	{"member": "m2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "fb42a6e9624c0648", "remote-peer-urls": ["unix://127.0.0.1:2102006507"]}
    logger.go:130: 2023-04-28T13:32:12.874Z	INFO	m2	starting etcd server	{"member": "m2", "local-member-id": "adcb8499dd134171", "local-server-version": "3.6.0-alpha.0", "cluster-version": "to_be_decided"}
    logger.go:130: 2023-04-28T13:32:12.875Z	INFO	grpc	[[core] [Server #53] Server created]
    logger.go:130: 2023-04-28T13:32:12.876Z	INFO	grpc	[[core] [Server #53 ListenSocket #54] ListenSocket created]
    logger.go:130: 2023-04-28T13:32:12.877Z	INFO	m2	started stream reader with remote peer	{"member": "m2", "stream-reader-type": "stream MsgApp v2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.877Z	INFO	m2	started stream reader with remote peer	{"member": "m2", "stream-reader-type": "stream Message", "local-member-id": "adcb8499dd134171", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.878Z	INFO	grpc	[[balancer] base.baseBalancer: handle SubConn state change: 0xc0020f9230, CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.879Z	INFO	m1.raft	b8dd644ac0a1a5f1 switched to configuration voters=(12523248985207685489 1332091354505397[195](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:196)3 18105216973289555528)	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.879Z	INFO	m1	added member	{"member": "m1", "cluster-id": "6399ddc30b6c70be", "local-member-id": "b8dd644ac0a1a5f1", "added-peer-id": "adcb8499dd134171", "added-peer-peer-urls": ["unix://127.0.0.1:2102606507"], "added-peer-is-learner": false}
    logger.go:130: 2023-04-28T13:32:12.881Z	INFO	m1	set message encoder	{"member": "m1", "from": "b8dd644ac0a1a5f1", "to": "adcb8499dd134171", "stream-type": "stream MsgApp v2"}
    logger.go:130: 2023-04-28T13:32:12.881Z	INFO	m1	established TCP streaming connection with remote peer	{"member": "m1", "stream-writer-type": "stream MsgApp v2", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.882Z	INFO	m1.raft	b8dd644ac0a1a5f1 switched to configuration voters=(12523248985207685489 13320913545053971953 18105216973289555528)	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.882Z	INFO	m1	added member	{"member": "m1", "cluster-id": "6399ddc30b6c70be", "local-member-id": "b8dd644ac0a1a5f1", "added-peer-id": "b8dd644ac0a1a5f1", "added-peer-peer-urls": ["unix://127.0.0.1:2102306507"], "added-peer-is-learner": false}
    logger.go:130: 2023-04-28T13:32:12.883Z	INFO	m1.raft	b8dd644ac0a1a5f1 switched to configuration voters=(12523248985207685489 13320913545053971953 18105216973289555528)	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.883Z	INFO	m1	added member	{"member": "m1", "cluster-id": "6399ddc30b6c70be", "local-member-id": "b8dd644ac0a1a5f1", "added-peer-id": "fb42a6e9624c0648", "added-peer-peer-urls": ["unix://127.0.0.1:210[200](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:201)6507"], "added-peer-is-learner": false}
    logger.go:130: [202](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:203)3-04-28T13:32:12.884Z	INFO	m2	peer became active	{"member": "m2", "peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.884Z	INFO	m2	established TCP streaming connection with remote peer	{"member": "m2", "stream-reader-type": "stream MsgApp v2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.887Z	INFO	m2	starting initial election tick advance	{"member": "m2", "election-ticks": 10}
    logger.go:130: 2023-04-28T13:32:12.888Z	INFO	m2	established TCP streaming connection with remote peer	{"member": "m2", "stream-reader-type": "stream Message", "local-member-id": "adcb8499dd134171", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.888Z	INFO	m0	kvstore restored	{"member": "m0", "current-rev": 1}
    logger.go:130: 2023-04-28T13:32:12.889Z	INFO	m2.raft	adcb8499dd134171 switched to configuration voters=(12523248985[207](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:208)685489 133[209](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:210)13545053971953 18105216973289555528)	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.890Z	INFO	m2	added member	{"member": "m2", "cluster-id": "6399ddc30b6c70be", "local-member-id": "adcb8499dd134171", "added-peer-id": "adcb8499dd134171", "added-peer-peer-urls": ["unix://127.0.0.1:[210](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:211)2606507"], "added-peer-is-learner": false}
    logger.go:130: 2023-04-28T13:32:12.890Z	INFO	m2.raft	adcb8499dd134171 switched to configuration voters=(12523248985207685489 13320913545053971953 18105[216](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:217)973289555528)	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.890Z	INFO	m2	added member	{"member": "m2", "cluster-id": "6399ddc30b6c70be", "local-member-id": "adcb8499dd134171", "added-peer-id": "b8dd644ac0a1a5f1", "added-peer-peer-urls": ["unix://127.0.0.1:210[230](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:231)6507"], "added-peer-is-learner": false}
    logger.go:130: 2023-04-28T13:32:12.890Z	INFO	m2.raft	adcb8499dd134171 switched to configuration voters=(125[232](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:233)48985207685489 13320913545053971953 18105216973289555528)	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.891Z	INFO	m2	added member	{"member": "m2", "cluster-id": "6399ddc30b6c70be", "local-member-id": "adcb8499dd134171", "added-peer-id": "fb42a6e9624c0648", "added-peer-peer-urls": ["unix://127.0.0.1:2102006507"], "added-peer-is-learner": false}
    logger.go:130: 2023-04-28T13:32:12.891Z	INFO	grpc	[[core] [Channel #51 SubChannel #52] Subchannel Connectivity change to READY]
    logger.go:130: 2023-04-28T13:32:12.891Z	INFO	grpc	[[balancer] base.baseBalancer: handle SubConn state change: 0xc0020f9230, READY]
    logger.go:130: 2023-04-28T13:32:12.891Z	INFO	grpc	[[roundrobin] roundrobinPicker: Build called with info: {map[0xc0020f9230:{{
          "Addr": "unix:localhost:m1",
          "ServerName": "localhost",
          "Attributes": null,
          "BalancerAttributes": null,
          "Type": 0,
          "Metadata": null
        }}]}]
    logger.go:130: 2023-04-28T13:32:12.891Z	INFO	grpc	[[core] [Channel #51] Channel Connectivity change to READY]
    logger.go:130: 2023-04-28T13:32:12.891Z	INFO	m1	launched a member	{"member": "m1", "name": "m1", "advertise-peer-urls": ["unix://127.0.0.1:2102306507"], "listen-client-urls": ["unix://127.0.0.1:2102406507"], "grpc-url": "unix://localhost:m1"}
    logger.go:130: 2023-04-28T13:32:12.893Z	INFO	grpc	[[core] [Channel #57] Channel created]
    logger.go:130: 2023-04-28T13:32:12.893Z	INFO	grpc	[[core] [Channel #57] original dial target is: "etcd-endpoints://0xc000b6a780/localhost:m2"]
    logger.go:130: 2023-04-28T13:32:12.893Z	INFO	grpc	[[core] [Channel #57] parsed dial target is: {Scheme:etcd-endpoints Authority:0xc000b6a780 Endpoint:localhost:m2 URL:{Scheme:etcd-endpoints Opaque: User: Host:0xc000b6a780 Path:/localhost:m2 RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}]
    logger.go:130: 2023-04-28T13:32:12.893Z	INFO	grpc	[[core] [Channel #57] Channel authority set to "localhost:m2"]
    logger.go:130: 2023-04-28T13:32:12.893Z	INFO	grpc	[[core] [Channel #57] Resolver state updated: {
          "Addresses": [
            {
              "Addr": "unix:localhost:m2",
              "ServerName": "localhost",
              "Attributes": null,
              "BalancerAttributes": null,
              "Type": 0,
              "Metadata": null
            }
          ],
          "ServiceConfig": {
            "Config": {
              "Config": null,
              "LB": "round_robin",
              "Methods": {}
            },
            "Err": null
          },
          "Attributes": null
        } (service config updated; resolver returned new addresses)]
    logger.go:130: 2023-04-28T13:32:12.893Z	INFO	grpc	[[core] [Channel #57] Channel switches to new LB policy "round_robin"]
    logger.go:130: 2023-04-28T13:32:12.893Z	INFO	grpc	[[balancer] base.baseBalancer: got new ClientConn state:  {{[{
          "Addr": "unix:localhost:m2",
          "ServerName": "localhost",
          "Attributes": null,
          "BalancerAttributes": null,
          "Type": 0,
          "Metadata": null
        }] 0xc00259b0e0 <nil>} <nil>}]
    logger.go:130: 2023-04-28T13:32:12.894Z	INFO	grpc	[[core] [Channel #57 SubChannel #58] Subchannel created]
    logger.go:130: 2023-04-28T13:32:12.894Z	INFO	grpc	[[roundrobin] roundrobinPicker: Build called with info: {map[]}]
    logger.go:130: 2023-04-28T13:32:12.894Z	INFO	grpc	[[core] [Channel #57] Channel Connectivity change to CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.894Z	INFO	m2	set message encoder	{"member": "m2", "from": "adcb8499dd134171", "to": "b8dd644ac0a1a5f1", "stream-type": "stream Message"}
    logger.go:130: 2023-04-28T13:32:12.894Z	INFO	m2	established TCP streaming connection with remote peer	{"member": "m2", "stream-writer-type": "stream Message", "local-member-id": "adcb8499dd134171", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.894Z	INFO	m2	set message encoder	{"member": "m2", "from": "adcb8499dd134171", "to": "b8dd644ac0a1a5f1", "stream-type": "stream MsgApp v2"}
    logger.go:130: 2023-04-28T13:32:12.895Z	INFO	m2	established TCP streaming connection with remote peer	{"member": "m2", "stream-writer-type": "stream MsgApp v2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.895Z	INFO	grpc	[[core] [Channel #57 SubChannel #58] Subchannel Connectivity change to CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.895Z	INFO	grpc	[[core] [Channel #57 SubChannel #58] Subchannel picks a new address "unix:localhost:m2" to connect]
    logger.go:130: 2023-04-28T13:32:12.895Z	INFO	grpc	[[balancer] base.baseBalancer: handle SubConn state change: 0xc0020f92f0, CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.896Z	INFO	m1	established TCP streaming connection with remote peer	{"member": "m1", "stream-reader-type": "stream Message", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.896Z	INFO	m1	established TCP streaming connection with remote peer	{"member": "m1", "stream-reader-type": "stream MsgApp v2", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.897Z	INFO	grpc	[[core] [Channel #57 SubChannel #58] Subchannel Connectivity change to READY]
    logger.go:130: 2023-04-28T13:32:12.898Z	INFO	grpc	[[balancer] base.baseBalancer: handle SubConn state change: 0xc0020f92f0, READY]
    logger.go:130: 2023-04-28T13:32:12.898Z	INFO	grpc	[[roundrobin] roundrobinPicker: Build called with info: {map[0xc0020f92f0:{{
          "Addr": "unix:localhost:m2",
          "ServerName": "localhost",
          "Attributes": null,
          "BalancerAttributes": null,
          "Type": 0,
          "Metadata": null
        }}]}]
    logger.go:130: 2023-04-28T13:32:12.898Z	INFO	grpc	[[core] [Channel #57] Channel Connectivity change to READY]
    logger.go:130: 2023-04-28T13:32:12.898Z	INFO	m2	launched a member	{"member": "m2", "name": "m2", "advertise-peer-urls": ["unix://127.0.0.1:2102606507"], "listen-client-urls": ["unix://127.0.0.1:2102706507"], "grpc-url": "unix://localhost:m2"}
    logger.go:130: 2023-04-28T13:32:12.899Z	INFO	m0	starting remote peer	{"member": "m0", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.899Z	INFO	m0	started HTTP pipelining with remote peer	{"member": "m0", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.901Z	INFO	m0	started stream writer with remote peer	{"member": "m0", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.901Z	INFO	m0	started stream writer with remote peer	{"member": "m0", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.901Z	INFO	m0	started stream reader with remote peer	{"member": "m0", "stream-reader-type": "stream MsgApp v2", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.901Z	INFO	m0	started stream reader with remote peer	{"member": "m0", "stream-reader-type": "stream Message", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.900Z	INFO	m0	started remote peer	{"member": "m0", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.901Z	INFO	m0	added remote peer	{"member": "m0", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "adcb8499dd134171", "remote-peer-urls": ["unix://127.0.0.1:2102606507"]}
    logger.go:130: 2023-04-28T13:32:12.902Z	INFO	m0	starting remote peer	{"member": "m0", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.902Z	INFO	m0	started HTTP pipelining with remote peer	{"member": "m0", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.903Z	INFO	m0	started remote peer	{"member": "m0", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.903Z	INFO	m0	added remote peer	{"member": "m0", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "b8dd644ac0a1a5f1", "remote-peer-urls": ["unix://127.0.0.1:2102306507"]}
    logger.go:130: 2023-04-28T13:32:12.903Z	INFO	m0	starting etcd server	{"member": "m0", "local-member-id": "fb42a6e9624c0648", "local-server-version": "3.6.0-alpha.0", "cluster-version": "to_be_decided"}
    logger.go:130: 2023-04-28T13:32:12.904Z	INFO	grpc	[[core] [Server #61] Server created]
    logger.go:130: 2023-04-28T13:32:12.906Z	INFO	m0	started stream writer with remote peer	{"member": "m0", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.906Z	INFO	m0	started stream writer with remote peer	{"member": "m0", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.906Z	INFO	m0	started stream reader with remote peer	{"member": "m0", "stream-reader-type": "stream Message", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.906Z	INFO	m0	started stream reader with remote peer	{"member": "m0", "stream-reader-type": "stream MsgApp v2", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.906Z	INFO	m0	starting initial election tick advance	{"member": "m0", "election-ticks": 10}
    logger.go:130: 2023-04-28T13:32:12.907Z	INFO	grpc	[[core] [Server #61 ListenSocket #62] ListenSocket created]
    logger.go:130: 2023-04-28T13:32:12.907Z	INFO	grpc	[[core] [Channel #63] Channel created]
    logger.go:130: 2023-04-28T13:32:12.907Z	INFO	grpc	[[core] [Channel #63] original dial target is: "etcd-endpoints://0xc0005105a0/localhost:m0"]
    logger.go:130: 2023-04-28T13:32:12.907Z	INFO	grpc	[[core] [Channel #63] parsed dial target is: {Scheme:etcd-endpoints Authority:0xc0005105a0 Endpoint:localhost:m0 URL:{Scheme:etcd-endpoints Opaque: User: Host:0xc0005105a0 Path:/localhost:m0 RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}]
    logger.go:130: 2023-04-28T13:32:12.908Z	INFO	grpc	[[core] [Channel #63] Channel authority set to "localhost:m0"]
    logger.go:130: 2023-04-28T13:32:12.908Z	INFO	grpc	[[core] [Channel #63] Resolver state updated: {
          "Addresses": [
            {
              "Addr": "unix:localhost:m0",
              "ServerName": "localhost",
              "Attributes": null,
              "BalancerAttributes": null,
              "Type": 0,
              "Metadata": null
            }
          ],
          "ServiceConfig": {
            "Config": {
              "Config": null,
              "LB": "round_robin",
              "Methods": {}
            },
            "Err": null
          },
          "Attributes": null
        } (service config updated; resolver returned new addresses)]
    logger.go:130: 2023-04-28T13:32:12.908Z	INFO	m0.raft	fb42a6e9624c0648 switched to configuration voters=(12523248985207685489 13320913545053971953 18105216973289555528)	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.909Z	INFO	m0	added member	{"member": "m0", "cluster-id": "6399ddc30b6c70be", "local-member-id": "fb42a6e9624c0648", "added-peer-id": "adcb8499dd134171", "added-peer-peer-urls": ["unix://127.0.0.1:2102606507"], "added-peer-is-learner": false}
    logger.go:130: 2023-04-28T13:32:12.909Z	INFO	m0.raft	fb42a6e9624c0648 switched to configuration voters=(12523248985207685489 13320913545053971953 18105216973289555528)	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.909Z	INFO	m0	added member	{"member": "m0", "cluster-id": "6399ddc30b6c70be", "local-member-id": "fb42a6e9624c0648", "added-peer-id": "b8dd644ac0a1a5f1", "added-peer-peer-urls": ["unix://127.0.0.1:2102306507"], "added-peer-is-learner": false}
    logger.go:130: 2023-04-28T13:32:12.909Z	INFO	m0.raft	fb42a6e9624c0648 switched to configuration voters=(12523248985207685489 13320913545053971953 18105216973289555528)	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.910Z	INFO	m0	added member	{"member": "m0", "cluster-id": "6399ddc30b6c70be", "local-member-id": "fb42a6e9624c0648", "added-peer-id": "fb42a6e9624c0648", "added-peer-peer-urls": ["unix://127.0.0.1:2102006507"], "added-peer-is-learner": false}
    logger.go:130: 2023-04-28T13:32:12.910Z	INFO	grpc	[[core] [Channel #63] Channel switches to new LB policy "round_robin"]
    logger.go:130: 2023-04-28T13:32:12.910Z	INFO	grpc	[[balancer] base.baseBalancer: got new ClientConn state:  {{[{
          "Addr": "unix:localhost:m0",
          "ServerName": "localhost",
          "Attributes": null,
          "BalancerAttributes": null,
          "Type": 0,
          "Metadata": null
        }] 0xc0024f7360 <nil>} <nil>}]
    logger.go:130: 2023-04-28T13:32:12.911Z	INFO	m2	set message encoder	{"member": "m2", "from": "adcb8499dd134171", "to": "fb42a6e9624c0648", "stream-type": "stream MsgApp v2"}
    logger.go:130: 2023-04-28T13:32:12.911Z	INFO	m2	peer became active	{"member": "m2", "peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.911Z	INFO	m2	established TCP streaming connection with remote peer	{"member": "m2", "stream-writer-type": "stream MsgApp v2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.911Z	INFO	m0	peer became active	{"member": "m0", "peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.911Z	INFO	m0	established TCP streaming connection with remote peer	{"member": "m0", "stream-reader-type": "stream MsgApp v2", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.911Z	INFO	grpc	[[core] [Channel #63 SubChannel #64] Subchannel created]
    logger.go:130: 2023-04-28T13:32:12.911Z	INFO	m0	peer became active	{"member": "m0", "peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.911Z	INFO	m0	established TCP streaming connection with remote peer	{"member": "m0", "stream-reader-type": "stream Message", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.911Z	INFO	grpc	[[roundrobin] roundrobinPicker: Build called with info: {map[]}]
    logger.go:130: 2023-04-28T13:32:12.911Z	INFO	grpc	[[core] [Channel #63] Channel Connectivity change to CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.912Z	INFO	m0	established TCP streaming connection with remote peer	{"member": "m0", "stream-reader-type": "stream Message", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.912Z	INFO	m1	set message encoder	{"member": "m1", "from": "b8dd644ac0a1a5f1", "to": "fb42a6e9624c0648", "stream-type": "stream Message"}
    logger.go:130: 2023-04-28T13:32:12.912Z	INFO	m1	peer became active	{"member": "m1", "peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.912Z	INFO	m1	established TCP streaming connection with remote peer	{"member": "m1", "stream-writer-type": "stream Message", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.910Z	INFO	m2	set message encoder	{"member": "m2", "from": "adcb8499dd134171", "to": "fb42a6e9624c0648", "stream-type": "stream Message"}
    logger.go:130: 2023-04-28T13:32:12.915Z	INFO	m0	set message encoder	{"member": "m0", "from": "fb42a6e9624c0648", "to": "b8dd644ac0a1a5f1", "stream-type": "stream MsgApp v2"}
    logger.go:130: 2023-04-28T13:32:12.915Z	INFO	m0	established TCP streaming connection with remote peer	{"member": "m0", "stream-writer-type": "stream MsgApp v2", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.916Z	INFO	m0	set message encoder	{"member": "m0", "from": "fb42a6e9624c0648", "to": "adcb8499dd134171", "stream-type": "stream Message"}
    logger.go:130: 2023-04-28T13:32:12.916Z	INFO	m0	established TCP streaming connection with remote peer	{"member": "m0", "stream-writer-type": "stream Message", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.914Z	INFO	m2	established TCP streaming connection with remote peer	{"member": "m2", "stream-writer-type": "stream Message", "local-member-id": "adcb8499dd134171", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.914Z	INFO	m0	set message encoder	{"member": "m0", "from": "fb42a6e9624c0648", "to": "adcb8499dd134171", "stream-type": "stream MsgApp v2"}
    logger.go:130: 2023-04-28T13:32:12.917Z	INFO	m0	established TCP streaming connection with remote peer	{"member": "m0", "stream-writer-type": "stream MsgApp v2", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "adcb8499dd134171"}
    logger.go:130: 2023-04-28T13:32:12.917Z	INFO	m1	established TCP streaming connection with remote peer	{"member": "m1", "stream-reader-type": "stream MsgApp v2", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.917Z	INFO	grpc	[[core] [Channel #63 SubChannel #64] Subchannel Connectivity change to CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.918Z	INFO	grpc	[[core] [Channel #63 SubChannel #64] Subchannel picks a new address "unix:localhost:m0" to connect]
    logger.go:130: 2023-04-28T13:32:12.919Z	INFO	m1	initialized peer connections; fast-forwarding election ticks	{"member": "m1", "local-member-id": "b8dd644ac0a1a5f1", "forward-ticks": 8, "forward-duration": "80ms", "election-ticks": 10, "election-timeout": "100ms", "active-remote-members": 2}
    logger.go:130: 2023-04-28T13:32:12.917Z	INFO	m2	established TCP streaming connection with remote peer	{"member": "m2", "stream-reader-type": "stream Message", "local-member-id": "adcb8499dd134171", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.917Z	INFO	m1	established TCP streaming connection with remote peer	{"member": "m1", "stream-reader-type": "stream Message", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.917Z	INFO	m2	established TCP streaming connection with remote peer	{"member": "m2", "stream-reader-type": "stream MsgApp v2", "local-member-id": "adcb8499dd134171", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.917Z	INFO	m0	set message encoder	{"member": "m0", "from": "fb42a6e9624c0648", "to": "b8dd644ac0a1a5f1", "stream-type": "stream Message"}
    logger.go:130: 2023-04-28T13:32:12.923Z	INFO	m0	established TCP streaming connection with remote peer	{"member": "m0", "stream-writer-type": "stream Message", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.923Z	INFO	m0	established TCP streaming connection with remote peer	{"member": "m0", "stream-reader-type": "stream MsgApp v2", "local-member-id": "fb42a6e9624c0648", "remote-peer-id": "b8dd644ac0a1a5f1"}
    logger.go:130: 2023-04-28T13:32:12.923Z	INFO	m1	set message encoder	{"member": "m1", "from": "b8dd644ac0a1a5f1", "to": "fb42a6e9624c0648", "stream-type": "stream MsgApp v2"}
    logger.go:130: 2023-04-28T13:32:12.924Z	INFO	m1	established TCP streaming connection with remote peer	{"member": "m1", "stream-writer-type": "stream MsgApp v2", "local-member-id": "b8dd644ac0a1a5f1", "remote-peer-id": "fb42a6e9624c0648"}
    logger.go:130: 2023-04-28T13:32:12.924Z	INFO	grpc	[[balancer] base.baseBalancer: handle SubConn state change: 0xc0024a3650, CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.924Z	INFO	grpc	[[core] [Channel #63 SubChannel #64] Subchannel Connectivity change to READY]
    logger.go:130: 2023-04-28T13:32:12.924Z	INFO	grpc	[[balancer] base.baseBalancer: handle SubConn state change: 0xc0024a3650, READY]
    logger.go:130: 2023-04-28T13:32:12.924Z	INFO	grpc	[[roundrobin] roundrobinPicker: Build called with info: {map[0xc0024a3650:{{
          "Addr": "unix:localhost:m0",
          "ServerName": "localhost",
          "Attributes": null,
          "BalancerAttributes": null,
          "Type": 0,
          "Metadata": null
        }}]}]
    logger.go:130: 2023-04-28T13:32:12.925Z	INFO	grpc	[[core] [Channel #63] Channel Connectivity change to READY]
    logger.go:130: 2023-04-28T13:32:12.925Z	INFO	m0	launched a member	{"member": "m0", "name": "m0", "advertise-peer-urls": ["unix://127.0.0.1:2102006507"], "listen-client-urls": ["unix://127.0.0.1:2102106507"], "grpc-url": "unix://localhost:m0"}
    logger.go:130: 2023-04-28T13:32:12.930Z	INFO	m1.raft	b8dd644ac0a1a5f1 is starting a new election at term 1	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.930Z	INFO	m1.raft	b8dd644ac0a1a5f1 became pre-candidate at term 1	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.930Z	INFO	m1.raft	b8dd644ac0a1a5f1 received MsgPreVoteResp from b8dd644ac0a1a5f1 at term 1	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.930Z	INFO	m1.raft	b8dd644ac0a1a5f1 [logterm: 1, index: 3] sent MsgPreVote request to adcb8499dd134171 at term 1	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.930Z	INFO	m1.raft	b8dd644ac0a1a5f1 [logterm: 1, index: 3] sent MsgPreVote request to fb42a6e9624c0648 at term 1	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.931Z	INFO	m2.raft	adcb8499dd134171 [logterm: 1, index: 3, vote: 0] cast MsgPreVote for b8dd644ac0a1a5f1 [logterm: 1, index: 3] at term 1	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.931Z	INFO	m0.raft	fb42a6e9624c0648 [logterm: 1, index: 3, vote: 0] cast MsgPreVote for b8dd644ac0a1a5f1 [logterm: 1, index: 3] at term 1	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.932Z	INFO	m1.raft	b8dd644ac0a1a5f1 received MsgPreVoteResp from fb42a6e9624c0648 at term 1	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.936Z	INFO	m1.raft	b8dd644ac0a1a5f1 has received 2 MsgPreVoteResp votes and 0 vote rejections	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.937Z	INFO	m1.raft	b8dd644ac0a1a5f1 became candidate at term 2	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.937Z	INFO	m1.raft	b8dd644ac0a1a5f1 received MsgVoteResp from b8dd644ac0a1a5f1 at term 2	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.937Z	INFO	m1.raft	b8dd644ac0a1a5f1 [logterm: 1, index: 3] sent MsgVote request to adcb8499dd134171 at term 2	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.937Z	INFO	m1.raft	b8dd644ac0a1a5f1 [logterm: 1, index: 3] sent MsgVote request to fb42a6e9624c0648 at term 2	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.937Z	INFO	m2.raft	adcb8499dd134171 [term: 1] received a MsgVote message with higher term from b8dd644ac0a1a5f1 [term: 2]	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.937Z	INFO	m2.raft	adcb8499dd134171 became follower at term 2	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.937Z	INFO	m2.raft	adcb8499dd134171 [logterm: 1, index: 3, vote: 0] cast MsgVote for b8dd644ac0a1a5f1 [logterm: 1, index: 3] at term 2	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.938Z	INFO	m0.raft	fb42a6e9624c0648 [term: 1] received a MsgVote message with higher term from b8dd644ac0a1a5f1 [term: 2]	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.938Z	INFO	m0.raft	fb42a6e9624c0648 became follower at term 2	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.938Z	INFO	m0.raft	fb42a6e9624c0648 [logterm: 1, index: 3, vote: 0] cast MsgVote for b8dd644ac0a1a5f1 [logterm: 1, index: 3] at term 2	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.938Z	INFO	m2	initialized peer connections; fast-forwarding election ticks	{"member": "m2", "local-member-id": "adcb8499dd134171", "forward-ticks": 8, "forward-duration": "80ms", "election-ticks": 10, "election-timeout": "100ms", "active-remote-members": 2}
    logger.go:130: 2023-04-28T13:32:12.938Z	INFO	m1.raft	b8dd644ac0a1a5f1 received MsgVoteResp from adcb8499dd134171 at term 2	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.938Z	INFO	m1.raft	b8dd644ac0a1a5f1 has received 2 MsgVoteResp votes and 0 vote rejections	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.938Z	INFO	m1.raft	b8dd644ac0a1a5f1 became leader at term 2	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.938Z	INFO	m1.raft	raft.node: b8dd644ac0a1a5f1 elected leader b8dd644ac0a1a5f1 at term 2	{"member": "m1"}
    logger.go:130: 2023-04-28T13:32:12.939Z	INFO	m2.raft	raft.node: adcb8499dd134171 elected leader b8dd644ac0a1a5f1 at term 2	{"member": "m2"}
    logger.go:130: 2023-04-28T13:32:12.940Z	INFO	m0.raft	raft.node: fb42a6e9624c0648 elected leader b8dd644ac0a1a5f1 at term 2	{"member": "m0"}
    logger.go:130: 2023-04-28T13:32:12.942Z	INFO	m1	setting up initial cluster version using v3 API	{"member": "m1", "cluster-version": "3.6"}
    logger.go:130: 2023-04-28T13:32:12.946Z	INFO	m1	set initial cluster version	{"member": "m1", "cluster-id": "6399ddc30b6c70be", "local-member-id": "b8dd644ac0a1a5f1", "cluster-version": "3.6"}
    logger.go:130: 2023-04-28T13:32:12.946Z	INFO	m1	cluster version differs from storage version.	{"member": "m1", "cluster-version": "3.6.0", "storage-version": "3.5.0"}
    logger.go:130: 2023-04-28T13:32:12.946Z	INFO	m1	updated storage version	{"member": "m1", "new-storage-version": "3.6.0"}
    logger.go:130: 2023-04-28T13:32:12.946Z	INFO	m1	published local member to cluster through raft	{"member": "m1", "local-member-id": "b8dd644ac0a1a5f1", "local-member-attributes": "{Name:m1 ClientURLs:[unix://127.0.0.1:2102406507]}", "cluster-id": "6399ddc30b6c70be", "publish-timeout": "5.2s"}
    logger.go:130: 2023-04-28T13:32:12.947Z	INFO	m1	cluster version is updated	{"member": "m1", "cluster-version": "3.6"}
    logger.go:130: 2023-04-28T13:32:12.948Z	INFO	m0	set initial cluster version	{"member": "m0", "cluster-id": "6399ddc30b6c70be", "local-member-id": "fb42a6e9624c0648", "cluster-version": "3.6"}
    logger.go:130: 2023-04-28T13:32:12.949Z	INFO	m0	cluster version differs from storage version.	{"member": "m0", "cluster-version": "3.6.0", "storage-version": "3.5.0"}
    logger.go:130: 2023-04-28T13:32:12.949Z	INFO	m0	updated storage version	{"member": "m0", "new-storage-version": "3.6.0"}
    logger.go:130: 2023-04-28T13:32:12.949Z	INFO	m0	published local member to cluster through raft	{"member": "m0", "local-member-id": "fb42a6e9624c0648", "local-member-attributes": "{Name:m0 ClientURLs:[unix://127.0.0.1:2102106507]}", "cluster-id": "6399ddc30b6c70be", "publish-timeout": "5.2s"}
    logger.go:130: 2023-04-28T13:32:12.949Z	INFO	m2	published local member to cluster through raft	{"member": "m2", "local-member-id": "adcb8499dd134171", "local-member-attributes": "{Name:m2 ClientURLs:[unix://127.0.0.1:2102706507]}", "cluster-id": "6399ddc30b6c70be", "publish-timeout": "5.2s"}
    logger.go:130: 2023-04-28T13:32:12.950Z	INFO	m2	set initial cluster version	{"member": "m2", "cluster-id": "6399ddc30b6c70be", "local-member-id": "adcb8499dd134171", "cluster-version": "3.6"}
    cluster.go:[238](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:239):  - m0 -> fb42a6e9624c0648 (unix://localhost:m0)
    cluster.go:238:  - m1 -> b8dd644ac0a1a5f1 (unix://localhost:m1)
    cluster.go:238:  - m2 -> adcb8499dd134171 (unix://localhost:m2)
    logger.go:130: 2023-04-28T13:32:12.951Z	INFO	m2	cluster version differs from storage version.	{"member": "m2", "cluster-version": "3.6.0", "storage-version": "3.5.0"}
    logger.go:130: 2023-04-28T13:32:12.951Z	INFO	m2	updated storage version	{"member": "m2", "new-storage-version": "3.6.0"}
    logger.go:130: 2023-04-28T13:32:12.957Z	INFO	m0	initialized peer connections; fast-forwarding election ticks	{"member": "m0", "local-member-id": "fb42a6e9624c0648", "forward-ticks": 8, "forward-duration": "80ms", "election-ticks": 10, "election-timeout": "100ms", "active-remote-members": 2}
    logger.go:130: 2023-04-28T13:32:12.958Z	INFO	grpc	[[core] [Channel #67] Channel created]
    logger.go:130: 2023-04-28T13:32:12.959Z	INFO	grpc	[[core] [Channel #67] original dial target is: "etcd:///foo"]
    logger.go:130: 2023-04-28T13:32:12.959Z	INFO	grpc	[[core] [Channel #67] parsed dial target is: {Scheme:etcd Authority: Endpoint:foo URL:{Scheme:etcd Opaque: User: Host: Path:/foo RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}]
    logger.go:130: 2023-04-28T13:32:12.959Z	INFO	grpc	[[core] [Channel #67] Channel authority set to "foo"]
    logger.go:130: 2023-04-28T13:32:12.960Z	INFO	grpc	[[core] [Channel #67] Resolver state updated: {
          "Addresses": [
            {
              "Addr": "127.0.0.1:39169",
              "ServerName": "",
              "Attributes": null,
              "BalancerAttributes": null,
              "Type": 0,
              "Metadata": null
            },
            {
              "Addr": "127.0.0.1:43113",
              "ServerName": "",
              "Attributes": null,
              "BalancerAttributes": null,
              "Type": 0,
              "Metadata": null
            }
          ],
          "ServiceConfig": null,
          "Attributes": null
        } (resolver returned new addresses)]
    logger.go:130: 2023-04-28T13:32:12.960Z	INFO	grpc	[[core] [Channel #67] Channel switches to new LB policy "round_robin"]
    logger.go:130: 2023-04-28T13:32:12.960Z	INFO	grpc	[[balancer] base.baseBalancer: got new ClientConn state:  {{[{
          "Addr": "127.0.0.1:39169",
          "ServerName": "",
          "Attributes": null,
          "BalancerAttributes": null,
          "Type": 0,
          "Metadata": null
        } {
          "Addr": "127.0.0.1:4[311](https://github.com/etcd-io/etcd/actions/runs/4831119673/jobs/8608139659?pr=15792#step:5:312)3",
          "ServerName": "",
          "Attributes": null,
          "BalancerAttributes": null,
          "Type": 0,
          "Metadata": null
        }] <nil> <nil>} <nil>}]
    logger.go:130: 2023-04-28T13:32:12.960Z	INFO	grpc	[[core] [Channel #67 SubChannel #68] Subchannel created]
    logger.go:130: 2023-04-28T13:32:12.961Z	INFO	grpc	[[core] [Channel #67 SubChannel #69] Subchannel created]
    logger.go:130: 2023-04-28T13:32:12.961Z	INFO	grpc	[[roundrobin] roundrobinPicker: Build called with info: {map[]}]
    logger.go:130: 2023-04-28T13:32:12.961Z	INFO	grpc	[[core] [Channel #67] Channel Connectivity change to CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.961Z	INFO	grpc	[[core] [Channel #67 SubChannel #69] Subchannel Connectivity change to CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.961Z	INFO	grpc	[[core] [Channel #67 SubChannel #69] Subchannel picks a new address "127.0.0.1:43113" to connect]
    logger.go:130: 2023-04-28T13:32:12.961Z	INFO	grpc	[[core] [Channel #67 SubChannel #68] Subchannel Connectivity change to CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.962Z	INFO	grpc	[[core] [Channel #67 SubChannel #68] Subchannel picks a new address "127.0.0.1:39169" to connect]
    logger.go:130: 2023-04-28T13:32:12.962Z	INFO	grpc	[[balancer] base.baseBalancer: handle SubConn state change: 0xc0024a3fb0, CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.962Z	INFO	grpc	[[balancer] base.baseBalancer: handle SubConn state change: 0xc0024a3f68, CONNECTING]
    logger.go:130: 2023-04-28T13:32:12.964Z	INFO	grpc	[[core] [Channel #67 SubChannel #69] Subchannel Connectivity change to READY]
    logger.go:130: 2023-04-28T13:32:12.964Z	INFO	grpc	[[balancer] base.baseBalancer: handle SubConn state change: 0xc0024a3fb0, READY]
    logger.go:130: 2023-04-28T13:32:12.964Z	INFO	grpc	[[roundrobin] roundrobinPicker: Build called with info: {map[0xc0024a3fb0:{{
          "Addr": "127.0.0.1:43113",
          "ServerName": "",
          "Attributes": null,
          "BalancerAttributes": null,
          "Type": 0,
          "Metadata": null
        }}]}]
    logger.go:130: 2023-04-28T13:32:12.964Z	INFO	grpc	[[core] [Channel #67] Channel Connectivity change to READY]
    logger.go:130: 2023-04-28T13:32:12.964Z	INFO	grpc	[[core] [Channel #67 SubChannel #68] Subchannel Connectivity change to READY]
    resolver_test.go:103: Response: 2
    resolver_test.go:103: Response: 3
    resolver_test.go:103: Response: 4
    resolver_test.go:103: Response: 5
    resolver_test.go:103: Response: 6
    resolver_test.go:103: Response: 7
    resolver_test.go:103: Response: 8
    resolver_test.go:103: Response: 9
    resolver_test.go:103: Response: 10
    resolver_test.go:103: Response: 11
    resolver_test.go:103: Response: 12
    resolver_test.go:103: Response: 13
    resolver_test.go:103: Response: 14
    resolver_test.go:103: Response: 15
    resolver_test.go:103: Response: 16
    resolver_test.go:103: Response: 17
    resolver_test.go:103: Response: 18
    resolver_test.go:103: Response: 19
    resolver_test.go:103: Response: 20
    resolver_test.go:103: Response: 21
    logger.go:130: 2023-04-28T13:32:12.976Z	INFO	grpc	[[balancer] base.baseBalancer: handle SubConn state change: 0xc0024a3f68, READY]
    logger.go:130: 2023-04-28T13:32:12.977Z	INFO	grpc	[[roundrobin] roundrobinPicker: Build called with info: {map[0xc0024a3f68:{{
          "Addr": "127.0.0.1:39169",
          "ServerName": "",
          "Attributes": null,
          "BalancerAttributes": null,
          "Type": 0,
          "Metadata": null
        }} 0xc0024a3fb0:{{
          "Addr": "127.0.0.1:43113",
          "ServerName": "",
          "Attributes": null,
          "BalancerAttributes": null,
          "Type": 0,
          "Metadata": null
        }}]}]
    resolver_test.go:103: Response: 22
    resolver_test.go:103: Response: 1
    resolver_test.go:103: Response: 23
    resolver_test.go:103: Response: 2
    resolver_test.go:103: Response: 24
    resolver_test.go:103: Response: 3
    resolver_test.go:103: Response: 25
    resolver_test.go:103: Response: 4
    resolver_test.go:103: Response: 26
    resolver_test.go:103: Response: 5
    resolver_test.go:103: Response: 27
    resolver_test.go:103: Response: 6
    resolver_test.go:103: Response: 28
    resolver_test.go:103: Response: 7
    resolver_test.go:103: Response: 29
    resolver_test.go:103: Response: 8
    resolver_test.go:103: Response: 30
    resolver_test.go:103: Response: 9
    resolver_test.go:103: Response: 31
    resolver_test.go:103: Response: 10
    resolver_test.go:103: Response: 32
    resolver_test.go:103: Response: 11
    resolver_test.go:103: Response: 33
    resolver_test.go:103: Response: 12
    resolver_test.go:103: Response: 34
    resolver_test.go:103: Response: 13
    resolver_test.go:103: Response: 35
    resolver_test.go:103: Response: 14
    resolver_test.go:103: Response: 36
    resolver_test.go:103: Response: 15
    resolver_test.go:103: Response: 37
    resolver_test.go:103: Response: 16
    resolver_test.go:103: Response: 38
    resolver_test.go:103: Response: 17
    resolver_test.go:103: Response: 39
    resolver_test.go:103: Response: 18
    resolver_test.go:103: Response: 40
    resolver_test.go:103: Response: 19
    resolver_test.go:103: Response: 41
    resolver_test.go:103: Response: 20
    resolver_test.go:103: Response: 42
    resolver_test.go:103: Response: 21
    resolver_test.go:103: Response: 43
    resolver_test.go:103: Response: 22
    resolver_test.go:103: Response: 44
    resolver_test.go:103: Response: 23
    resolver_test.go:103: Response: 45
    resolver_test.go:103: Response: 24
    resolver_test.go:103: Response: 46
    resolver_test.go:103: Response: 25
    resolver_test.go:103: Response: 47
    resolver_test.go:103: Response: 26
    resolver_test.go:103: Response: 48
    resolver_test.go:103: Response: 27
    resolver_test.go:103: Response: 49
    resolver_test.go:103: Response: 28
    resolver_test.go:103: Response: 50
    resolver_test.go:103: Response: 29
    resolver_test.go:103: Response: 51
    resolver_test.go:103: Response: 30
    resolver_test.go:103: Response: 52
    resolver_test.go:103: Response: 31
    resolver_test.go:103: Response: 53
    resolver_test.go:103: Response: 32
    resolver_test.go:103: Response: 54
    resolver_test.go:103: Response: 33
    resolver_test.go:103: Response: 55
    resolver_test.go:103: Response: 34
    resolver_test.go:103: Response: 56
    resolver_test.go:103: Response: 35
    resolver_test.go:103: Response: 57
    resolver_test.go:103: Response: 36
    resolver_test.go:103: Response: 58
    resolver_test.go:103: Response: 37
    resolver_test.go:103: Response: 59
    resolver_test.go:103: Response: 38
    resolver_test.go:103: Response: 60
    resolver_test.go:103: Response: 39
    resolver_test.go:103: Response: 61
    resolver_test.go:112: Last response: 61
    resolver_test.go:128: 
        	Error Trace:	/home/runner/work/etcd/etcd/tests/integration/clientv3/naming/resolver_test.go:128
        	            				/home/runner/work/etcd/etcd/tests/integration/clientv3/naming/resolver_test.go:147
        	Error:      	Relative error is too high: 0.1 (expected)
        	            	        < 0.22 (actual)
        	Test:       	TestEtcdGrpcResolverRoundRobin
        	Messages:   	unexpected total responses from foo: 61
@jmhbnz
Copy link
Member

jmhbnz commented Apr 28, 2023 •
edited
Loading

Thanks for raising this @fuweid.

This is the test I introduced recently so I will pick up and fix, it looks like the threshold we set needs tuning as roundrobin is never exactly 50/50, from memory currently we allow up to 10% variation so can increase this slightly.

@jmhbnz jmhbnz self-assigned this Apr 28, 2023
@jmhbnz jmhbnz mentioned this issue Apr 29, 2023
Merged
@chaochn47
Copy link
Member 

=== FAIL: integration/clientv3/naming TestEtcdGrpcResolverRoundRobin (0.79s)

     resolver_test.go:128: 
        	Error Trace:	/home/runner/work/etcd/etcd/tests/integration/clientv3/naming/resolver_test.go:128
        	            				/home/runner/work/etcd/etcd/tests/integration/clientv3/naming/resolver_test.go:147
         	Error:      	Relative error is too high: 0.15 (expected)
        	            	        < 0.176 (actual)

https://github.com/etcd-io/etcd/actions/runs/4933543352/jobs/8817599646?pr=15865

@jmhbnz jmhbnz reopened this May 10, 2023
@jmhbnz
Copy link
Member

jmhbnz commented May 10, 2023

Thanks for highlighting that flake @chaochn47, re-opened.

It looks like my last update helped, but still a little more tuning is needed. I will relax the threshold just a little more to 0.20. I had actually considered going straight to .20 last update but wanted to see how much difference the increase in sample size would have as well.

Will raise a pr tonight.

@jmhbnz jmhbnz mentioned this issue May 10, 2023
Merged
@Rajalakshmi-Girish Rajalakshmi-Girish mentioned this issue Jul 17, 2023
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@jmhbnz jmhbnz

Labels
area/testing type/flake
Milestone
No milestone
3 participants
@fuweid @jmhbnz @chaochn47