store-gateway: add timeout to query gate wait #7777

dimitarvdimitrov · 2024-04-02T18:21:31Z

What this PR does

This PR adds a timeout to query gate waiting. The store-gateway returns an empty response. The querier treats the empty response as if the blocks weren't discovered by the store-gateway and tries them again on another store-gateway.

Which issue(s) this PR fixes or relates to

Fixes #

Checklist

Tests updated.
Documentation added.
CHANGELOG.md updated - the order of entries should be [CHANGE], [FEATURE], [ENHANCEMENT], [BUGFIX].
about-versioning.md updated with experimental features.

CHANGELOG.md

pkg/storage/tsdb/config.go

charleskorn · 2024-04-02T23:33:40Z

pkg/storegateway/bucket.go

@@ -611,6 +611,11 @@ func (s *BucketStore) Series(req *storepb.SeriesRequest, srv storegatewaypb.Stor
 	// but sometimes it can take minutes if the block isn't loaded and there is a surge in queries for unloaded blocks.
 	done, err := s.limitConcurrentQueries(ctx, stats)
 	if err != nil {
+		if errors.Is(err, errGateTimeout) {


If a timeout occurs here, should we add an event to the trace span or log something?

It might also be useful to add a metric for the number of queries that were rejected due to the gate timing out - a high rate of this indicates either a performance problem or suggests scaling out store-gateways would be useful.

It might also be useful to add a metric for the number of queries that were rejected due to the gate timing out - a high rate of this indicates either a performance problem or suggests scaling out store-gateways would be useful.

A metric has been added directly in dskit:
grafana/dskit#512

It doesn't tell exactly the reason why the gate wasn't allowed tho.

If a timeout occurs here, should we add an event to the trace span or log something?

good idea. I will add a span log

It doesn't tell exactly the reason why the gate wasn't allowed tho.

with the current setup a query can be "not_permitted" either because it was cancelled (context.Canceled) or because it timed out (context.DeadlineExceeded). I can add this distinction in the metrics. There's also the response metrics of the gRPC method calls which would record status_code="Canceled" or status_code="OK", but it might be more clear to have this separation in the dskit metrics

charleskorn · 2024-04-02T23:34:42Z

pkg/storegateway/bucket.go

@@ -611,6 +611,11 @@ func (s *BucketStore) Series(req *storepb.SeriesRequest, srv storegatewaypb.Stor
 	// but sometimes it can take minutes if the block isn't loaded and there is a surge in queries for unloaded blocks.
 	done, err := s.limitConcurrentQueries(ctx, stats)
 	if err != nil {
+		if errors.Is(err, errGateTimeout) {
+			// If the gate timed out, then we behave in the same way as if the blocks aren't discovered yet.
+			// The querier will try the blocks again on a different store-gateway replica.


How is this situation logged by queriers? (I'm wondering if we'll get a misleading or confusing message logged by queriers along the lines of "store-gateway hasn't discovered blocks", when the truth is that the store-gateway timed out the request.)

I have a similar concern here. Why not returning the error? The querier will retry the request on other store-gateways in case of error, unless it's detected as a non retriable error (but we make sure the error we return here is detected as retryable).

How is this situation logged by queriers?

this is the SpanLog that the querier logs

mimir/pkg/querier/blocks_store_queryable.go

Line 596 in fce7b38

spanLog.DebugLog("msg", "couldn't query all blocks", "attempt", attempt, "missing blocks", strings.Join(convertULIDsToString(remainingBlocks), " "))

If all of the store-gateways cannot query a block, then this is the error that the querier generates:

mimir/pkg/querier/blocks_store_queryable.go

Lines 600 to 601 in fce7b38

err = newStoreConsistencyCheckFailedError(remainingBlocks)

level.Warn(util_log.WithContext(ctx, spanLog)).Log("msg", "failed consistency check after all attempts", "err", err)

mimir/pkg/querier/blocks_store_queryable.go

Line 596 in fce7b38

spanLog.DebugLog("msg", "couldn't query all blocks", "attempt", attempt, "missing blocks", strings.Join(convertULIDsToString(remainingBlocks), " "))

Why not returning the error? The querier will retry the request on other store-gateways in case of error, unless it's detected as a non retriable error (but we make sure the error we return here is detected as retryable).

That's not the case unfortunately. If the store-gateway returns an error, then the querier will immediately abort the query:

mimir/pkg/querier/blocks_store_queryable.go

Lines 569 to 574 in fce7b38

// Fetch series from stores. If an error occur we do not retry because retries

// are only meant to cover missing blocks.

queriedBlocks, err := queryF(clients, minT, maxT)

if err != nil {

return err

}

I did consider returning a special error, but that seemed more complicated because of response processing in fetchSeriesFromStores. If you still think it's a better idea to have a special error and handle it properly, then I can do the necessary refactors; perhaps even adopt a similar error-handling pattern to the distributor-ingester ingestion error handling.

That's not the case unfortunately. If the store-gateway returns an error, then the querier will immediately abort the query:

I'm not sure about it. I think the "magic" is done by queryF. For example, look at fetchSeriesFromStores() implementation and its call to shouldStopQueryFunc(). I think the idea is that queryF only return a fatal error, while swallow errors that shouldn't stop the query execution.

you're right there is shouldStopQueryFunc

mimir/pkg/querier/blocks_store_queryable.go

Lines 755 to 760 in fce7b38

if shouldStopQueryFunc(err) {

return err

}

level.Warn(log).Log("msg", "failed to fetch series", "remote", c.RemoteAddress(), "err", err)

return nil

let me give it a try to add some error handling similar to distributor-ingester errors

this ended up being more complicated than i expected too. I opened a PR to prepare for this change #7790. I could have copied some code too, but wanted to move towards reducing code duplication

pkg/querier/blocks_store_queryable_test.go

pracucci

Overall LGTM, thanks. I'm not convinced by not returning an error from the store-gateway: to me, it looks more natural returning an error.

pracucci · 2024-04-03T06:59:02Z

pkg/storegateway/bucket_stores.go

@@ -420,6 +421,27 @@ func (u *BucketStores) syncDirForUser(userID string) string {
 	return filepath.Join(u.cfg.BucketStore.SyncDir, userID)
 }

+type timeoutGate struct {


[nit] Looks something we could have done in dskit. Non blocking.

i also realized this after submitting the PR. But dskit doesn't have context.WithTimeoutCause and implementing that isn't as trivial as I expected. Let's keep it here as the scope is very small anyways. Someone can move it to dskit when it's updated. I left a comment on timeoutGate 7bf6b24

pracucci · 2024-04-03T07:00:36Z

pkg/storegateway/bucket.go

@@ -611,6 +611,11 @@ func (s *BucketStore) Series(req *storepb.SeriesRequest, srv storegatewaypb.Stor
 	// but sometimes it can take minutes if the block isn't loaded and there is a surge in queries for unloaded blocks.
 	done, err := s.limitConcurrentQueries(ctx, stats)
 	if err != nil {
+		if errors.Is(err, errGateTimeout) {


It might also be useful to add a metric for the number of queries that were rejected due to the gate timing out - a high rate of this indicates either a performance problem or suggests scaling out store-gateways would be useful.

A metric has been added directly in dskit:
grafana/dskit#512

It doesn't tell exactly the reason why the gate wasn't allowed tho.

pracucci · 2024-04-03T07:03:01Z

pkg/storegateway/bucket.go

@@ -611,6 +611,11 @@ func (s *BucketStore) Series(req *storepb.SeriesRequest, srv storegatewaypb.Stor
 	// but sometimes it can take minutes if the block isn't loaded and there is a surge in queries for unloaded blocks.
 	done, err := s.limitConcurrentQueries(ctx, stats)
 	if err != nil {
+		if errors.Is(err, errGateTimeout) {
+			// If the gate timed out, then we behave in the same way as if the blocks aren't discovered yet.
+			// The querier will try the blocks again on a different store-gateway replica.


I have a similar concern here. Why not returning the error? The querier will retry the request on other store-gateways in case of error, unless it's detected as a non retriable error (but we make sure the error we return here is detected as retryable).

jdbaldry

configuration documentation lgtm

This PR adds a timeout to query gate waiting. The store-gateway returns an empty response. The querier treats the empty response as if the blocks weren't discovered by the store-gateway and tries them again on another store-gateway. Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Co-authored-by: Charles Korn <charleskorn@users.noreply.github.com>

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

…cy limit Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

…d_other Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

dimitarvdimitrov · 2024-05-03T12:06:58Z

pkg/querier/blocks_store_queryable_test.go

+		"should not stop query on store-gateway instance limit": {
+			err:      globalerror.NewErrorWithGRPCStatus(errors.New("instance limit"), codes.Aborted, &mimirpb.ErrorDetails{Cause: mimirpb.INSTANCE_LIMIT}),
+			expected: false,
+		},
+		"should not stop query on store-gateway instance limit; shouldn't look at the gRPC code, only Mimir error cause": {
+			err:      globalerror.NewErrorWithGRPCStatus(errors.New("instance limit"), codes.Internal, &mimirpb.ErrorDetails{Cause: mimirpb.INSTANCE_LIMIT}),
+			expected: false,
+		},
+		"should not stop query on any other mimirpb error": {
+			err:      globalerror.NewErrorWithGRPCStatus(errors.New("instance limit"), codes.Internal, &mimirpb.ErrorDetails{Cause: mimirpb.TOO_BUSY}),
+			expected: false,
+		},
+		"should not stop query on any unknown error detail": {
+			err: func() error {
+				st, createErr := status.New(codes.Internal, "test").WithDetails(&hintspb.Block{Id: "123"})
+				require.NoError(t, createErr)
+				return st.Err()
+			}(),
+			expected: false,
+		},
+		"should not stop query on multiple error details": {
+			err: func() error {
+				st, createErr := status.New(codes.Internal, "test").WithDetails(&hintspb.Block{Id: "123"}, &mimirpb.ErrorDetails{Cause: mimirpb.INSTANCE_LIMIT})
+				require.NoError(t, createErr)
+				return st.Err()
+			}(),
+			expected: false,
+		},


I didn't change the implementation, because that was the default behaviour anyways. But decided to add tests because the current behaviour is implicit rather than explicit.

pracucci

Very nice work, LGTM!

dimitarvdimitrov added the component/store-gateway label Apr 2, 2024

dimitarvdimitrov requested a review from a team as a code owner April 2, 2024 18:21

charleskorn reviewed Apr 2, 2024

View reviewed changes

pracucci self-requested a review April 3, 2024 06:53

pracucci approved these changes Apr 3, 2024

View reviewed changes

dimitarvdimitrov mentioned this pull request Apr 3, 2024

chore: move ErrorWithStatus to globalerror #7790

Merged

1 task

dimitarvdimitrov requested a review from jdbaldry as a code owner April 3, 2024 13:17

dimitarvdimitrov force-pushed the dimitar/st-gw/add-timeout-to-query-gate-waiting branch from d57ac54 to 2ae4e2b Compare April 3, 2024 13:19

jdbaldry approved these changes Apr 4, 2024

View reviewed changes

dimitarvdimitrov force-pushed the dimitar/st-gw/add-timeout-to-query-gate-waiting branch from 2ae4e2b to 13fad9e Compare May 3, 2024 08:26

dimitarvdimitrov and others added 9 commits May 3, 2024 10:26

Add CHANGELOG.md entry

87abd77

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Update pkg/storage/tsdb/config.go

63adee8

Co-authored-by: Charles Korn <charleskorn@users.noreply.github.com>

Update CHANGELOG.md

52d2596

Co-authored-by: Charles Korn <charleskorn@users.noreply.github.com>

Remote TODO

608b5a9

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Add a spanLog to timeoutGate

7a0d772

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Add comment on why timeoutGate is in Mimir

573ec0d

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Update docs

68a0024

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Propagate errors from store-gateway to querier when hitting concurren…

ed7012c

…cy limit Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

dimitarvdimitrov force-pushed the dimitar/st-gw/add-timeout-to-query-gate-waiting branch from 13fad9e to ed7012c Compare May 3, 2024 08:27

dimitarvdimitrov added 6 commits May 3, 2024 10:36

Fix formatting

f09508c

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Update autogenerated config

523f26a

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Add license header

28b00ff

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Add tests for timeoutGate

375a044

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Report timeoutGate timeouts as rejected_deadline_exceeded not rejecte…

413a415

…d_other Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

Properly detect custom errors in timeoutGate

df43e5f

Signed-off-by: Dimitar Dimitrov <dimitar.dimitrov@grafana.com>

dimitarvdimitrov force-pushed the dimitar/st-gw/add-timeout-to-query-gate-waiting branch from 816718d to df43e5f Compare May 3, 2024 11:11

dimitarvdimitrov commented May 3, 2024

View reviewed changes

pracucci approved these changes May 3, 2024

View reviewed changes

dimitarvdimitrov merged commit 61a1c8b into main May 3, 2024
29 checks passed

dimitarvdimitrov deleted the dimitar/st-gw/add-timeout-to-query-gate-waiting branch May 3, 2024 12:24

This was referenced May 14, 2024

store-gateway: add timeout to index-header loading #8137

Closed

store-gateway: Add timeout for index-header loading gate #8138

Merged

charleskorn mentioned this pull request May 16, 2024

Fix race between timeout gate timing out and delegated gate returning successfully #8149

Merged

2 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

store-gateway: add timeout to query gate wait #7777

store-gateway: add timeout to query gate wait #7777

dimitarvdimitrov commented Apr 2, 2024

charleskorn Apr 2, 2024

pracucci Apr 3, 2024

dimitarvdimitrov Apr 3, 2024

charleskorn Apr 2, 2024

pracucci Apr 3, 2024

dimitarvdimitrov Apr 3, 2024

pracucci Apr 3, 2024

dimitarvdimitrov Apr 3, 2024

dimitarvdimitrov Apr 3, 2024

pracucci left a comment

pracucci Apr 3, 2024

dimitarvdimitrov Apr 3, 2024

pracucci Apr 3, 2024

pracucci Apr 3, 2024

jdbaldry left a comment

dimitarvdimitrov May 3, 2024

pracucci left a comment

	err = newStoreConsistencyCheckFailedError(remainingBlocks)
	level.Warn(util_log.WithContext(ctx, spanLog)).Log("msg", "failed consistency check after all attempts", "err", err)

	// Fetch series from stores. If an error occur we do not retry because retries
	// are only meant to cover missing blocks.
	queriedBlocks, err := queryF(clients, minT, maxT)
	if err != nil {
	return err
	}

	if shouldStopQueryFunc(err) {
	return err
	}

	level.Warn(log).Log("msg", "failed to fetch series", "remote", c.RemoteAddress(), "err", err)
	return nil

store-gateway: add timeout to query gate wait #7777

store-gateway: add timeout to query gate wait #7777

Conversation

dimitarvdimitrov commented Apr 2, 2024

What this PR does

Which issue(s) this PR fixes or relates to

Checklist

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

pracucci left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jdbaldry left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

pracucci left a comment

Choose a reason for hiding this comment