TSM fanout waits until client timeout and returns 502 when some members return non-2xx responses

[tonychoe]

Disclaimer: Used AI agent to diagnose the issue and write this report

Summary

With Trickster 2.0.4 (91f547433698f221094e03def7d9503c49d9d358), a TSM ALB query can wait until the caller’s timeout and return 502 when the fanout contains a mix of successful and non-2xx downstream responses.

The same PromQL succeeds when sent directly to healthy pool members. Downstream responses complete quickly, indicating that most of the delay occurs in Trickster’s fanout/gather path.

Setup

• Trickster 2.0.4
• Prometheus-compatible TSM ALB
• Instant PromQL query
• Large multi-backend pool
• Mixed downstream results, including HTTP 200 and HTTP 401

Observed behavior

• The TSM request produces no response headers before the client’s 90-second timeout.

• The caller receives 502.

• (CORRECTION: please disregard this line which was my mistake in testing) In one reproduction, a failing member returned HTTP 401 with no org id in approximately 0.2 seconds, while a working member returned HTTP 200 in approximately 0.34 seconds.

• Despite these downstream responses completing quickly, the TSM request waited until the client timeout.

• Representative Trickster logs include:

  • vector unmarshaling error
  • tsm gather merge failure: no timerange query
  • tsm gather failed due to nil func

Expected behavior

A failed or non-2xx pool member should not hold the entire TSM request until the client deadline.

If at least one member returns usable data, Trickster should return a bounded partial response with warnings. If no member contributes usable data, it should return an error promptly.

Related issue

This appears related to #1040 / #1041, but that fix is already included in the tested commit and seems focused on proxy-only/cache-range responses. The remaining case appears to involve instant queries with mixed successful and non-2xx member responses.

[houyuwushang]

@tonychoe I authored #1035 and #1041, so I followed up on this to check whether it could be a regression from those changes. I couldn't reproduce the delay from mixed statuses alone: a 64-member fanout with one usable 200 and the remaining members returning 401, including one that reaches the no timerange query merge error, returned partial data immediately. Those merge warnings are emitted after the member handlers return, so they don't account for the 90-second wait by themselves.

Could you confirm whether every pool member completed before the caller timed out, rather than only the representative 200/401 requests in the report? Per-member completion times and the configured backend timeout would help narrow this down. It would also be useful to know whether the final 502 was written by Trickster or generated by the caller/gateway after 90 seconds. A sanitized TSM backend/pool config and the exact request path/query parameters should make the setup reproducible.

[houyuwushang]

I can reproduce the timeout shape with shortened timeouts now, but only when one pool member remains in flight. On 91f5474, a 64-member config with one 200 response at about 340ms and 63 401 responses at about 200ms returns 200/phit in about 635ms. Replacing one of those 401s with a member that never completes makes TSM wait for it; with a 5s backend timeout and a 700ms outer timeout, the outer caller generates a 502 at about 703ms and the response has no X-Trickster-Result.

The same caller-timeout behavior is present at 3d60092, before #1035 and #1041. The no timerange query warning appears with #1041's body fallback, but the wait itself predates both changes.

There is also a cancellation gap after the caller disconnects: the OPC/DPC request clones detach the fanout context, so the unfinished origin request continues until its backend timeout. I have a local patch that preserves cancellation only for ALB fanout, and the same setup then cancels the origin promptly. That does not remove the need to identify the still-running member or keep the backend timeout below the caller timeout. @jranson, if you are not already changing that cancellation path, I can send the patch.

[tonychoe]

@houyuwushang, thanks. We repeated the test using the same panel query and a fixed evaluation time.

Through Grafana, the request timed out after 90.54 seconds. Grafana returned HTTP 400 containing a datasource error with status 502:

context deadline exceeded (Client.Timeout exceeded while awaiting headers)

We did not capture an HTTP 502 response directly from Trickster.

We then replayed the same query against all 64 admitted pool members individually through Trickster:

• 28 returned HTTP 200
• (CORRECTION: please disregard this line which was my mistake in testing) 36 returned HTTP 401
• All 64 completed in 0.13–2.01 seconds

We also sent the aggregate query directly to Trickster. It returned HTTP 200 in 7.14 seconds with:

X-Trickster-Result: engine=ObjectProxyCache; status=phit

The response contained the expected result and 36 warnings.

So the query and the combination of 200 and 401 responses do not consistently reproduce the failure. Since the individual replay happened afterward, we cannot tell whether one member was still in flight during the failed request.

Based on your reproduction, it sounds like the context handling you found could explain what we saw, but please let us know if you think these results point somewhere else or if another test would be useful.

[tonychoe]

Quick correction to my previous comment:

In our follow-up reproduction test, we bypassed Grafana and called Trickster directly. That test did not include the X-Scope-OrgID header used by the Grafana datasource, which caused the 36 401 no org id responses. Please disregard the earlier 28/36 split and partial-response result. Sorry about that.

We reran the reproduction test with the header included. We called each of the 64 admitted pool members individually through Trickster, and all returned HTTP 200 within 0.12–4.89 seconds.

We then called the aggregate Trickster endpoint with the same query, time, and header. It timed out after 100 seconds without returning headers or a body. We ran it twice and got the same result.

So the problem reproduces in Trickster’s aggregate fanout path, not from the mix of 200 and 401 responses. We also did not receive a direct 502 from Trickster—the HTTP test client timed out without receiving a response.

Does this match the context-handling issue you found?

[houyuwushang]

Not quite. The corrected result confirms that the delay is in the aggregate path, but the context gap I found only affects what happens after the caller disconnects. It can leave in-flight origin work running after the 100-second timeout; it does not by itself explain why the aggregate request has not responded during those 100 seconds.

One thing worth checking first is fanout queueing. TSM defaults query_concurrency_limit to GOMAXPROCS and waits for every member. With 64 members, a limit of 1 or 2 can push the aggregate past 100 seconds even when each member completes in 0.12–4.89 seconds when called alone. What are the effective GOMAXPROCS, query_concurrency_limit, and query_concurrency_multiplier values? A controlled rerun with a higher query concurrency limit would distinguish queueing from a member blocked inside the aggregate request. If it still hangs, a goroutine dump taken while it is stuck would be the next useful artifact.

[keithshum]

Hi @houyuwushang , thanks for your explanation, here is Production environment:

GOMAXPROCS: Unset, defaults to 8.
query_concurrency_limit: Unset, defaults to GOMAXPROCS which is 8 also.
query_concurrency_multiplier: Unset, defaults to 1? What is query_concurrency_multiplier for any way?

We have node pool for Trickster exclusively:
Node config: 4 ocpu x 32 GB ram (1 ocpu = 2 vcpu)
1 node for 1 Trickster app, 9 nodes totally.

How would you suggest the configs tryout for query_concurrency_limit and query_concurrency_multiplier? Any guideline we can go with?

[keithshum]

(Con't)
We have 2 large TSM pools, both with 66 members (Mimir backends).