DeadlineExceeded in 2.10.2

[hamishforbes]

Describe the bug

I'm getting a constant low level of DeadlineExceeded errors from the distributor after upgrading from 2.10.1 to 2.10.2.
Reverting to 2.10.1 fixes this, no other changes.

To Reproduce

Upgrade to 2.10.2

Expected behavior

No errors!

Environment

• Infrastructure: Kubernetes
• Deployment tool: Jsonnet

My setup is
Vanilla Prometheus remote write -> Envoy as an HTTP gateway/load balancer -> Distributors

Additional Context

The same issue presented in 2 environments for me and both were resolved by reverting to 2.10.1

Logs:

ts=2023-10-16T01:52:11.72323819Z caller=logging.go:126 level=warn traceID=544e742c02a21389 msg="POST /api/v1/push (500) 2.122306606s Response: \"failed pushing to ingester: rpc error: code = DeadlineExceeded desc = context deadline exceeded\\n\" ws: false; Content-Encoding: snappy; Content-Length: 126508; Content-Type: application/x-protobuf; User-Agent: Prometheus/2.47.1; X-Envoy-Expected-Rq-Timeout-Ms: 15000; X-Forwarded-Proto: http; X-Prometheus-Remote-Write-Version: 0.1.0; X-Request-Id: 27e07fcf-c5fd-4eff-b683-e79aa2e89540; X-Scope-Orgid: core; " |  

From the Mimir / Writes dash

[langerma]

i have the same problem with grafana-agent.

[sviatlo]

We had exactly same issue on k8s, deployed with helm. I think it is related to this PR and the issue was seen in integration tests.

[czhfe]

I'm having the same problem.

[trexx]

I've also rolled back, however the issue wasn't resolved until all the ingesters were slowly rolled back. They take a very long time to terminate and then to replay the wal.

[beatkind]

We are seeing the same issue here

[bboreham]

FWIW we did not see these errors when the code was rolled out at Grafana Labs.
We don't have a lot to go on to debug what you are seeing. More detail would be helpful, e.g. a grab of more of the 'writes' dashboard showing ingesters too, and 'writes resources' at the time of the problem.

They take a very long time to terminate and then to replay the wal.

Consider "zone-aware replication" which lets you take down a third of ingesters at a time.
https://github.com/grafana/mimir/blob/main/docs/sources/mimir/configure/configure-zone-aware-replication.md

EDIT: Apologies, I did not understand when I wrote the above that "long time to terminate" is a new symptom of the bug.

[chewrocca]

Experiencing the same issue after upgrading to 2.10.2.

The Prometheus Agents send a lot of these two warnings 10-15 mins after the upgrade before remote writes stop altogether. The vast majority of the warnings are the "use of closed network connection."

ts=2023-10-17T14:22:29.012Z caller=dedupe.go:112 component=remote level=warn remote_name=mimir-distributor.dev.silabs.net url=http://127.0.0.1:8080/api/v1/push msg="Failed to send batch, retrying" err="server returned HTTP status 500 Internal Server Error: failed pushing to ingester: rpc error: code = DeadlineExceeded desc = context deadline exceeded"

and

ts=2023-10-17T14:22:27.016Z caller=dedupe.go:112 component=remote level=warn remote_name=mimir-distributor.dev.silabs.net url=http://127.0.0.1:8080/api/v1/push msg="Failed to send batch, retrying" err="server returned HTTP status 500 Internal Server Error: failed pushing to ingester: rpc error: code = Unavailable desc = error reading from server: read tcp 172.26.64.126:34612->10.51.157.201:22240: use of closed network connection"

[ying-jeanne]

@hamishforbes what is your setting for server.grpc-max-concurrent-streams? the default value is 100 if you didn't set it before, could you try to set it higher let's say 500 and see whether it solved problem. I think the problem comes from this commit grpc/grpc-go@6a1400d

[ZeidAqemia]

@hamishforbes what is your setting for server.grpc-max-concurrent-streams? the default value is 100 if you didn't set it before, could you try to set it higher let's say 500 and see whether it solved problem. I think the problem comes from this commit grpc/grpc-go@6a1400d

Mine is set to 1000

Here are few more graphs
https://grafana.slack.com/archives/C039863E8P7/p1697555754641479

[ying-jeanne]

@ZeidAqemia, have you considered setting server.grpc-max-concurrent-streams to 0 as a test? This could help us pinpoint the root cause of the issue.

[ZeidAqemia]

@ZeidAqemia, have you considered setting server.grpc-max-concurrent-streams to 0 as a test? This could help us pinpoint the root cause of the issue.

I applied the change and I'm rotating out the ingesters. I'll report back when it's done.

[ZeidAqemia]

First ingester removed at 16:41 and last one at 16:54.

• Inflights connections are back to normal levels.
• TCP connections on the Ingester went from 25-30 back to 8.
• Latency seems gone
• Ruler errors are gone too

[bboreham]

I believe we have tracked the underlying problem to a bad backport in grpc-go.
grpc/grpc-go#6737

We'll do some more testing and, if it checks out, issue a new release.