We read every piece of feedback, and take your input very seriously.
To see all available qualifiers, see our documentation.
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
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
test (linux-amd64-integration-4-cpu)
TestLeasingReconnectNonOwnerGet
https://github.com/etcd-io/etcd/actions/runs/3071777532/jobs/4963526956
=== Failed === FAIL: integration/clientv3/lease TestLeasingReconnectNonOwnerGet (unknown) cluster.go:533: Creating listener with addr: 127.0.0.1:2125406054 cluster.go:533: Creating listener with addr: 127.0.0.1:2125506054 logger.go:130: 2022-09-17T05:24:30.555Z INFO m0 LISTEN GRPC {"member": "m0", "grpcAddr": "localhost:m0", "m.Name": "m0", "workdir": "/tmp/TestLeasingReconnectNonOwnerGet2462777176/001"} logger.go:130: 2022-09-17T05:24:30.555Z INFO m0 LISTEN BRIDGE {"member": "m0", "grpc-address": "localhost:m00", "member": "m0"} cluster.go:217: Launching new cluster... logger.go:130: 2022-09-17T05:24:30.555Z INFO m0 launching a member {"member": "m0", "name": "m0", "advertise-peer-urls": ["unix://127.0.0.1:2125406054"], "listen-client-urls": ["unix://127.0.0.1:2125506054"], "grpc-url": "unix://localhost:m00"} logger.go:130: 2022-09-17T05:24:30.556Z INFO m0 opened backend db {"member": "m0", "path": "/tmp/TestLeasingReconnectNonOwnerGet2462777176/002/etcd3822453242/member/snap/db", "took": "886.412µs"} logger.go:130: 2022-09-17T05:24:30.558Z INFO m0 starting local member {"member": "m0", "local-member-id": "816de54200e25e04", "cluster-id": "585b247855404513"} logger.go:130: 2022-09-17T05:24:30.558Z INFO m0.raft 816de54200e25e04 switched to configuration voters=() {"member": "m0"} logger.go:130: 2022-09-17T05:24:30.558Z INFO m0.raft 816de54200e25e04 became follower at term 0 {"member": "m0"} logger.go:130: 2022-09-17T05:24:30.558Z INFO m0.raft newRaft 816de54200e25e04 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] {"member": "m0"} logger.go:130: 2022-09-17T05:24:30.559Z INFO m0.raft 816de54200e25e04 became follower at term 1 {"member": "m0"} logger.go:130: 2022-09-17T05:24:30.559Z INFO m0.raft 816de54200e25e04 switched to configuration voters=(9326362474999602692) {"member": "m0"} logger.go:130: 2022-09-17T05:24:30.560Z WARN m0 simple token is not cryptographically signed {"member": "m0"} logger.go:130: 2022-09-17T05:24:30.561Z INFO m0 kvstore restored {"member": "m0", "current-rev": 1} logger.go:130: 2022-09-17T05:24:30.562Z INFO m0 starting etcd server {"member": "m0", "local-member-id": "816de54200e25e04", "local-server-version": "3.6.0-alpha.0", "cluster-version": "to_be_decided"} logger.go:130: 2022-09-17T05:24:30.562Z INFO grpc [[core] [Server #597] Server created] logger.go:130: 2022-09-17T05:24:30.562Z INFO m0 started as single-node; fast-forwarding election ticks {"member": "m0", "local-member-id": "816de54200e25e04", "forward-ticks": 9, "forward-duration": "90ms", "election-ticks": 10, "election-timeout": "100ms"} logger.go:130: 2022-09-17T05:24:30.562Z INFO grpc [[core] [Channel #598] Channel created] logger.go:130: 2022-09-17T05:24:30.562Z INFO grpc [[core] [Channel #598] original dial target is: "etcd-endpoints://0xc000533c20/localhost:m00"] logger.go:130: 2022-09-17T05:24:30.562Z INFO grpc [[core] [Channel #598] parsed dial target is: {Scheme:etcd-endpoints Authority:0xc000533c20 Endpoint:localhost:m00 URL:{Scheme:etcd-endpoints Opaque: User: Host:0xc000533c20 Path:/localhost:m00 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}] logger.go:130: 2022-09-17T05:24:30.562Z INFO grpc [[core] [Channel #598] Channel authority set to "localhost:m00"] logger.go:130: 2022-09-17T05:24:30.562Z INFO grpc [[core] [Channel #598] Resolver state updated: { "Addresses": [ { "Addr": "unix:localhost:m00", "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: 2022-09-17T05:24:30.562Z INFO grpc [[core] [Channel #598] Channel switches to new LB policy "round_robin"] logger.go:130: 2022-09-17T05:24:30.562Z INFO grpc [[balancer] base.baseBalancer: got new ClientConn state: {{[{ "Addr": "unix:localhost:m00", "ServerName": "localhost", "Attributes": null, "BalancerAttributes": null, "Type": 0, "Metadata": null }] 0xc00170a960 <nil>} <nil>}] logger.go:130: 2022-09-17T05:24:30.562Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel created] logger.go:130: 2022-09-17T05:24:30.562Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.562Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel picks a new address "unix:localhost:m00" to connect] logger.go:130: 2022-09-17T05:24:30.563Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, CONNECTING] logger.go:130: 2022-09-17T05:24:30.563Z INFO grpc [[core] [Channel #598] Channel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.563Z INFO m0.raft 816de54200e25e04 switched to configuration voters=(9326362474999602692) {"member": "m0"} logger.go:130: 2022-09-17T05:24:30.563Z INFO m0 added member {"member": "m0", "cluster-id": "585b247855404513", "local-member-id": "816de54200e25e04", "added-peer-id": "816de54200e25e04", "added-peer-peer-urls": ["unix://127.0.0.1:2125406054"], "added-peer-is-learner": false} logger.go:130: 2022-09-17T05:24:30.564Z INFO grpc [[core] [Server #597 ListenSocket #599] ListenSocket created] logger.go:130: 2022-09-17T05:24:30.564Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.564Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, READY] logger.go:130: 2022-09-17T05:24:30.564Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[0xc00155f7d0:{{ "Addr": "unix:localhost:m00", "ServerName": "localhost", "Attributes": null, "BalancerAttributes": null, "Type": 0, "Metadata": null }}]}] logger.go:130: 2022-09-17T05:24:30.564Z INFO grpc [[core] [Channel #598] Channel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.564Z INFO m0 launched a member {"member": "m0", "name": "m0", "advertise-peer-urls": ["unix://127.0.0.1:2125406054"], "listen-client-urls": ["unix://127.0.0.1:2125506054"], "grpc-url": "unix://localhost:m00"} logger.go:130: 2022-09-17T05:24:30.569Z INFO m0.raft 816de54200e25e04 is starting a new election at term 1 {"member": "m0"} logger.go:130: 2022-09-17T05:24:30.569Z INFO m0.raft 816de54200e25e04 became candidate at term 2 {"member": "m0"} logger.go:130: 2022-09-17T05:24:30.569Z INFO m0.raft 816de54200e25e04 received MsgVoteResp from 816de54200e25e04 at term 2 {"member": "m0"} logger.go:130: 2022-09-17T05:24:30.569Z INFO m0.raft 816de54200e25e04 became leader at term 2 {"member": "m0"} logger.go:130: 2022-09-17T05:24:30.569Z INFO m0.raft raft.node: 816de54200e25e04 elected leader 816de54200e25e04 at term 2 {"member": "m0"} logger.go:130: 2022-09-17T05:24:30.569Z INFO m0 setting up initial cluster version using v3 API {"member": "m0", "cluster-version": "3.6"} logger.go:130: 2022-09-17T05:24:30.569Z INFO m0 published local member to cluster through raft {"member": "m0", "local-member-id": "816de54200e25e04", "local-member-attributes": "{Name:m0 ClientURLs:[unix://127.0.0.1:2125506054]}", "cluster-id": "585b247855404513", "publish-timeout": "5.2s"} logger.go:130: 2022-09-17T05:24:30.569Z INFO m0 set initial cluster version {"member": "m0", "cluster-id": "585b247855404513", "local-member-id": "816de54200e25e04", "cluster-version": "3.6"} logger.go:130: 2022-09-17T05:24:30.570Z INFO m0 cluster version is updated {"member": "m0", "cluster-version": "3.6"} logger.go:130: 2022-09-17T05:24:30.570Z WARN m0 Failed to detect schema version {"member": "m0", "error": "missing confstate information"} logger.go:130: 2022-09-17T05:24:30.570Z ERROR m0 failed to update storage version {"member": "m0", "cluster-version": "3.6.0", "error": "cannot detect storage schema version: missing confstate information"} cluster.go:236: - m0 -> 816de54200e25e04 (unix://localhost:m00) logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.581Z WARN m0.client retrying of unary invoker failed {"member": "m0", "target": "etcd-endpoints://0xc000533c20/localhost:m00", "method": "/etcdserverpb.KV/Txn", "attempt": 0, "error": "rpc error: code = Unavailable desc = error reading from server: read unix @->localhost:m00: read: connection reset by peer"} logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[core] blockingPicker: the picked transport is not ready, loop back to repick] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, IDLE] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[]}] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[core] [Channel #598] Channel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel picks a new address "unix:localhost:m00" to connect] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, CONNECTING] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[core] [Channel #598] Channel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, READY] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[0xc00155f7d0:{{ "Addr": "unix:localhost:m00", "ServerName": "localhost", "Attributes": null, "BalancerAttributes": null, "Type": 0, "Metadata": null }}]}] logger.go:130: 2022-09-17T05:24:30.581Z INFO grpc [[core] [Channel #598] Channel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.582Z WARN grpc [[core] [Server #597] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.582Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.582Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.582Z WARN m0.client retrying of unary invoker failed {"member": "m0", "target": "etcd-endpoints://0xc000533c20/localhost:m00", "method": "/etcdserverpb.KV/Txn", "attempt": 0, "error": "rpc error: code = Unavailable desc = error reading from server: EOF"} logger.go:130: 2022-09-17T05:24:30.582Z INFO grpc [[core] blockingPicker: the picked transport is not ready, loop back to repick] logger.go:130: 2022-09-17T05:24:30.582Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, IDLE] logger.go:130: 2022-09-17T05:24:30.582Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[]}] logger.go:130: 2022-09-17T05:24:30.582Z INFO grpc [[core] [Channel #598] Channel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.582Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.582Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.582Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel picks a new address "unix:localhost:m00" to connect] logger.go:130: 2022-09-17T05:24:30.582Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, CONNECTING] logger.go:130: 2022-09-17T05:24:30.582Z INFO grpc [[core] [Channel #598] Channel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.583Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.583Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, READY] logger.go:130: 2022-09-17T05:24:30.583Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[0xc00155f7d0:{{ "Addr": "unix:localhost:m00", "ServerName": "localhost", "Attributes": null, "BalancerAttributes": null, "Type": 0, "Metadata": null }}]}] logger.go:130: 2022-09-17T05:24:30.583Z INFO grpc [[core] [Channel #598] Channel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.584Z WARN m0.client retrying of unary invoker failed {"member": "m0", "target": "etcd-endpoints://0xc000533c20/localhost:m00", "method": "/etcdserverpb.KV/Txn", "attempt": 0, "error": "rpc error: code = Unavailable desc = error reading from server: EOF"} logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[core] blockingPicker: the picked transport is not ready, loop back to repick] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, IDLE] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[]}] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[core] [Channel #598] Channel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel picks a new address "unix:localhost:m00" to connect] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, CONNECTING] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[core] [Channel #598] Channel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, READY] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[0xc00155f7d0:{{ "Addr": "unix:localhost:m00", "ServerName": "localhost", "Attributes": null, "BalancerAttributes": null, "Type": 0, "Metadata": null }}]}] logger.go:130: 2022-09-17T05:24:30.584Z INFO grpc [[core] [Channel #598] Channel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.585Z WARN grpc [[core] [Server #597] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.585Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.585Z WARN m0.client retrying of unary invoker failed {"member": "m0", "target": "etcd-endpoints://0xc000533c20/localhost:m00", "method": "/etcdserverpb.KV/Txn", "attempt": 0, "error": "rpc error: code = Unavailable desc = error reading from server: EOF"} logger.go:130: 2022-09-17T05:24:30.585Z INFO grpc [[core] blockingPicker: the picked transport is not ready, loop back to repick] logger.go:130: 2022-09-17T05:24:30.585Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.585Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, IDLE] logger.go:130: 2022-09-17T05:24:30.585Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[]}] logger.go:130: 2022-09-17T05:24:30.585Z INFO grpc [[core] [Channel #598] Channel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.585Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.585Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.585Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel picks a new address "unix:localhost:m00" to connect] logger.go:130: 2022-09-17T05:24:30.585Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, CONNECTING] logger.go:130: 2022-09-17T05:24:30.585Z INFO grpc [[core] [Channel #598] Channel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.586Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.586Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.587Z WARN grpc [[core] [Server #597] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, READY] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[0xc00155f7d0:{{ "Addr": "unix:localhost:m00", "ServerName": "localhost", "Attributes": null, "BalancerAttributes": null, "Type": 0, "Metadata": null }}]}] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[core] [Channel #598] Channel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, IDLE] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[]}] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[core] [Channel #598] Channel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel picks a new address "unix:localhost:m00" to connect] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[core] blockingPicker: the picked transport is not ready, loop back to repick] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, CONNECTING] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[core] [Channel #598] Channel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.587Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.588Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, READY] logger.go:130: 2022-09-17T05:24:30.588Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[0xc00155f7d0:{{ "Addr": "unix:localhost:m00", "ServerName": "localhost", "Attributes": null, "BalancerAttributes": null, "Type": 0, "Metadata": null }}]}] logger.go:130: 2022-09-17T05:24:30.588Z INFO grpc [[core] [Channel #598] Channel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.588Z WARN grpc [[core] [Server #597] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.588Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.589Z WARN m0.client retrying of unary invoker failed {"member": "m0", "target": "etcd-endpoints://0xc000533c20/localhost:m00", "method": "/etcdserverpb.KV/Txn", "attempt": 0, "error": "rpc error: code = Unavailable desc = error reading from server: EOF"} logger.go:130: 2022-09-17T05:24:30.589Z INFO grpc [[core] blockingPicker: the picked transport is not ready, loop back to repick] logger.go:130: 2022-09-17T05:24:30.589Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.589Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, IDLE] logger.go:130: 2022-09-17T05:24:30.589Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[]}] logger.go:130: 2022-09-17T05:24:30.589Z INFO grpc [[core] [Channel #598] Channel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.589Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.589Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.589Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel picks a new address "unix:localhost:m00" to connect] logger.go:130: 2022-09-17T05:24:30.589Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, CONNECTING] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[core] [Channel #598] Channel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.589Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, READY] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[0xc00155f7d0:{{ "Addr": "unix:localhost:m00", "ServerName": "localhost", "Attributes": null, "BalancerAttributes": null, "Type": 0, "Metadata": null }}]}] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[core] [Channel #598] Channel Connectivity change to READY] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, IDLE] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[roundrobin] roundrobinPicker: Build called with info: {map[]}] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[core] [Channel #598] Channel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel picks a new address "unix:localhost:m00" to connect] logger.go:130: 2022-09-17T05:24:30.590Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, CONNECTING] logger.go:130: 2022-09-17T05:24:30.591Z INFO grpc [[core] [Channel #598] Channel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.591Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.591Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.591Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.591Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, IDLE] logger.go:130: 2022-09-17T05:24:30.591Z INFO grpc [[core] [Channel #598] Channel Connectivity change to IDLE] logger.go:130: 2022-09-17T05:24:30.591Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.591Z INFO grpc [[core] [Channel #598 SubChannel #600] Subchannel picks a new address "unix:localhost:m00" to connect] logger.go:130: 2022-09-17T05:24:30.591Z INFO grpc [[balancer] base.baseBalancer: handle SubConn state change: 0xc00155f7d0, CONNECTING] logger.go:130: 2022-09-17T05:24:30.591Z INFO grpc [[core] [Channel #598] Channel Connectivity change to CONNECTING] logger.go:130: 2022-09-17T05:24:30.592Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:30.592Z INFO grpc [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"] logger.go:130: 2022-09-17T05:24:34.570Z INFO m0 cluster version differs from storage version. {"member": "m0", "cluster-version": "3.6.0", "storage-version": "3.5.0"} logger.go:130: 2022-09-17T05:24:34.571Z INFO m0 updated storage version {"member": "m0", "new-storage-version": "3.6.0"} logger.go:130: 2022-09-17T05:25:30.634Z ERROR m0 failed to detach old lease from a key {"member": "m0", "error": "lease not found"} panic: test timed out after 15m0s goroutine 14977 [running]: testing.(*M).startAlarm.func1() /opt/hostedtoolcache/go/1.17.8/x64/src/testing/testing.go:1788 +0x8e created by time.goFunc /opt/hostedtoolcache/go/1.17.8/x64/src/time/sleep.go:180 +0x31 goroutine 1 [chan receive, 14 minutes]: testing.(*T).Run(0xc000097040, {0xf55fdc, 0x46ebb3}, 0xf8a828) /opt/hostedtoolcache/go/1.17.8/x64/src/testing/testing.go:1307 +0x375 testing.runTests.func1(0xc0005059e0) /opt/hostedtoolcache/go/1.17.8/x64/src/testing/testing.go:1598 +0x6e testing.tRunner(0xc000097040, 0xc0005bfcc0) /opt/hostedtoolcache/go/1.17.8/x64/src/testing/testing.go:1259 +0x102 testing.runTests(0xc0001e6300, {0x17acce0, 0x41, 0x41}, {0xc0005bfd90, 0x40f0f4, 0x17bdd20}) /opt/hostedtoolcache/go/1.17.8/x64/src/testing/testing.go:1596 +0x43f testing.(*M).Run(0xc0001e6300) /opt/hostedtoolcache/go/1.17.8/x64/src/testing/testing.go:1504 +0x51d go.etcd.io/etcd/client/pkg/v3/testutil.MustTestMainWithLeakDetection(0xc0000001a0) /home/runner/work/etcd/etcd/client/pkg/testutil/leak.go:176 +0x19 go.etcd.io/etcd/tests/v3/integration/clientv3/lease_test.TestMain(...) /home/runner/work/etcd/etcd/tests/integration/clientv3/lease/main_test.go:14 main.main() _testmain.go:175 +0x166 goroutine 14942 [select]: go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).monitorStorageVersion(0xc0004b3c00) /home/runner/work/etcd/etcd/server/etcdserver/server.go:2182 +0x132 go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).GoAttach.func1() /home/runner/work/etcd/etcd/server/etcdserver/server.go:2403 +0x64 created by go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).GoAttach /home/runner/work/etcd/etcd/server/etcdserver/server.go:2401 +0x117 goroutine 14910 [select]: go.etcd.io/etcd/server/v3/etcdserver.(*raftNode).start.func1() /home/runner/work/etcd/etcd/server/etcdserver/raft.go:166 +0x185 created by go.etcd.io/etcd/server/v3/etcdserver.(*raftNode).start /home/runner/work/etcd/etcd/server/etcdserver/raft.go:161 +0x85 goroutine 14955 [select, 14 minutes]: google.golang.org/grpc.(*ccBalancerWrapper).watcher(0xc000597940) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/balancer_conn_wrappers.go:112 +0x79 created by google.golang.org/grpc.newCCBalancerWrapper /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/balancer_conn_wrappers.go:73 +0x22f goroutine 14900 [IO wait, 14 minutes]: internal/poll.runtime_pollWait(0x7f991c576108, 0x72) /opt/hostedtoolcache/go/1.17.8/x64/src/runtime/netpoll.go:234 +0x89 internal/poll.(*pollDesc).wait(0xc000fa0c80, 0x1, 0x0) /opt/hostedtoolcache/go/1.17.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x32 internal/poll.(*pollDesc).waitRead(...) /opt/hostedtoolcache/go/1.17.8/x64/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Accept(0xc000fa0c80) /opt/hostedtoolcache/go/1.17.8/x64/src/internal/poll/fd_unix.go:402 +0x22c net.(*netFD).accept(0xc000fa0c80) /opt/hostedtoolcache/go/1.17.8/x64/src/net/fd_unix.go:173 +0x35 net.(*UnixListener).accept(0xc00006fec0) /opt/hostedtoolcache/go/1.17.8/x64/src/net/unixsock_posix.go:167 +0x1c net.(*UnixListener).Accept(0xc000acd2c0) /opt/hostedtoolcache/go/1.17.8/x64/src/net/unixsock.go:260 +0x3d go.etcd.io/etcd/tests/v3/framework/integration.(*bridge).serveListen(0xc0004e7080) /home/runner/work/etcd/etcd/tests/framework/integration/bridge.go:107 +0x8d created by go.etcd.io/etcd/tests/v3/framework/integration.newBridge /home/runner/work/etcd/etcd/tests/framework/integration/bridge.go:54 +0x1a7 goroutine 14903 [select]: go.etcd.io/etcd/server/v3/storage/backend.(*backend).run(0xc000dc8240) /home/runner/work/etcd/etcd/server/storage/backend/backend.go:417 +0x10f created by go.etcd.io/etcd/server/v3/storage/backend.newBackend /home/runner/work/etcd/etcd/server/storage/backend/backend.go:225 +0x5b0 goroutine 14905 [select]: go.etcd.io/etcd/raft/v3.(*node).run(0xc0004e7c80) /home/runner/work/etcd/etcd/raft/node.go:344 +0x78a created by go.etcd.io/etcd/raft/v3.StartNode /home/runner/work/etcd/etcd/raft/node.go:233 +0x359 goroutine 14907 [select]: go.etcd.io/etcd/server/v3/lease.(*lessor).runLoop(0xc000dc83c0) /home/runner/work/etcd/etcd/server/lease/lessor.go:613 +0xd2 created by go.etcd.io/etcd/server/v3/lease.newLessor /home/runner/work/etcd/etcd/server/lease/lessor.go:234 +0x373 goroutine 14858 [select, 14 minutes]: google.golang.org/grpc.(*pickerWrapper).pick(0xc000accf60, {0x10a48d8, 0xc000acdd40}, 0x0, {{0xf543af, 0x0}, {0x10a48d8, 0xc000acdd40}}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/picker_wrapper.go:103 +0x21b google.golang.org/grpc.(*ClientConn).getTransport(0x26, {0x10a48d8, 0xc000acdd40}, 0xb8, {0xf543af, 0xf543af}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/clientconn.go:929 +0x35 google.golang.org/grpc.(*csAttempt).getTransport(0xc0009502c0) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:430 +0x48 google.golang.org/grpc.newClientStreamWithParams.func2(0xc0009502c0) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:315 +0x2b google.golang.org/grpc.(*clientStream).withRetry(0xc000676000, 0xc00155e540, 0xc00064b700) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:709 +0xd3 google.golang.org/grpc.newClientStreamWithParams({0x10a48d8, 0xc000acdbf0}, 0x17b7260, 0xc000259c00, {0xf543af, 0x7e6700}, {0x0, 0x0, 0x0, 0x0, ...}, ...) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:327 +0x9ce google.golang.org/grpc.newClientStream.func2({0x10a48d8, 0xc000acdbf0}, 0xc000acdbf0) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:192 +0x9f google.golang.org/grpc.newClientStream({0x10a48d8, 0xc000acdbf0}, 0x17b7260, 0xc000259c00, {0xf543af, 0xc0004e08f0}, {0xc0002aec80, 0x3, 0x4}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:220 +0x4bf google.golang.org/grpc.invoke({0x10a48d8, 0xc000acdbf0}, {0xf543af, 0x3030303063783028}, {0xef3ae0, 0xc000acdb90}, {0xefe040, 0xc000cf7310}, 0x6d6f682f090a2930, {0xc0002aec80, ...}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/call.go:66 +0x7d go.etcd.io/etcd/client/v3.(*Client).unaryClientInterceptor.func1({0x10a4830, 0xc000597800}, {0xf543af, 0x1e}, {0xef3ae0, 0xc000acdb90}, {0xefe040, 0xc000cf7310}, 0xc000259c00, 0xf8abb8, ...) /home/runner/work/etcd/etcd/client/v3/retry_interceptor.go:60 +0x50a google.golang.org/grpc.(*ClientConn).Invoke(0x60, {0x10a4830, 0xc000597800}, {0xf543af, 0x6}, {0xef3ae0, 0xc000acdb90}, {0xefe040, 0xc000cf7310}, {0xc0006f15c0, ...}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/call.go:35 +0x223 go.etcd.io/etcd/api/v3/etcdserverpb.(*leaseClient).LeaseGrant(0xc000b88068, {0x10a4830, 0xc000597800}, 0xc000634800, {0xc0006f15c0, 0x4, 0x6}) /home/runner/work/etcd/etcd/api/etcdserverpb/rpc.pb.go:6853 +0xc9 go.etcd.io/etcd/client/v3.(*retryLeaseClient).LeaseGrant(0xc000f705f0, {0x10a4830, 0xc000597800}, 0x40f0f4, {0x17b7c80, 0x3, 0x3}) /home/runner/work/etcd/etcd/client/v3/retry.go:144 +0x130 go.etcd.io/etcd/client/v3.(*lessor).Grant(0xc0002d60a0, {0x10a4830, 0xc000597800}, 0x3c) /home/runner/work/etcd/etcd/client/v3/lease.go:216 +0x78 go.etcd.io/etcd/client/v3/concurrency.NewSession(0xc000533c20, {0x0, 0x0, 0x0}) /home/runner/work/etcd/etcd/client/v3/concurrency/session.go:46 +0xec go.etcd.io/etcd/client/v3/leasing.(*leasingKV).monitorSession(0xc0006ac210) /home/runner/work/etcd/etcd/client/v3/leasing/kv.go:142 +0x19f go.etcd.io/etcd/client/v3/leasing.NewKV.func1() /home/runner/work/etcd/etcd/client/v3/leasing/kv.go:71 +0x5a created by go.etcd.io/etcd/client/v3/leasing.NewKV /home/runner/work/etcd/etcd/client/v3/leasing/kv.go:69 +0x212 goroutine 14936 [select]: go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).run(0xc0004b3c00) /home/runner/work/etcd/etcd/server/etcdserver/server.go:843 +0x7e7 created by go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).start /home/runner/work/etcd/etcd/server/etcdserver/server.go:591 +0xfc5 goroutine 14954 [IO wait, 14 minutes]: internal/poll.runtime_pollWait(0x7f991c750580, 0x72) /opt/hostedtoolcache/go/1.17.8/x64/src/runtime/netpoll.go:234 +0x89 internal/poll.(*pollDesc).wait(0xc000fa0900, 0xc00006acf8, 0x0) /opt/hostedtoolcache/go/1.17.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x32 internal/poll.(*pollDesc).waitRead(...) /opt/hostedtoolcache/go/1.17.8/x64/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Accept(0xc000fa0900) /opt/hostedtoolcache/go/1.17.8/x64/src/internal/poll/fd_unix.go:402 +0x22c net.(*netFD).accept(0xc000fa0900) /opt/hostedtoolcache/go/1.17.8/x64/src/net/fd_unix.go:173 +0x35 net.(*UnixListener).accept(0xeb4b40) /opt/hostedtoolcache/go/1.17.8/x64/src/net/unixsock_posix.go:167 +0x1c net.(*UnixListener).Accept(0xc000acce70) /opt/hostedtoolcache/go/1.17.8/x64/src/net/unixsock.go:260 +0x3d net/http.(*Server).Serve(0xc000143260, {0x1099f68, 0xc00155f100}) /opt/hostedtoolcache/go/1.17.8/x64/src/net/http/server.go:3002 +0x394 net/http/httptest.(*Server).goServe.func1() /opt/hostedtoolcache/go/1.17.8/x64/src/net/http/httptest/server.go:308 +0x6a created by net/http/httptest.(*Server).goServe /opt/hostedtoolcache/go/1.17.8/x64/src/net/http/httptest/server.go:306 +0x6f goroutine 14943 [select, 14 minutes]: go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).linearizableReadLoop(0xc0004b3c00) /home/runner/work/etcd/etcd/server/etcdserver/v3_server.go:729 +0xe5 go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).GoAttach.func1() /home/runner/work/etcd/etcd/server/etcdserver/server.go:2403 +0x64 created by go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).GoAttach /home/runner/work/etcd/etcd/server/etcdserver/server.go:2401 +0x117 goroutine 14908 [select, 14 minutes]: go.etcd.io/etcd/pkg/v3/schedule.(*fifo).run(0xc000496770) /home/runner/work/etcd/etcd/pkg/schedule/schedule.go:173 +0x193 created by go.etcd.io/etcd/pkg/v3/schedule.NewFIFOScheduler /home/runner/work/etcd/etcd/pkg/schedule/schedule.go:101 +0x188 goroutine 14917 [select]: go.etcd.io/etcd/client/v3.(*lessor).deadlineLoop(0xc0002d60a0) /home/runner/work/etcd/etcd/client/v3/lease.go:551 +0x85 created by go.etcd.io/etcd/client/v3.(*lessor).KeepAlive.func1 /home/runner/work/etcd/etcd/client/v3/lease.go:300 +0xa7 goroutine 14904 [select, 14 minutes]: go.etcd.io/etcd/server/v3/storage/wal.(*filePipeline).run(0xc0002af400) /home/runner/work/etcd/etcd/server/storage/wal/file_pipeline.go:98 +0x111 created by go.etcd.io/etcd/server/v3/storage/wal.newFilePipeline /home/runner/work/etcd/etcd/server/storage/wal/file_pipeline.go:55 +0x288 goroutine 14948 [IO wait, 14 minutes]: internal/poll.runtime_pollWait(0x7f991c575710, 0x72) /opt/hostedtoolcache/go/1.17.8/x64/src/runtime/netpoll.go:234 +0x89 internal/poll.(*pollDesc).wait(0xc000fa0a80, 0x20, 0x0) /opt/hostedtoolcache/go/1.17.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x32 internal/poll.(*pollDesc).waitRead(...) /opt/hostedtoolcache/go/1.17.8/x64/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Accept(0xc000fa0a80) /opt/hostedtoolcache/go/1.17.8/x64/src/internal/poll/fd_unix.go:402 +0x22c net.(*netFD).accept(0xc000fa0a80) /opt/hostedtoolcache/go/1.17.8/x64/src/net/fd_unix.go:173 +0x35 net.(*UnixListener).accept(0xc0004e1e80) /opt/hostedtoolcache/go/1.17.8/x64/src/net/unixsock_posix.go:167 +0x1c net.(*UnixListener).Accept(0xc000acd260) /opt/hostedtoolcache/go/1.17.8/x64/src/net/unixsock.go:260 +0x3d google.golang.org/grpc.(*Server).Serve(0xc0009ba380, {0x109ac88, 0xc000acd260}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/server.go:780 +0x477 created by go.etcd.io/etcd/tests/v3/framework/integration.(*Member).Launch /home/runner/work/etcd/etcd/tests/framework/integration/cluster.go:946 +0x94f goroutine 14916 [select, 14 minutes]: google.golang.org/grpc.(*pickerWrapper).pick(0xc000accf60, {0x10a48d8, 0xc000e095c0}, 0x0, {{0xf5aacb, 0x0}, {0x10a48d8, 0xc000e095c0}}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/picker_wrapper.go:103 +0x21b google.golang.org/grpc.(*ClientConn).getTransport(0x10000c000b32bd0, {0x10a48d8, 0xc000e095c0}, 0x10, {0xf5aacb, 0xf5aacb}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/clientconn.go:929 +0x35 google.golang.org/grpc.(*csAttempt).getTransport(0xc0006ac160) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:430 +0x48 google.golang.org/grpc.newClientStreamWithParams.func2(0xc0006ac160) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:315 +0x2b google.golang.org/grpc.(*clientStream).withRetry(0xc00040e240, 0xc001412930, 0xc000a118b0) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:709 +0xd3 google.golang.org/grpc.newClientStreamWithParams({0x10a48d8, 0xc000e094a0}, 0x179aa40, 0xc000259c00, {0xf5aacb, 0x7e6700}, {0x0, 0x0, 0x0, 0x0, ...}, ...) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:327 +0x9ce google.golang.org/grpc.newClientStream.func2({0x10a48d8, 0xc000e094a0}, 0xc000e094a0) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:192 +0x9f google.golang.org/grpc.newClientStream({0x10a48d8, 0xc000e094a0}, 0x179aa40, 0xc000259c00, {0xf5aacb, 0x2}, {0xc000362c80, 0x3, 0x4}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:220 +0x4bf go.etcd.io/etcd/client/v3.(*Client).streamClientInterceptor.func1({0x10a4830, 0xc000362c00}, 0x179aa40, 0xc000259c00, {0xf5aacb, 0x410ebd}, 0xf8abc8, {0xc0006b1560, 0x5, 0x6}) /home/runner/work/etcd/etcd/client/v3/retry_interceptor.go:131 +0x5c6 google.golang.org/grpc.(*ClientConn).NewStream(0xc000b88148, {0x10a4830, 0xc000362c00}, 0xc000a11d10, {0xf5aacb, 0xe80f00}, {0xc0006b1560, 0xc000a11d60, 0xc000b88148}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:159 +0x187 go.etcd.io/etcd/api/v3/etcdserverpb.(*leaseClient).LeaseKeepAlive(0x1096cb8, {0x10a4830, 0xc000362c00}, {0xc0006b1560, 0x6, 0x30}) /home/runner/work/etcd/etcd/api/etcdserverpb/rpc.pb.go:6870 +0x67 go.etcd.io/etcd/client/v3.(*retryLeaseClient).LeaseKeepAlive(0xc000f705f0, {0x10a4830, 0xc000362c00}, {0xc0006b1560, 0x4, 0x6}) /home/runner/work/etcd/etcd/client/v3/retry.go:152 +0x11d go.etcd.io/etcd/client/v3.(*lessor).resetRecv(0xc0002d60a0) /home/runner/work/etcd/etcd/client/v3/lease.go:486 +0x174 go.etcd.io/etcd/client/v3.(*lessor).recvKeepAliveLoop(0xc0002d60a0) /home/runner/work/etcd/etcd/client/v3/lease.go:449 +0xaf created by go.etcd.io/etcd/client/v3.(*lessor).KeepAlive.func1 /home/runner/work/etcd/etcd/client/v3/lease.go:299 +0x65 goroutine 14941 [select]: go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).monitorClusterVersions(0xc0004b3c00) /home/runner/work/etcd/etcd/server/etcdserver/server.go:2164 +0x11e go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).GoAttach.func1() /home/runner/work/etcd/etcd/server/etcdserver/server.go:2403 +0x64 created by go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).GoAttach /home/runner/work/etcd/etcd/server/etcdserver/server.go:2401 +0x117 goroutine 14932 [select, 14 minutes]: go.etcd.io/etcd/server/v3/storage/mvcc.(*watchableStore).syncVictimsLoop(0xc000cc00a0) /home/runner/work/etcd/etcd/server/storage/mvcc/watchable_store.go:259 +0x16a created by go.etcd.io/etcd/server/v3/storage/mvcc.newWatchableStore /home/runner/work/etcd/etcd/server/storage/mvcc/watchable_store.go:96 +0x611 goroutine 14940 [select, 6 minutes]: go.etcd.io/etcd/server/v3/etcdserver.monitorFileDescriptor(0xc000b28db0, 0xc000424480) /home/runner/work/etcd/etcd/server/etcdserver/metrics.go:212 +0x35e go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).Start.func3() /home/runner/work/etcd/etcd/server/etcdserver/server.go:530 +0x36 go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).GoAttach.func1() /home/runner/work/etcd/etcd/server/etcdserver/server.go:2403 +0x64 created by go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).GoAttach /home/runner/work/etcd/etcd/server/etcdserver/server.go:2401 +0x117 goroutine 14859 [select]: go.etcd.io/etcd/client/v3/leasing.(*leaseCache).clearOldRevokes(0xc0006ac238, {0x10a4830, 0xc000118f80}) /home/runner/work/etcd/etcd/client/v3/leasing/cache.go:253 +0xb9 go.etcd.io/etcd/client/v3/leasing.NewKV.func2() /home/runner/work/etcd/etcd/client/v3/leasing/kv.go:75 +0x6a created by go.etcd.io/etcd/client/v3/leasing.NewKV /home/runner/work/etcd/etcd/client/v3/leasing/kv.go:73 +0x27f goroutine 14939 [select, 14 minutes]: go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).purgeFile(0xc0004b3c00) /home/runner/work/etcd/etcd/server/etcdserver/server.go:606 +0x3aa go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).GoAttach.func1() /home/runner/work/etcd/etcd/server/etcdserver/server.go:2403 +0x64 created by go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).GoAttach /home/runner/work/etcd/etcd/server/etcdserver/server.go:2401 +0x117 goroutine 14950 [IO wait, 14 minutes]: internal/poll.runtime_pollWait(0x7f991c7501e0, 0x72) /opt/hostedtoolcache/go/1.17.8/x64/src/runtime/netpoll.go:234 +0x89 internal/poll.(*pollDesc).wait(0xc000fa0780, 0x0, 0x0) /opt/hostedtoolcache/go/1.17.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x32 internal/poll.(*pollDesc).waitRead(...) /opt/hostedtoolcache/go/1.17.8/x64/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Accept(0xc000fa0780) /opt/hostedtoolcache/go/1.17.8/x64/src/internal/poll/fd_unix.go:402 +0x22c net.(*netFD).accept(0xc000fa0780) /opt/hostedtoolcache/go/1.17.8/x64/src/net/fd_unix.go:173 +0x35 net.(*UnixListener).accept(0x0) /opt/hostedtoolcache/go/1.17.8/x64/src/net/unixsock_posix.go:167 +0x1c net.(*UnixListener).Accept(0xc000acce10) /opt/hostedtoolcache/go/1.17.8/x64/src/net/unixsock.go:260 +0x3d github.com/soheilhy/cmux.(*cMux).Serve(0xc001bde230) /home/runner/go/pkg/mod/github.com/soheilhy/cmux@v0.1.5/cmux.go:170 +0xa9 go.etcd.io/etcd/tests/v3/framework/integration.(*Member).Launch.func2() /home/runner/work/etcd/etcd/tests/framework/integration/cluster.go:984 +0x5d created by go.etcd.io/etcd/tests/v3/framework/integration.(*Member).Launch /home/runner/work/etcd/etcd/tests/framework/integration/cluster.go:982 +0xe68 goroutine 14899 [select, 14 minutes]: google.golang.org/grpc.(*pickerWrapper).pick(0xc000accf60, {0x10a48d8, 0xc000e08540}, 0x0, {{0xf476b3, 0x0}, {0x10a48d8, 0xc000e08540}}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/picker_wrapper.go:103 +0x21b google.golang.org/grpc.(*ClientConn).getTransport(0x26, {0x10a48d8, 0xc000e08540}, 0x68, {0xf476b3, 0xf476b3}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/clientconn.go:929 +0x35 google.golang.org/grpc.(*csAttempt).getTransport(0xc0006ac0b0) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:430 +0x48 google.golang.org/grpc.newClientStreamWithParams.func2(0xc0006ac0b0) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:315 +0x2b google.golang.org/grpc.(*clientStream).withRetry(0xc00040e000, 0xc0006d8350, 0xc0005acb20) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:709 +0xd3 google.golang.org/grpc.newClientStreamWithParams({0x10a48d8, 0xc000e08390}, 0x17b7260, 0xc000259c00, {0xf476b3, 0x7e6700}, {0x0, 0x0, 0x0, 0x0, ...}, ...) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:327 +0x9ce google.golang.org/grpc.newClientStream.func2({0x10a48d8, 0xc000e08390}, 0xc000e08390) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:192 +0x9f google.golang.org/grpc.newClientStream({0x10a48d8, 0xc000e08390}, 0x17b7260, 0xc000259c00, {0xf476b3, 0xc0005acd10}, {0xc000362080, 0x3, 0x4}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/stream.go:220 +0x4bf google.golang.org/grpc.invoke({0x10a48d8, 0xc000e08390}, {0xf476b3, 0x203000}, {0xefafa0, 0xc0004a0230}, {0xefb100, 0xc0006ee9b0}, 0x0, {0xc000362080, ...}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/call.go:66 +0x7d go.etcd.io/etcd/client/v3.(*Client).unaryClientInterceptor.func1({0x10a4868, 0xc0000c0008}, {0xf476b3, 0x14}, {0xefafa0, 0xc0004a0230}, {0xefb100, 0xc0006ee9b0}, 0xc000259c00, 0xf8abb8, ...) /home/runner/work/etcd/etcd/client/v3/retry_interceptor.go:60 +0x50a google.golang.org/grpc.(*ClientConn).Invoke(0x40f0f4, {0x10a4868, 0xc0000c0008}, {0xf476b3, 0xa0ab40}, {0xefafa0, 0xc0004a0230}, {0xefb100, 0xc0006ee9b0}, {0x17b7c80, ...}) /home/runner/go/pkg/mod/google.golang.org/grpc@v1.47.0/call.go:35 +0x223 go.etcd.io/etcd/api/v3/etcdserverpb.(*kVClient).Txn(0xc000b88060, {0x10a4868, 0xc0000c0008}, 0x40f447, {0x17b7c80, 0x3, 0x3}) /home/runner/work/etcd/etcd/api/etcdserverpb/rpc.pb.go:6528 +0xc9 go.etcd.io/etcd/client/v3.(*retryKVClient).Txn(0x0, {0x10a4868, 0xc0000c0008}, 0x0, {0x17b7c80, 0x0, 0x0}) /home/runner/work/etcd/etcd/client/v3/retry.go:117 +0x30 go.etcd.io/etcd/client/v3.(*txn).Commit(0xc000b32000) /home/runner/work/etcd/etcd/client/v3/txn.go:146 +0x[158](https://github.com/etcd-io/etcd/actions/runs/3071777532/jobs/4963526956#step:5:159) go.etcd.io/etcd/client/v3/leasing.(*leasingKV).acquire(_, {_, _}, {_, _}, {0x1, {0xc000b28a98, 0x3, 0x8}, {0x0, ...}, ...}) /home/runner/work/etcd/etcd/client/v3/leasing/kv.go:275 +0x66b go.etcd.io/etcd/client/v3/leasing.(*leasingKV).get(_, {_, _}, {0x1, {0xc000b28a88, 0x3, 0x8}, {0x0, 0x0, 0x0}, ...}) /home/runner/work/etcd/etcd/client/v3/leasing/kv.go:317 +0x1e5 go.etcd.io/etcd/client/v3/leasing.(*leasingKV).Get(0xf38819, {0x10a4868, 0xc0000c0008}, {0xc000b28a85, 0x1}, {0x0, 0xc0010a854d, 0x474}) /home/runner/work/etcd/etcd/client/v3/leasing/kv.go:86 +0xd0 go.etcd.io/etcd/tests/v3/integration/clientv3/lease_test.TestLeasingReconnectNonOwnerGet(0xc00086e000) /home/runner/work/etcd/etcd/tests/integration/clientv3/lease/leasing_test.go:1715 +0x416 testing.tRunner(0xc00086e000, 0xf8a828) /opt/hostedtoolcache/go/1.17.8/x64/src/testing/testing.go:1259 +0x102 created by testing.(*T).Run /opt/hostedtoolcache/go/1.17.8/x64/src/testing/testing.go:1306 +0x35a goroutine 14947 [select]: go.etcd.io/etcd/server/v3/etcdserver/api/v3rpc.monitorLeader.func1() /home/runner/work/etcd/etcd/server/etcdserver/api/v3rpc/interceptor.go:322 +0xc5 go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).GoAttach.func1() /home/runner/work/etcd/etcd/server/etcdserver/server.go:2403 +0x64 created by go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).GoAttach /home/runner/work/etcd/etcd/server/etcdserver/server.go:2401 +0x117 goroutine 14931 [select]: go.etcd.io/etcd/server/v3/storage/mvcc.(*watchableStore).syncWatchersLoop(0xc000cc00a0) /home/runner/work/etcd/etcd/server/storage/mvcc/watchable_store.go:233 +0x1ab created by go.etcd.io/etcd/server/v3/storage/mvcc.newWatchableStore /home/runner/work/etcd/etcd/server/storage/mvcc/watchable_store.go:95 +0x5cf goroutine 14949 [select, 14 minutes]: github.com/soheilhy/cmux.muxListener.Accept({{0x1099f68, 0xc00155f080}, 0xc0004e63c0, 0xc000424840}) /home/runner/go/pkg/mod/github.com/soheilhy/cmux@v0.1.5/cmux.go:262 +0x7f net/http.(*Server).Serve(0xc000143180, {0x109b2e8, 0xc00[170](https://github.com/etcd-io/etcd/actions/runs/3071777532/jobs/4963526956#step:5:171)a3e0}) /opt/hostedtoolcache/go/1.17.8/x64/src/net/http/server.go:3002 +0x394 net/http/httptest.(*Server).goServe.func1() /opt/hostedtoolcache/go/1.17.8/x64/src/net/http/httptest/server.go:308 +0x6a created by net/http/httptest.(*Server).goServe /opt/hostedtoolcache/go/1.17.8/x64/src/net/http/httptest/server.go:306 +0x6f goroutine 14909 [select, 14 minutes]: go.etcd.io/etcd/pkg/v3/schedule.(*fifo).run(0xc0004a04d0) /home/runner/work/etcd/etcd/pkg/schedule/schedule.go:[173](https://github.com/etcd-io/etcd/actions/runs/3071777532/jobs/4963526956#step:5:174) +0x193 created by go.etcd.io/etcd/pkg/v3/schedule.NewFIFOScheduler /home/runner/work/etcd/etcd/pkg/schedule/schedule.go:101 +0x[188](https://github.com/etcd-io/etcd/actions/runs/3071777532/jobs/4963526956#step:5:189)
No response
The text was updated successfully, but these errors were encountered:
another data point https://github.com/etcd-io/etcd/actions/runs/3108126683/jobs/5036981692
Sorry, something went wrong.
@serathius @ahrtr it is related to grpc issue fixed by grpc/grpc-go#5714. Is it possible to bump to new grpc version when it is ready?
Successfully merging a pull request may close this issue.
Which github workflows are flaking?
test (linux-amd64-integration-4-cpu)
Which tests are flaking?
TestLeasingReconnectNonOwnerGet
Github Action link
https://github.com/etcd-io/etcd/actions/runs/3071777532/jobs/4963526956
Reason for failure (if possible)
Anything else we need to know?
No response
The text was updated successfully, but these errors were encountered: