Robustness tests get stuck on grpc client read

[serathius]

Which github workflows are flaking?

TestRobustness

Which tests are flaking?

TestRobustness/Etcd/HighTraffic/ClusterOfSize3

Github Action link

https://github.com/etcd-io/etcd/actions/runs/6833893382/job/18586105428

Reason for failure (if possible)

Robustness tests assign 40 ms context timeout for each request, still some requests can get stuck on some grpc internals for 2 minutes

2023-11-11T14:38:24.9386801Z goroutine 775424 [select, 2 minutes]:
2023-11-11T14:38:24.9387340Z google.golang.org/grpc.(*pickerWrapper).pick(0xc0005ab400, {0x1038f38, 0xc00087f110}, 0x0, {{0xed8c6f?, 0xc001845590?}, {0x1038f38?, 0xc00087f110?}})
2023-11-11T14:38:24.9387755Z    /home/runner/go/pkg/mod/google.golang.org/grpc@v1.59.0/picker_wrapper.go:119 +0x205
2023-11-11T14:38:24.9388208Z google.golang.org/grpc.(*ClientConn).getTransport(0x456026?, {0x1038f38?, 0xc00087f110?}, 0xb0?, {0xed8c6f?, 0xc0003e1830?})
2023-11-11T14:38:24.9388536Z    /home/runner/go/pkg/mod/google.golang.org/grpc@v1.59.0/clientconn.go:1177 +0x2f
2023-11-11T14:38:24.9388751Z google.golang.org/grpc.(*csAttempt).getTransport(0xc00010eb60)
2023-11-11T14:38:24.9389047Z    /home/runner/go/pkg/mod/google.golang.org/grpc@v1.59.0/stream.go:466 +0x45
2023-11-11T14:38:24.9389314Z google.golang.org/grpc.newClientStreamWithParams.func2(0xc00010eb60)
2023-11-11T14:38:24.9389599Z    /home/runner/go/pkg/mod/google.golang.org/grpc@v1.59.0/stream.go:349 +0x25
2023-11-11T14:38:24.9389985Z google.golang.org/grpc.(*clientStream).withRetry(0xc000658000, 0xc0003e1820, 0xc001b249a0)
2023-11-11T14:38:24.9390291Z    /home/runner/go/pkg/mod/google.golang.org/grpc@v1.59.0/stream.go:776 +0x13a
2023-11-11T14:38:24.9390924Z google.golang.org/grpc.newClientStreamWithParams({0x1038f38, 0xc00087eff0}, 0x16ebea0, 0xc000100400, {0xed8c6f, 0x16}, {0x0, 0x0, 0x0, 0x0, ...}, ...)
2023-11-11T14:38:24.9391227Z    /home/runner/go/pkg/mod/google.golang.org/grpc@v1.59.0/stream.go:361 +0xc05
2023-11-11T14:38:24.9391810Z google.golang.org/grpc.newClientStream.func3({0x1038f38?, 0xc00087eff0?}, 0xc00087eff0?)
2023-11-11T14:38:24.9392107Z    /home/runner/go/pkg/mod/google.golang.org/grpc@v1.59.0/stream.go:218 +0x8a
2023-11-11T14:38:24.9392608Z google.golang.org/grpc.newClientStream({0x1038f38, 0xc00087eff0}, 0x16ebea0, 0xc000100400, {0xed8c6f, 0x16}, {0xc001320440, 0x3, 0xff?})
2023-11-11T14:38:24.9392917Z    /home/runner/go/pkg/mod/google.golang.org/grpc@v1.59.0/stream.go:253 +0x7a3
2023-11-11T14:38:24.9393504Z google.golang.org/grpc.invoke({0x1038f38?, 0xc00087eff0?}, {0xed8c6f?, 0x7fcc6411acf8?}, {0xea42c0, 0xc0004415f0}, {0xe8d180, 0xc001845450}, 0x3?, {0xc001320440, ...})
2023-11-11T14:38:24.9393800Z    /home/runner/go/pkg/mod/google.golang.org/grpc@v1.59.0/call.go:66 +0x77
2023-11-11T14:38:24.9394494Z go.etcd.io/etcd/client/v3.(*Client).unaryClientInterceptor.func1({0x1038ec8?, 0x171de20?}, {0xed8c6f, 0x16}, {0xea42c0, 0xc0004415f0}, {0xe8d180, 0xc001845450}, 0xc000100400, 0xf44600, ...)
2023-11-11T14:38:24.9394782Z    /home/runner/work/etcd/etcd/client/v3/retry_interceptor.go:61 +0x6e4
2023-11-11T14:38:24.9395400Z google.golang.org/grpc.(*ClientConn).Invoke(0xc000100400, {0x1038ec8?, 0x171de20?}, {0xed8c6f?, 0x6?}, {0xea42c0?, 0xc0004415f0?}, {0xe8d180?, 0xc001845450?}, {0xc000f3d320, ...})
2023-11-11T14:38:24.9395694Z    /home/runner/go/pkg/mod/google.golang.org/grpc@v1.59.0/call.go:35 +0x205
2023-11-11T14:38:24.9396178Z go.etcd.io/etcd/api/v3/etcdserverpb.(*kVClient).Range(0xc000408048, {0x1038ec8, 0x171de20}, 0x90?, {0xc000f3d320, 0x4, 0x6})
2023-11-11T14:38:24.9396549Z    /home/runner/work/etcd/etcd/api/etcdserverpb/rpc.pb.go:6517 +0xc5
2023-11-11T14:38:24.9397068Z go.etcd.io/etcd/client/v3.(*retryKVClient).Range(0xc00050adf0, {0x1038ec8, 0x171de20}, 0xc001b254b8?, {0x16ec860, 0x666c726677736d69?, 0x3})
2023-11-11T14:38:24.9397285Z    /home/runner/work/etcd/etcd/client/v3/retry.go:105 +0x10d
2023-11-11T14:38:24.9397653Z go.etcd.io/etcd/client/v3.(*kv).Do(_, {_, _}, {0x1, {0xc001825240, 0x3, 0x8}, {0xc001825248, 0x3, 0x8}, ...})
2023-11-11T14:38:24.9397846Z    /home/runner/work/etcd/etcd/client/v3/kv.go:151 +0x2a9
2023-11-11T14:38:24.9398360Z go.etcd.io/etcd/client/v3.(*kv).Get(0x171de20?, {0x1038ec8, 0x171de20}, {0xec664c?, 0xd56b00?}, {0xc0004d0438?, 0x262577e?, 0xc14bfb37664e69ec?})
2023-11-11T14:38:24.9398550Z    /home/runner/work/etcd/etcd/client/v3/kv.go:120 +0xb2
2023-11-11T14:38:24.9399161Z go.etcd.io/etcd/tests/v3/robustness/traffic.(*RecordingClient).Range(0xc00045a240, {0x1038ec8, 0x171de20}, {0xec664c, 0x3}, {0xc001825233, 0x3}, 0x0, 0x0)
2023-11-11T14:38:24.9399478Z    /home/runner/work/etcd/etcd/tests/robustness/traffic/client.go:109 +0x48e
2023-11-11T14:38:24.9400166Z go.etcd.io/etcd/tests/v3/robustness/traffic.etcdTrafficClient.Request({{0xa, {0x16dabe0, 0x7, 0x7}, 0x1c20, 0x8001}, {0xec664c, 0x3}, 0xc00045a240, 0xc00b975d10, ...}, ...)
2023-11-11T14:38:24.9400547Z    /home/runner/work/etcd/etcd/tests/robustness/traffic/etcd.go:172 +0xfab
2023-11-11T14:38:24.9401205Z go.etcd.io/etcd/tests/v3/robustness/traffic.etcdTraffic.Run({0xa, {0x16dabe0, 0x7, 0x7}, 0x1c20, 0x8001}, {0x1038ec8, 0x171de20}, 0x452f746c75616665?, 0xc00b975d10, ...)
2023-11-11T14:38:24.9401502Z    /home/runner/work/etcd/etcd/tests/robustness/traffic/etcd.go:127 +0x296
2023-11-11T14:38:24.9401828Z go.etcd.io/etcd/tests/v3/robustness/traffic.SimulateTraffic.func1(0xc00045a240)
2023-11-11T14:38:24.9402140Z    /home/runner/work/etcd/etcd/tests/robustness/traffic/traffic.go:79 +0x117
2023-11-11T14:38:24.9402509Z created by go.etcd.io/etcd/tests/v3/robustness/traffic.SimulateTraffic in goroutine 775297
2023-11-11T14:38:24.9402897Z    /home/runner/work/etcd/etcd/tests/robustness/traffic/traffic.go:75 +0x2e5

Anything else we need to know?

No response

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed after 21 days if no further activity occurs. Thank you for your contributions.