diff --git a/platform/base/messagequeue/BUILD.bazel b/platform/base/messagequeue/BUILD.bazel index a163d617a..97b4f74aa 100644 --- a/platform/base/messagequeue/BUILD.bazel +++ b/platform/base/messagequeue/BUILD.bazel @@ -2,14 +2,20 @@ load("@rules_go//go:def.bzl", "go_library", "go_test") go_library( name = "go_default_library", - srcs = ["message.go"], + srcs = [ + "context.go", + "message.go", + ], importpath = "github.com/uber/submitqueue/platform/base/messagequeue", visibility = ["//visibility:public"], ) go_test( name = "go_default_test", - srcs = ["message_test.go"], + srcs = [ + "context_test.go", + "message_test.go", + ], embed = [":go_default_library"], deps = ["@com_github_stretchr_testify//assert:go_default_library"], ) diff --git a/platform/base/messagequeue/context.go b/platform/base/messagequeue/context.go new file mode 100644 index 000000000..a29fb3403 --- /dev/null +++ b/platform/base/messagequeue/context.go @@ -0,0 +1,38 @@ +// Copyright (c) 2025 Uber Technologies, Inc. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package messagequeue + +import ( + "context" +) + +// MetadataKeyQueueName carries the queue name independently of the +// transport partition key. Producers set it on Message.Metadata so consumers +// can attribute work before decoding the payload. +const MetadataKeyQueueName = "queue_name" + +type queueNameContextKey struct{} + +// WithQueueName returns a child context containing the queue name of the +// delivered message. +func WithQueueName(ctx context.Context, queueName string) context.Context { + return context.WithValue(ctx, queueNameContextKey{}, queueName) +} + +// QueueName returns the delivered message's queue name from ctx. +func QueueName(ctx context.Context) (string, bool) { + queueName, ok := ctx.Value(queueNameContextKey{}).(string) + return queueName, ok +} diff --git a/platform/base/messagequeue/context_test.go b/platform/base/messagequeue/context_test.go new file mode 100644 index 000000000..8cbde78b9 --- /dev/null +++ b/platform/base/messagequeue/context_test.go @@ -0,0 +1,33 @@ +// Copyright (c) 2025 Uber Technologies, Inc. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package messagequeue + +import ( + "context" + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestQueueNameContext(t *testing.T) { + ctx := WithQueueName(context.Background(), "monorepo/main") + + queueName, ok := QueueName(ctx) + assert.True(t, ok) + assert.Equal(t, "monorepo/main", queueName) + + _, ok = QueueName(context.Background()) + assert.False(t, ok) +} diff --git a/platform/consumer/BUILD.bazel b/platform/consumer/BUILD.bazel index b8951219e..cdc035058 100644 --- a/platform/consumer/BUILD.bazel +++ b/platform/consumer/BUILD.bazel @@ -36,6 +36,7 @@ go_test( "//platform/extension/consumergate/noop:go_default_library", "//platform/extension/messagequeue:go_default_library", "//platform/extension/messagequeue/mock:go_default_library", + "//platform/metrics:go_default_library", "@com_github_stretchr_testify//assert:go_default_library", "@com_github_stretchr_testify//require:go_default_library", "@com_github_uber_go_tally//:go_default_library", diff --git a/platform/consumer/consumer.go b/platform/consumer/consumer.go index 753620db5..9e1fb03af 100644 --- a/platform/consumer/consumer.go +++ b/platform/consumer/consumer.go @@ -22,6 +22,7 @@ import ( "time" "github.com/uber-go/tally" + entityqueue "github.com/uber/submitqueue/platform/base/messagequeue" "github.com/uber/submitqueue/platform/errs" "github.com/uber/submitqueue/platform/extension/consumergate" extqueue "github.com/uber/submitqueue/platform/extension/messagequeue" @@ -371,6 +372,13 @@ func (m *consumer) processPartition(ctx context.Context, controller Controller, func (m *consumer) processDelivery(ctx context.Context, controller Controller, delivery extqueue.Delivery, controllerScope tally.Scope) { const opName = "process" + msg := delivery.Message() + queueName := msg.Metadata[entityqueue.MetadataKeyQueueName] + ctx = entityqueue.WithQueueName(ctx, queueName) + if queueName != "" { + ctx = metrics.WithContextTags(ctx, metrics.NewTag("queue", queueName)) + } + // Consumer gate: a delivery whose gate is closed is recorded as parked and // postponed (barrier + re-check on redelivery); a false return also covers // shutdown-while-checking, where the delivery is left in flight so its @@ -380,7 +388,6 @@ func (m *consumer) processDelivery(ctx context.Context, controller Controller, d return } - msg := delivery.Message() topicKey := controller.TopicKey() m.logger.Debugw("processing delivery", @@ -396,7 +403,7 @@ func (m *consumer) processDelivery(ctx context.Context, controller Controller, d // Call controller with wrapped delivery start := time.Now() - op := metrics.Begin(controllerScope, opName, metrics.LongLatencyBuckets) + op := metrics.Begin(controllerScope, opName, metrics.LongLatencyBuckets, metrics.TagsFromContext(ctx)...) err := controller.Process(ctx, wrapped) elapsed := time.Since(start) @@ -419,7 +426,7 @@ func (m *consumer) processDelivery(ctx context.Context, controller Controller, d // A failure outcome wins over a recorded hold — a hold is only honored // on success, so retry accounting and dead-lettering stay meaningful. if wrapped.held { - metrics.NamedCounter(controllerScope, opName, "hold_ignored", 1) + metrics.NamedCounter(controllerScope, opName, "hold_ignored", 1, metrics.TagsFromContext(ctx)...) m.logger.Warnw("hold recorded but controller returned error, failure outcome wins", "controller", controller.Name(), "topic_key", topicKey, @@ -451,7 +458,7 @@ func (m *consumer) processDelivery(ctx context.Context, controller Controller, d ) // Reject moves to DLQ (or acks if DLQ disabled) - rejectOp := metrics.Begin(controllerScope, "reject", metrics.StorageLatencyBuckets) + rejectOp := metrics.Begin(controllerScope, "reject", metrics.StorageLatencyBuckets, metrics.TagsFromContext(ctx)...) rejectErr := delivery.Reject(ctx, controllerFailure) rejectOp.Complete(rejectErr) if rejectErr != nil { @@ -485,7 +492,7 @@ func (m *consumer) processDelivery(ctx context.Context, controller Controller, d // Nack requeues immediately - the visibility timeout spaces retries. // The failure travels with it so that the attempt which finally spends // the retry budget can dead-letter saying why. - nackOp := metrics.Begin(controllerScope, "nack", metrics.StorageLatencyBuckets) + nackOp := metrics.Begin(controllerScope, "nack", metrics.StorageLatencyBuckets, metrics.TagsFromContext(ctx)...) nackErr := delivery.Nack(ctx, controllerFailure) nackOp.Complete(nackErr) if nackErr != nil { @@ -505,7 +512,7 @@ func (m *consumer) processDelivery(ctx context.Context, controller Controller, d // the visibility timeout lapses into a normal redelivery, so the hold // loop's liveness never depends on this write succeeding. if wrapped.held { - postponeOp := metrics.Begin(controllerScope, "postpone", metrics.StorageLatencyBuckets) + postponeOp := metrics.Begin(controllerScope, "postpone", metrics.StorageLatencyBuckets, metrics.TagsFromContext(ctx)...) postponeErr := delivery.Postpone(ctx, wrapped.holdDelayMs) postponeOp.Complete(postponeErr) if postponeErr != nil { @@ -530,7 +537,7 @@ func (m *consumer) processDelivery(ctx context.Context, controller Controller, d } // Controller succeeded - ack message - ackOp := metrics.Begin(controllerScope, "ack", metrics.StorageLatencyBuckets) + ackOp := metrics.Begin(controllerScope, "ack", metrics.StorageLatencyBuckets, metrics.TagsFromContext(ctx)...) ackErr := delivery.Ack(ctx) ackOp.Complete(ackErr) if ackErr != nil { @@ -578,7 +585,7 @@ func (m *consumer) checkGate(ctx context.Context, controller Controller, deliver // into a normal redelivery. return false } - metrics.NamedCounter(scope, opName, "enter_errors", 1) + metrics.NamedCounter(scope, opName, "enter_errors", 1, metrics.TagsFromContext(ctx)...) m.logger.Errorw("gate check failed, failing open", "consumer_group", consumerGroup, "topic", topic, @@ -600,7 +607,7 @@ func (m *consumer) checkGate(ctx context.Context, controller Controller, deliver // earlier re-check, the gate has opened and the record must go so // observers see an empty parked set. A no-op when never parked. if unparkErr := entry.Unpark(ctx, descriptor); unparkErr != nil { - metrics.NamedCounter(scope, opName, "unpark_errors", 1) + metrics.NamedCounter(scope, opName, "unpark_errors", 1, metrics.TagsFromContext(ctx)...) m.logger.Warnw("failed to remove parked record on admit", "consumer_group", consumerGroup, "topic", topic, @@ -615,7 +622,7 @@ func (m *consumer) checkGate(ctx context.Context, controller Controller, deliver // partition waits behind it (barrier) and the gate is re-checked on // redelivery without burning retry budget. if parkErr := entry.Park(ctx, descriptor); parkErr != nil { - metrics.NamedCounter(scope, opName, "park_errors", 1) + metrics.NamedCounter(scope, opName, "park_errors", 1, metrics.TagsFromContext(ctx)...) m.logger.Warnw("failed to write parked record, postponing anyway", "consumer_group", consumerGroup, "topic", topic, @@ -624,8 +631,8 @@ func (m *consumer) checkGate(ctx context.Context, controller Controller, deliver ) } - metrics.NamedCounter(scope, opName, "parked", 1) - postponeOp := metrics.Begin(scope, "postpone", metrics.StorageLatencyBuckets) + metrics.NamedCounter(scope, opName, "parked", 1, metrics.TagsFromContext(ctx)...) + postponeOp := metrics.Begin(scope, "postpone", metrics.StorageLatencyBuckets, metrics.TagsFromContext(ctx)...) postponeErr := delivery.Postpone(ctx, m.gateRecheckDelayMs) postponeOp.Complete(postponeErr) if postponeErr != nil { diff --git a/platform/consumer/consumer_test.go b/platform/consumer/consumer_test.go index 0480db1d7..ceb557026 100644 --- a/platform/consumer/consumer_test.go +++ b/platform/consumer/consumer_test.go @@ -33,6 +33,7 @@ import ( consumergatenoop "github.com/uber/submitqueue/platform/extension/consumergate/noop" extqueue "github.com/uber/submitqueue/platform/extension/messagequeue" queuemock "github.com/uber/submitqueue/platform/extension/messagequeue/mock" + "github.com/uber/submitqueue/platform/metrics" "go.uber.org/mock/gomock" "go.uber.org/zap/zaptest" ) @@ -286,10 +287,14 @@ func TestConsumer_ProcessDelivery_Success(t *testing.T) { c := New(logger, tally.NoopScope, reg, errs.NewClassifierProcessor(), consumergatenoop.New()) handledMsg := "" + handledQueue := "" + var handledTags []metrics.Tag handler := &testController{} setupController(handler, "test-handler", testTopicKeyStart, "test-group", func(ctx context.Context, delivery Delivery) error { handledMsg = delivery.Message().ID + handledQueue, _ = entityqueue.QueueName(ctx) + handledTags = metrics.TagsFromContext(ctx) return nil }, ) @@ -303,7 +308,9 @@ func TestConsumer_ProcessDelivery_Success(t *testing.T) { err = c.Start(ctx) require.NoError(t, err) - msg := entityqueue.NewMessage("test-msg-1", []byte("payload"), "partition1", nil) + msg := entityqueue.NewMessage("test-msg-1", []byte("payload"), "partition1", map[string]string{ + entityqueue.MetadataKeyQueueName: "monorepo/main", + }) mockDel := queuemock.NewMockDelivery(ctrl) done := setupDelivery(mockDel, msg, nil, nil) @@ -311,6 +318,8 @@ func TestConsumer_ProcessDelivery_Success(t *testing.T) { <-done assert.Equal(t, "test-msg-1", handledMsg) + assert.Equal(t, "monorepo/main", handledQueue) + assert.Equal(t, []metrics.Tag{metrics.NewTag("queue", "monorepo/main")}, handledTags) err = c.Stop(30000) require.NoError(t, err) diff --git a/platform/metrics/metrics.go b/platform/metrics/metrics.go index 20f98c755..5bba9793f 100644 --- a/platform/metrics/metrics.go +++ b/platform/metrics/metrics.go @@ -30,11 +30,36 @@ type Tag struct { Value string } +type contextTagsKey struct{} + // NewTag creates a Tag with the given key and value. func NewTag(key, value string) Tag { return Tag{Key: key, Value: value} } +// WithContextTags returns a child context carrying the supplied metric tags. +// Tags already carried by ctx are preserved, and both inputs are copied. +func WithContextTags(ctx context.Context, tags ...Tag) context.Context { + existing, _ := ctx.Value(contextTagsKey{}).([]Tag) + contextTags := make([]Tag, 0, len(existing)+len(tags)) + contextTags = append(contextTags, existing...) + contextTags = append(contextTags, tags...) + return context.WithValue(ctx, contextTagsKey{}, contextTags) +} + +// TagsFromContext appends metric tags explicitly carried by ctx. Additional +// tags are preserved, and context-derived tags win when the same key is present. +func TagsFromContext(ctx context.Context, tags ...Tag) []Tag { + stored, _ := ctx.Value(contextTagsKey{}).([]Tag) + if len(stored) == 0 { + return tags + } + + contextTags := make([]Tag, 0, len(tags)+len(stored)) + contextTags = append(contextTags, tags...) + return append(contextTags, stored...) +} + // Common duration bucket sets for latency histograms. Operations differ widely // in expected latency, so there is no single default — pick the set whose range // matches the operation and pass it to Begin or NamedHistogram. Buckets diff --git a/platform/metrics/metrics_test.go b/platform/metrics/metrics_test.go index 3dd70c23e..52e567fa9 100644 --- a/platform/metrics/metrics_test.go +++ b/platform/metrics/metrics_test.go @@ -158,6 +158,22 @@ func TestNamedGauge(t *testing.T) { assert.Equal(t, float64(42), g.Value()) } +func TestTagsFromContext(t *testing.T) { + contextTags := []Tag{NewTag("queue", "monorepo/main")} + ctx := WithContextTags(context.Background(), contextTags...) + contextTags[0] = NewTag("queue", "changed") + ctx = WithContextTags(ctx, NewTag("controller", "build")) + + tags := TagsFromContext(ctx, NewTag("result", "success"), NewTag("queue", "wrong")) + assert.Equal(t, []Tag{ + NewTag("result", "success"), + NewTag("queue", "wrong"), + NewTag("queue", "monorepo/main"), + NewTag("controller", "build"), + }, tags) + assert.Empty(t, TagsFromContext(context.Background())) +} + func TestLatencyBuckets_Sorted(t *testing.T) { sets := map[string]tally.DurationBuckets{ "FastLatencyBuckets": FastLatencyBuckets, diff --git a/platform/publish/publish.go b/platform/publish/publish.go index 4f280c315..53cbc7ed4 100644 --- a/platform/publish/publish.go +++ b/platform/publish/publish.go @@ -26,6 +26,7 @@ package publish import ( "context" "fmt" + "maps" "strings" "sync/atomic" "time" @@ -34,7 +35,8 @@ import ( "github.com/uber/submitqueue/platform/consumer" ) -// Message publishes payload to the topic registered for key. +// Message publishes payload to the topic registered for key. Allowlisted +// delivery context is propagated as message metadata. // // msgID selects the dedup behavior, so the caller must choose it deliberately. // The queue deduplicates on (topic, partition key, message ID) against every @@ -53,6 +55,8 @@ func Message(ctx context.Context, registry consumer.TopicRegistry, key consumer. // MessageWithMetadata is Message with side-band message metadata (headers/attributes) // attached to the delivery. Use it to carry diagnostic context that is not part of // the payload — the backend persists and redelivers metadata alongside the message. +// Allowlisted delivery context, currently only the queue name, is propagated unless +// the caller supplies that metadata key explicitly. func MessageWithMetadata(ctx context.Context, registry consumer.TopicRegistry, key consumer.TopicKey, msgID string, payload []byte, partitionKey string, metadata map[string]string) error { q, ok := registry.Queue(key) if !ok { @@ -63,10 +67,26 @@ func MessageWithMetadata(ctx context.Context, registry consumer.TopicRegistry, k return fmt.Errorf("no topic name registered for topic key %s", key) } - msg := entityqueue.NewMessage(msgID, payload, partitionKey, metadata) + msg := entityqueue.NewMessage(msgID, payload, partitionKey, metadataFromContext(ctx, metadata)) return q.Publisher().Publish(ctx, topicName, msg) } +func metadataFromContext(ctx context.Context, metadata map[string]string) map[string]string { + metadata = maps.Clone(metadata) + if _, exists := metadata[entityqueue.MetadataKeyQueueName]; exists { + return metadata + } + queueName, ok := entityqueue.QueueName(ctx) + if !ok || queueName == "" { + return metadata + } + if metadata == nil { + metadata = make(map[string]string) + } + metadata[entityqueue.MetadataKeyQueueName] = queueName + return metadata +} + // IntentID names the occasion to publish rather than the entity published // about: entityID says what the message concerns, and cause says why this // particular message exists. diff --git a/platform/publish/publish_test.go b/platform/publish/publish_test.go index d98f09e91..23ec08ae7 100644 --- a/platform/publish/publish_test.go +++ b/platform/publish/publish_test.go @@ -60,6 +60,64 @@ func TestMessage(t *testing.T) { assert.Equal(t, "msg-1", published.ID) assert.Equal(t, []byte("payload"), published.Payload) assert.Equal(t, "partition-1", published.PartitionKey) + assert.Empty(t, published.Metadata) +} + +func TestMessage_PropagatesQueueNameFromContext(t *testing.T) { + ctrl := gomock.NewController(t) + registry, publisher := newTestRegistry(t, ctrl) + + var published entityqueue.Message + publisher.EXPECT(). + Publish(gomock.Any(), "test-topic", gomock.Any()). + DoAndReturn(func(_ context.Context, _ string, msg entityqueue.Message) error { + published = msg + return nil + }) + + ctx := entityqueue.WithQueueName(context.Background(), "monorepo/main") + require.NoError(t, Message(ctx, registry, testKey, "msg-1", []byte("payload"), "partition-1")) + assert.Equal(t, "monorepo/main", published.Metadata[entityqueue.MetadataKeyQueueName]) +} + +func TestMessageWithMetadata_MergesContextWithoutMutatingInput(t *testing.T) { + ctrl := gomock.NewController(t) + registry, publisher := newTestRegistry(t, ctrl) + + var published entityqueue.Message + publisher.EXPECT(). + Publish(gomock.Any(), "test-topic", gomock.Any()). + DoAndReturn(func(_ context.Context, _ string, msg entityqueue.Message) error { + published = msg + return nil + }) + + metadata := map[string]string{"failure_reason": "build failed"} + ctx := entityqueue.WithQueueName(context.Background(), "monorepo/main") + require.NoError(t, MessageWithMetadata(ctx, registry, testKey, "msg-1", []byte("payload"), "partition-1", metadata)) + assert.Equal(t, map[string]string{ + "failure_reason": "build failed", + entityqueue.MetadataKeyQueueName: "monorepo/main", + }, published.Metadata) + assert.Equal(t, map[string]string{"failure_reason": "build failed"}, metadata) +} + +func TestMessageWithMetadata_ExplicitQueueNameWins(t *testing.T) { + ctrl := gomock.NewController(t) + registry, publisher := newTestRegistry(t, ctrl) + + var published entityqueue.Message + publisher.EXPECT(). + Publish(gomock.Any(), "test-topic", gomock.Any()). + DoAndReturn(func(_ context.Context, _ string, msg entityqueue.Message) error { + published = msg + return nil + }) + + ctx := entityqueue.WithQueueName(context.Background(), "inbound") + metadata := map[string]string{entityqueue.MetadataKeyQueueName: "outbound"} + require.NoError(t, MessageWithMetadata(ctx, registry, testKey, "msg-1", []byte("payload"), "partition-1", metadata)) + assert.Equal(t, "outbound", published.Metadata[entityqueue.MetadataKeyQueueName]) } func TestMessage_UnregisteredKey(t *testing.T) { diff --git a/stovepipe/controller/BUILD.bazel b/stovepipe/controller/BUILD.bazel index 4bbd1cffe..5668f272e 100644 --- a/stovepipe/controller/BUILD.bazel +++ b/stovepipe/controller/BUILD.bazel @@ -10,6 +10,7 @@ go_library( visibility = ["//visibility:public"], deps = [ "//api/stovepipe/protopb:go_default_library", + "//platform/base/messagequeue:go_default_library", "//platform/consumer:go_default_library", "//platform/errs:go_default_library", "//platform/extension/counter:go_default_library", @@ -33,6 +34,7 @@ go_test( embed = [":go_default_library"], deps = [ "//api/stovepipe/protopb:go_default_library", + "//platform/base/messagequeue:go_default_library", "//platform/consumer:go_default_library", "//platform/extension/counter:go_default_library", "//platform/extension/counter/mock:go_default_library", diff --git a/stovepipe/controller/build/BUILD.bazel b/stovepipe/controller/build/BUILD.bazel index ced03370f..ecb3e1cbb 100644 --- a/stovepipe/controller/build/BUILD.bazel +++ b/stovepipe/controller/build/BUILD.bazel @@ -30,6 +30,7 @@ go_test( "//platform/consumer/mock:go_default_library", "//platform/errs:go_default_library", "//platform/extension/messagequeue/mock:go_default_library", + "//platform/metrics:go_default_library", "//stovepipe/core/messagequeue:go_default_library", "//stovepipe/entity:go_default_library", "//stovepipe/extension/buildrunner:go_default_library", diff --git a/stovepipe/controller/build/build.go b/stovepipe/controller/build/build.go index 8bd08c6cd..0cdebdc17 100644 --- a/stovepipe/controller/build/build.go +++ b/stovepipe/controller/build/build.go @@ -84,28 +84,27 @@ func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) er br := &stovepipemq.BuildRequest{} if err := stovepipemq.Unmarshal(msg.Payload, br); err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "deserialize_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "deserialize_errors", 1, metrics.TagsFromContext(ctx)...) // Non-retryable: a malformed message will never succeed regardless of retries. return fmt.Errorf("failed to deserialize build request: %w", err) } - store, err := c.stores.For(storage.Config{QueueName: br.GetQueueName()}) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_resolve_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_resolve_errors", 1, metrics.TagsFromContext(ctx)...) // Non-retryable: a missing or unresolvable queue is a malformed message. return fmt.Errorf("failed to resolve storage for queue %q: %w", br.GetQueueName(), err) } request, err := c.loadRequest(ctx, store, br.Id) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1, metrics.TagsFromContext(ctx)...) return err } // The payload's queue must match the request's authoritative queue; a // mismatch is a malformed message. Non-retryable — reject to the DLQ. if br.GetQueueName() != "" && br.GetQueueName() != request.Queue { - metrics.NamedCounter(c.metricsScope, _opName, "queue_mismatch", 1) + metrics.NamedCounter(c.metricsScope, _opName, "queue_mismatch", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("payload queue %q does not match queue %q of request %s", br.GetQueueName(), request.Queue, request.ID) } @@ -123,7 +122,7 @@ func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) er // process decided the scope; build never re-derives incremental-vs-full. if request.BuildStrategy == entity.BuildStrategyUnknown { - metrics.NamedCounter(c.metricsScope, _opName, "strategy_not_visible", 1) + metrics.NamedCounter(c.metricsScope, _opName, "strategy_not_visible", 1, metrics.TagsFromContext(ctx)...) return errs.NewRetryableError(fmt.Errorf("request %s has no build strategy yet", request.ID)) } baseURI := "" diff --git a/stovepipe/controller/build/build_test.go b/stovepipe/controller/build/build_test.go index 1e7d85207..e5c9b7bc9 100644 --- a/stovepipe/controller/build/build_test.go +++ b/stovepipe/controller/build/build_test.go @@ -27,6 +27,7 @@ import ( consumermock "github.com/uber/submitqueue/platform/consumer/mock" "github.com/uber/submitqueue/platform/errs" mqmock "github.com/uber/submitqueue/platform/extension/messagequeue/mock" + "github.com/uber/submitqueue/platform/metrics" stovepipemq "github.com/uber/submitqueue/stovepipe/core/messagequeue" "github.com/uber/submitqueue/stovepipe/entity" "github.com/uber/submitqueue/stovepipe/extension/buildrunner" @@ -45,6 +46,11 @@ const ( testBuildID = "bk-1" ) +func queueContext() context.Context { + ctx := entityqueue.WithQueueName(context.Background(), testQueue) + return metrics.WithContextTags(ctx, metrics.NewTag("queue", testQueue)) +} + // buildMocks bundles the mocks a build controller test case wires expectations on. type buildMocks struct { reqStore *storagemock.MockRequestStore @@ -52,6 +58,7 @@ type buildMocks struct { runnerFactory *buildrunnermock.MockFactory runner *buildrunnermock.MockBuildRunner publisher *mqmock.MockPublisher + metricsScope tally.TestScope } // staticStorageFactory resolves every queue to one fixed store aggregate. @@ -63,12 +70,14 @@ func (f staticStorageFactory) For(storage.Config) (storage.Storage, error) { ret func newController(t *testing.T, ctrl *gomock.Controller) (*Controller, buildMocks) { t.Helper() + scope := tally.NewTestScope("test", nil) m := buildMocks{ reqStore: storagemock.NewMockRequestStore(ctrl), buildStore: storagemock.NewMockBuildStore(ctrl), runnerFactory: buildrunnermock.NewMockFactory(ctrl), runner: buildrunnermock.NewMockBuildRunner(ctrl), publisher: mqmock.NewMockPublisher(ctrl), + metricsScope: scope, } store := storagemock.NewMockStorage(ctrl) @@ -83,10 +92,49 @@ func newController(t *testing.T, ctrl *gomock.Controller) (*Controller, buildMoc }) require.NoError(t, err) - c := NewController(zap.NewNop().Sugar(), tally.NewTestScope("test", nil), staticStorageFactory{store: store}, m.runnerFactory, registry, stovepipemq.TopicKeyBuild, "stovepipe-build") + c := NewController(zap.NewNop().Sugar(), scope, staticStorageFactory{store: store}, m.runnerFactory, registry, stovepipemq.TopicKeyBuild, "stovepipe-build") return c, m } +func TestProcessTagsMetricsWithQueue(t *testing.T) { + ctrl := gomock.NewController(t) + c, m := newController(t, ctrl) + m.reqStore.EXPECT().Get(gomock.Any(), testID). + Return(processingRequest(entity.BuildStrategyUnknown, ""), nil) + m.runnerFactory.EXPECT().For(buildrunner.Config{QueueName: testQueue}).Return(m.runner, nil) + + require.Error(t, c.Process(queueContext(), delivery(t, ctrl, buildPayload(t, testID)))) + counter, ok := m.metricsScope.Snapshot().Counters()["test.build_controller.build.strategy_not_visible+queue=monorepo/main"] + require.True(t, ok) + assert.EqualValues(t, 1, counter.Value()) +} + +func TestProcessTagsDeserializeErrorsFromContext(t *testing.T) { + ctrl := gomock.NewController(t) + c, m := newController(t, ctrl) + + require.Error(t, c.Process(queueContext(), delivery(t, ctrl, []byte("not-protojson")))) + counter, ok := m.metricsScope.Snapshot().Counters()["test.build_controller.build.deserialize_errors+queue=monorepo/main"] + require.True(t, ok) + assert.EqualValues(t, 1, counter.Value()) +} + +func TestPublishBuildSignalCarriesQueueMetadata(t *testing.T) { + ctrl := gomock.NewController(t) + c, m := newController(t, ctrl) + + var got entityqueue.Message + m.publisher.EXPECT().Publish(gomock.Any(), "buildsignal", gomock.Any()). + DoAndReturn(func(_ context.Context, _ string, msg entityqueue.Message) error { + got = msg + return nil + }) + + require.NoError(t, c.publishBuildSignal(queueContext(), testBuildID, testQueue)) + assert.Equal(t, testBuildID, got.PartitionKey) + assert.Equal(t, testQueue, got.Metadata[entityqueue.MetadataKeyQueueName]) +} + func delivery(t *testing.T, ctrl *gomock.Controller, payload []byte) consumer.Delivery { t.Helper() d := consumermock.NewMockDelivery(ctrl) @@ -97,7 +145,7 @@ func delivery(t *testing.T, ctrl *gomock.Controller, payload []byte) consumer.De func buildPayload(t *testing.T, id string) []byte { t.Helper() - b, err := stovepipemq.Marshal(&stovepipemq.BuildRequest{Id: id}) + b, err := stovepipemq.Marshal(&stovepipemq.BuildRequest{Id: id, QueueName: testQueue}) require.NoError(t, err) return b } @@ -295,7 +343,7 @@ func TestProcess(t *testing.T) { payload = buildPayload(t, testID) } - err := c.Process(context.Background(), delivery(t, ctrl, payload)) + err := c.Process(queueContext(), delivery(t, ctrl, payload)) if tt.wantErr { require.Error(t, err) diff --git a/stovepipe/controller/buildsignal/BUILD.bazel b/stovepipe/controller/buildsignal/BUILD.bazel index bdec7cdfd..5cb922589 100644 --- a/stovepipe/controller/buildsignal/BUILD.bazel +++ b/stovepipe/controller/buildsignal/BUILD.bazel @@ -29,6 +29,7 @@ go_test( "//platform/consumer/mock:go_default_library", "//platform/errs:go_default_library", "//platform/extension/messagequeue/mock:go_default_library", + "//platform/metrics:go_default_library", "//stovepipe/core/messagequeue:go_default_library", "//stovepipe/entity:go_default_library", "//stovepipe/extension/buildrunner:go_default_library", diff --git a/stovepipe/controller/buildsignal/buildsignal.go b/stovepipe/controller/buildsignal/buildsignal.go index c040d239c..f8aca8bfd 100644 --- a/stovepipe/controller/buildsignal/buildsignal.go +++ b/stovepipe/controller/buildsignal/buildsignal.go @@ -104,34 +104,33 @@ func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) er sig := &stovepipemq.BuildSignal{} if err := stovepipemq.Unmarshal(msg.Payload, sig); err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "deserialize_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "deserialize_errors", 1, metrics.TagsFromContext(ctx)...) // Non-retryable: a malformed message will never succeed regardless of retries. return fmt.Errorf("failed to deserialize build signal: %w", err) } - store, err := c.stores.For(storage.Config{QueueName: sig.GetQueueName()}) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_resolve_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_resolve_errors", 1, metrics.TagsFromContext(ctx)...) // Non-retryable: a missing or unresolvable queue is a malformed message. return fmt.Errorf("failed to resolve storage for queue %q: %w", sig.GetQueueName(), err) } build, err := c.loadBuild(ctx, store, sig.Id) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1, metrics.TagsFromContext(ctx)...) return err } request, err := c.loadRequest(ctx, store, build.RequestID) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1, metrics.TagsFromContext(ctx)...) return err } // The payload's queue must match the request's authoritative queue; a // mismatch is a malformed message. Non-retryable — reject to the DLQ. if sig.GetQueueName() != "" && sig.GetQueueName() != request.Queue { - metrics.NamedCounter(c.metricsScope, _opName, "queue_mismatch", 1) + metrics.NamedCounter(c.metricsScope, _opName, "queue_mismatch", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("payload queue %q does not match queue %q of request %s", sig.GetQueueName(), request.Queue, request.ID) } @@ -214,12 +213,12 @@ func (c *Controller) finishRequest(ctx context.Context, store storage.Storage, r } if err := c.releaseBuildSlot(ctx, store, request.Queue); err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1, metrics.TagsFromContext(ctx)...) return err } if err := c.markOutcome(ctx, store, request, outcomeState(status)); err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1, metrics.TagsFromContext(ctx)...) return err } return nil @@ -268,7 +267,7 @@ func (c *Controller) markOutcome(ctx context.Context, store storage.Storage, req updated.Version = newVersion *request = updated metrics.NamedCounter(c.metricsScope, _opName, "outcomes", 1, - metrics.NewTag("state", string(state)), + metrics.TagsFromContext(ctx, metrics.NewTag("state", string(state)))..., ) return nil } @@ -300,7 +299,7 @@ func (c *Controller) releaseBuildSlot(ctx context.Context, store storage.Storage } return fmt.Errorf("failed to release build slot for queue %s: %w", queueName, err) } - metrics.NamedCounter(c.metricsScope, _opName, "slot_released", 1) + metrics.NamedCounter(c.metricsScope, _opName, "slot_released", 1, metrics.TagsFromContext(ctx)...) return nil } } diff --git a/stovepipe/controller/buildsignal/buildsignal_test.go b/stovepipe/controller/buildsignal/buildsignal_test.go index 022ff927a..d20ee7289 100644 --- a/stovepipe/controller/buildsignal/buildsignal_test.go +++ b/stovepipe/controller/buildsignal/buildsignal_test.go @@ -27,6 +27,7 @@ import ( consumermock "github.com/uber/submitqueue/platform/consumer/mock" "github.com/uber/submitqueue/platform/errs" mqmock "github.com/uber/submitqueue/platform/extension/messagequeue/mock" + "github.com/uber/submitqueue/platform/metrics" stovepipemq "github.com/uber/submitqueue/stovepipe/core/messagequeue" "github.com/uber/submitqueue/stovepipe/entity" "github.com/uber/submitqueue/stovepipe/extension/buildrunner" @@ -43,6 +44,11 @@ const ( testBuildID = "bk-1" ) +func queueContext() context.Context { + ctx := entityqueue.WithQueueName(context.Background(), testQueue) + return metrics.WithContextTags(ctx, metrics.NewTag("queue", testQueue)) +} + // buildsignalMocks bundles the mocks a buildsignal controller test case wires // expectations on. type buildsignalMocks struct { @@ -52,6 +58,7 @@ type buildsignalMocks struct { runnerFactory *buildrunnermock.MockFactory runner *buildrunnermock.MockBuildRunner publisher *mqmock.MockPublisher + metricsScope tally.TestScope } // staticStorageFactory resolves every queue to one fixed store aggregate. @@ -63,6 +70,7 @@ func (f staticStorageFactory) For(storage.Config) (storage.Storage, error) { ret func newController(t *testing.T, ctrl *gomock.Controller) (*Controller, buildsignalMocks) { t.Helper() + scope := tally.NewTestScope("test", nil) m := buildsignalMocks{ reqStore: storagemock.NewMockRequestStore(ctrl), buildStore: storagemock.NewMockBuildStore(ctrl), @@ -70,6 +78,7 @@ func newController(t *testing.T, ctrl *gomock.Controller) (*Controller, buildsig runnerFactory: buildrunnermock.NewMockFactory(ctrl), runner: buildrunnermock.NewMockBuildRunner(ctrl), publisher: mqmock.NewMockPublisher(ctrl), + metricsScope: scope, } store := storagemock.NewMockStorage(ctrl) @@ -86,10 +95,21 @@ func newController(t *testing.T, ctrl *gomock.Controller) (*Controller, buildsig }) require.NoError(t, err) - c := NewController(zap.NewNop().Sugar(), tally.NewTestScope("test", nil), staticStorageFactory{store: store}, m.runnerFactory, registry, stovepipemq.TopicKeyBuildSignal, "stovepipe-buildsignal") + c := NewController(zap.NewNop().Sugar(), scope, staticStorageFactory{store: store}, m.runnerFactory, registry, stovepipemq.TopicKeyBuildSignal, "stovepipe-buildsignal") return c, m } +func TestProcessTagsMetricsWithQueue(t *testing.T) { + ctrl := gomock.NewController(t) + c, m := newController(t, ctrl) + m.buildStore.EXPECT().Get(gomock.Any(), testBuildID).Return(entity.Build{}, assert.AnError) + + require.Error(t, c.Process(queueContext(), delivery(t, ctrl, buildSignalPayload(t, testBuildID)))) + counter, ok := m.metricsScope.Snapshot().Counters()["test.buildsignal_controller.buildsignal.storage_errors+queue=monorepo/main"] + require.True(t, ok) + assert.EqualValues(t, 1, counter.Value()) +} + func delivery(t *testing.T, ctrl *gomock.Controller, payload []byte) *consumermock.MockDelivery { t.Helper() d := consumermock.NewMockDelivery(ctrl) @@ -100,7 +120,7 @@ func delivery(t *testing.T, ctrl *gomock.Controller, payload []byte) *consumermo func buildSignalPayload(t *testing.T, id string) []byte { t.Helper() - b, err := stovepipemq.Marshal(&stovepipemq.BuildSignal{Id: id}) + b, err := stovepipemq.Marshal(&stovepipemq.BuildSignal{Id: id, QueueName: testQueue}) require.NoError(t, err) return b } @@ -403,7 +423,7 @@ func TestProcess(t *testing.T) { d.EXPECT().Hold(tt.wantHoldMs) } - err := c.Process(context.Background(), d) + err := c.Process(queueContext(), d) if tt.wantErr { require.Error(t, err) @@ -429,13 +449,14 @@ func TestPublishRecordCarriesRequestID(t *testing.T) { return nil }) - require.NoError(t, c.publishRecord(context.Background(), testID, "monorepo/main")) + require.NoError(t, c.publishRecord(queueContext(), testID, "monorepo/main")) var payload stovepipemq.Record require.NoError(t, stovepipemq.Unmarshal(got.Payload, &payload)) assert.Equal(t, testID, payload.Id) assert.Equal(t, testID, got.ID) assert.Equal(t, testID, got.PartitionKey) + assert.Equal(t, "monorepo/main", got.Metadata[entityqueue.MetadataKeyQueueName]) } func TestOutcomeState(t *testing.T) { diff --git a/stovepipe/controller/dlq/BUILD.bazel b/stovepipe/controller/dlq/BUILD.bazel index d921b5e02..929be0543 100644 --- a/stovepipe/controller/dlq/BUILD.bazel +++ b/stovepipe/controller/dlq/BUILD.bazel @@ -33,6 +33,7 @@ go_test( "//platform/base/messagequeue:go_default_library", "//platform/consumer:go_default_library", "//platform/consumer/mock:go_default_library", + "//platform/metrics:go_default_library", "//stovepipe/core/messagequeue:go_default_library", "//stovepipe/entity:go_default_library", "//stovepipe/extension/storage:go_default_library", diff --git a/stovepipe/controller/dlq/build.go b/stovepipe/controller/dlq/build.go index 3afed6815..1bee58da3 100644 --- a/stovepipe/controller/dlq/build.go +++ b/stovepipe/controller/dlq/build.go @@ -62,17 +62,17 @@ func NewDLQBuildController( func (c *buildController) Process(ctx context.Context, delivery consumer.Delivery) error { buildRequest := &stovepipemq.BuildRequest{} if err := stovepipemq.Unmarshal(delivery.Message().Payload, buildRequest); err != nil { - metrics.NamedCounter(c.metricsScope, _buildOpName, "deserialize_errors", 1) + metrics.NamedCounter(c.metricsScope, _buildOpName, "deserialize_errors", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("failed to decode dlq payload: %w", err) } if buildRequest.Id == "" { - metrics.NamedCounter(c.metricsScope, _buildOpName, "empty_id_errors", 1) + metrics.NamedCounter(c.metricsScope, _buildOpName, "empty_id_errors", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("build dlq payload decoded to empty request id") } store, err := c.stores.For(storage.Config{QueueName: buildRequest.GetQueueName()}) if err != nil { - metrics.NamedCounter(c.metricsScope, _buildOpName, "storage_resolve_errors", 1) + metrics.NamedCounter(c.metricsScope, _buildOpName, "storage_resolve_errors", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("failed to resolve storage for queue %q: %w", buildRequest.GetQueueName(), err) } @@ -86,10 +86,10 @@ func (c *buildController) Process(ctx context.Context, delivery consumer.Deliver ) if err := failRequest(ctx, store, c.logger, buildRequest.Id); err != nil { - metrics.NamedCounter(c.metricsScope, _buildOpName, "reconcile_errors", 1) + metrics.NamedCounter(c.metricsScope, _buildOpName, "reconcile_errors", 1, metrics.TagsFromContext(ctx)...) return err } - metrics.NamedCounter(c.metricsScope, _buildOpName, "reconciled", 1) + metrics.NamedCounter(c.metricsScope, _buildOpName, "reconciled", 1, metrics.TagsFromContext(ctx)...) return nil } diff --git a/stovepipe/controller/dlq/build_test.go b/stovepipe/controller/dlq/build_test.go index a725b521d..fa9c68341 100644 --- a/stovepipe/controller/dlq/build_test.go +++ b/stovepipe/controller/dlq/build_test.go @@ -15,7 +15,6 @@ package dlq import ( - "context" "testing" "github.com/stretchr/testify/assert" @@ -32,15 +31,17 @@ import ( func newBuildController(t *testing.T, ctrl *gomock.Controller) (consumer.Controller, dlqMocks) { t.Helper() + scope := tally.NewTestScope("test", nil) m := dlqMocks{ - reqStore: storagemock.NewMockRequestStore(ctrl), - queueStore: storagemock.NewMockQueueStore(ctrl), + reqStore: storagemock.NewMockRequestStore(ctrl), + queueStore: storagemock.NewMockQueueStore(ctrl), + metricsScope: scope, } store := storagemock.NewMockStorage(ctrl) store.EXPECT().GetRequestStore().Return(m.reqStore).AnyTimes() store.EXPECT().GetQueueStore().Return(m.queueStore).AnyTimes() - c := NewDLQBuildController(zap.NewNop().Sugar(), tally.NewTestScope("test", nil), staticStorageFactory{store: store}, TopicKey(stovepipemq.TopicKeyBuild), "stovepipe-build-dlq") + c := NewDLQBuildController(zap.NewNop().Sugar(), scope, staticStorageFactory{store: store}, TopicKey(stovepipemq.TopicKeyBuild), "stovepipe-build-dlq") return c, m } @@ -53,10 +54,11 @@ func buildPayload(t *testing.T, id string) []byte { func TestBuildProcess(t *testing.T) { tests := []struct { - name string - payload []byte - setup func(m dlqMocks) - wantErr bool + name string + payload []byte + setup func(m dlqMocks) + wantErr bool + wantMetric string }{ { name: "processing request is failed", @@ -68,9 +70,15 @@ func TestBuildProcess(t *testing.T) { updated.State = entity.RequestStateFailed m.reqStore.EXPECT().Update(gomock.Any(), updated, int32(2), int32(3)).Return(nil) }, + wantMetric: "test.build_dlq_controller.build_dlq.reconciled+queue=monorepo/main", }, {name: "malformed payload is returned", payload: []byte("not-a-proto"), wantErr: true}, - {name: "empty request id is returned", payload: buildPayload(t, ""), wantErr: true}, + { + name: "empty request id is returned", + payload: buildPayload(t, ""), + wantErr: true, + wantMetric: "test.build_dlq_controller.build_dlq.empty_id_errors+queue=monorepo/main", + }, } for _, tt := range tests { @@ -85,7 +93,12 @@ func TestBuildProcess(t *testing.T) { if payload == nil { payload = buildPayload(t, testID) } - err := controller.Process(context.Background(), delivery(t, ctrl, payload)) + err := controller.Process(queueContext(), delivery(t, ctrl, payload)) + if tt.wantMetric != "" { + counter, ok := mocks.metricsScope.Snapshot().Counters()[tt.wantMetric] + require.True(t, ok) + assert.EqualValues(t, 1, counter.Value()) + } if tt.wantErr { require.Error(t, err) return diff --git a/stovepipe/controller/dlq/buildsignal.go b/stovepipe/controller/dlq/buildsignal.go index c68d2f2d0..c42629bad 100644 --- a/stovepipe/controller/dlq/buildsignal.go +++ b/stovepipe/controller/dlq/buildsignal.go @@ -89,7 +89,7 @@ func (c *buildSignalController) Process(ctx context.Context, delivery consumer.D sig := &stovepipemq.BuildSignal{} if err := stovepipemq.Unmarshal(msg.Payload, sig); err != nil { - metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "deserialize_errors", 1) + metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "deserialize_errors", 1, metrics.TagsFromContext(ctx)...) // Retried rather than acked, for the same deployment-skew reason the // process reconciler gives: a newer producer's payload decodes fine once // the rollout finishes, and acking here would skip the slot release @@ -97,13 +97,13 @@ func (c *buildSignalController) Process(ctx context.Context, delivery consumer.D return fmt.Errorf("failed to decode dlq payload: %w", err) } if sig.Id == "" { - metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "empty_id_errors", 1) + metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "empty_id_errors", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("dlq payload decoded to empty build id") } store, err := c.stores.For(storage.Config{QueueName: sig.GetQueueName()}) if err != nil { - metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "storage_resolve_errors", 1) + metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "storage_resolve_errors", 1, metrics.TagsFromContext(ctx)...) // Non-retryable: a missing or unresolvable queue is a malformed message. return fmt.Errorf("failed to resolve storage for queue %q: %w", sig.GetQueueName(), err) } @@ -124,10 +124,10 @@ func (c *buildSignalController) Process(ctx context.Context, delivery consumer.D // Create. There is no request to recover from this payload; the build // stage's own DLQ handles the request that triggered it. c.logger.Warnw("dlq reconcile: build not found, skipping", "build_id", sig.Id) - metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "build_not_found", 1) + metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "build_not_found", 1, metrics.TagsFromContext(ctx)...) return nil } - metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "build_store_errors", 1) + metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "build_store_errors", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("failed to get build %s: %w", sig.Id, err) } @@ -135,7 +135,7 @@ func (c *buildSignalController) Process(ctx context.Context, delivery consumer.D // Defensive: a build with no request has nothing to reconcile and no slot // to release. Ack it so the DLQ does not grow forever. c.logger.Errorw("dlq reconcile: build has empty request id, skipping", "build_id", sig.Id) - metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "build_missing_request", 1) + metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "build_missing_request", 1, metrics.TagsFromContext(ctx)...) return nil } @@ -144,11 +144,11 @@ func (c *buildSignalController) Process(ctx context.Context, delivery consumer.D // triggers only once process has written the strategy, which lands in the same CAS // as accepted→processing, and processing exits only to a terminal outcome. if err := failRequest(ctx, store, c.logger, build.RequestID); err != nil { - metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "reconcile_errors", 1) + metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "reconcile_errors", 1, metrics.TagsFromContext(ctx)...) return err } - metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "reconciled", 1) + metrics.NamedCounter(c.metricsScope, _buildSignalOpName, "reconciled", 1, metrics.TagsFromContext(ctx)...) return nil } diff --git a/stovepipe/controller/dlq/buildsignal_test.go b/stovepipe/controller/dlq/buildsignal_test.go index dbe88812f..8d3447072 100644 --- a/stovepipe/controller/dlq/buildsignal_test.go +++ b/stovepipe/controller/dlq/buildsignal_test.go @@ -15,7 +15,6 @@ package dlq import ( - "context" "testing" "github.com/stretchr/testify/assert" @@ -33,18 +32,21 @@ import ( const testBuildID = "go-code-on-odin-submitqueue/builds/2867068" type buildSignalDLQMocks struct { - reqStore *storagemock.MockRequestStore - queueStore *storagemock.MockQueueStore - buildStore *storagemock.MockBuildStore + reqStore *storagemock.MockRequestStore + queueStore *storagemock.MockQueueStore + buildStore *storagemock.MockBuildStore + metricsScope tally.TestScope } func newBuildSignalController(t *testing.T, ctrl *gomock.Controller) (consumer.Controller, buildSignalDLQMocks) { t.Helper() + scope := tally.NewTestScope("test", nil) m := buildSignalDLQMocks{ - reqStore: storagemock.NewMockRequestStore(ctrl), - queueStore: storagemock.NewMockQueueStore(ctrl), - buildStore: storagemock.NewMockBuildStore(ctrl), + reqStore: storagemock.NewMockRequestStore(ctrl), + queueStore: storagemock.NewMockQueueStore(ctrl), + buildStore: storagemock.NewMockBuildStore(ctrl), + metricsScope: scope, } store := storagemock.NewMockStorage(ctrl) @@ -54,7 +56,7 @@ func newBuildSignalController(t *testing.T, ctrl *gomock.Controller) (consumer.C c := NewDLQBuildSignalController( zap.NewNop().Sugar(), - tally.NewTestScope("test", nil), + scope, staticStorageFactory{store: store}, TopicKey(stovepipemq.TopicKeyBuildSignal), "stovepipe-buildsignal-dlq", @@ -80,10 +82,11 @@ func build() entity.Build { func TestBuildSignalProcess(t *testing.T) { tests := []struct { - name string - payload []byte - setup func(m buildSignalDLQMocks) - wantErr bool + name string + payload []byte + setup func(m buildSignalDLQMocks) + wantErr bool + wantMetric string }{ { // The case this reconciler exists for: a poll message that @@ -147,10 +150,11 @@ func TestBuildSignalProcess(t *testing.T) { wantErr: true, }, { - name: "empty build id is returned as an error", - payload: buildSignalPayload(t, ""), - setup: func(buildSignalDLQMocks) {}, - wantErr: true, + name: "empty build id is returned as an error", + payload: buildSignalPayload(t, ""), + setup: func(buildSignalDLQMocks) {}, + wantErr: true, + wantMetric: "test.buildsignal_dlq_controller.buildsignal_dlq.empty_id_errors+queue=monorepo/main", }, } @@ -165,7 +169,12 @@ func TestBuildSignalProcess(t *testing.T) { payload = buildSignalPayload(t, testBuildID) } - err := c.Process(context.Background(), delivery(t, ctrl, payload)) + err := c.Process(queueContext(), delivery(t, ctrl, payload)) + if tt.wantMetric != "" { + counter, ok := m.metricsScope.Snapshot().Counters()[tt.wantMetric] + require.True(t, ok) + assert.EqualValues(t, 1, counter.Value()) + } if tt.wantErr { require.Error(t, err) diff --git a/stovepipe/controller/dlq/dlq_test.go b/stovepipe/controller/dlq/dlq_test.go index ed3962ea6..b296e2104 100644 --- a/stovepipe/controller/dlq/dlq_test.go +++ b/stovepipe/controller/dlq/dlq_test.go @@ -24,6 +24,7 @@ import ( entityqueue "github.com/uber/submitqueue/platform/base/messagequeue" "github.com/uber/submitqueue/platform/consumer" consumermock "github.com/uber/submitqueue/platform/consumer/mock" + "github.com/uber/submitqueue/platform/metrics" stovepipemq "github.com/uber/submitqueue/stovepipe/core/messagequeue" "github.com/uber/submitqueue/stovepipe/entity" "github.com/uber/submitqueue/stovepipe/extension/storage" @@ -37,9 +38,15 @@ const ( testID = "request/monorepo/main/7" ) +func queueContext() context.Context { + ctx := entityqueue.WithQueueName(context.Background(), testQueue) + return metrics.WithContextTags(ctx, metrics.NewTag("queue", testQueue)) +} + type dlqMocks struct { - reqStore *storagemock.MockRequestStore - queueStore *storagemock.MockQueueStore + reqStore *storagemock.MockRequestStore + queueStore *storagemock.MockQueueStore + metricsScope tally.TestScope } // staticStorageFactory resolves every queue to one fixed store aggregate. @@ -51,16 +58,18 @@ func (f staticStorageFactory) For(storage.Config) (storage.Storage, error) { ret func newController(t *testing.T, ctrl *gomock.Controller) (consumer.Controller, dlqMocks) { t.Helper() + scope := tally.NewTestScope("test", nil) m := dlqMocks{ - reqStore: storagemock.NewMockRequestStore(ctrl), - queueStore: storagemock.NewMockQueueStore(ctrl), + reqStore: storagemock.NewMockRequestStore(ctrl), + queueStore: storagemock.NewMockQueueStore(ctrl), + metricsScope: scope, } store := storagemock.NewMockStorage(ctrl) store.EXPECT().GetRequestStore().Return(m.reqStore).AnyTimes() store.EXPECT().GetQueueStore().Return(m.queueStore).AnyTimes() - c := NewDLQRequestController(zap.NewNop().Sugar(), tally.NewTestScope("test", nil), staticStorageFactory{store: store}, TopicKey(stovepipemq.TopicKeyProcess), "stovepipe-process-dlq") + c := NewDLQRequestController(zap.NewNop().Sugar(), scope, staticStorageFactory{store: store}, TopicKey(stovepipemq.TopicKeyProcess), "stovepipe-process-dlq") return c, m } @@ -79,7 +88,7 @@ func delivery(t *testing.T, ctrl *gomock.Controller, payload []byte) consumer.De func processPayload(t *testing.T, id string) []byte { t.Helper() - b, err := stovepipemq.Marshal(&stovepipemq.ProcessRequest{Id: id}) + b, err := stovepipemq.Marshal(&stovepipemq.ProcessRequest{Id: id, QueueName: testQueue}) require.NoError(t, err) return b } @@ -95,10 +104,11 @@ func requestWithState(state entity.RequestState) entity.Request { func TestProcess(t *testing.T) { tests := []struct { - name string - payload []byte - setup func(m dlqMocks) - wantErr bool + name string + payload []byte + setup func(m dlqMocks) + wantErr bool + wantMetric string }{ { // No queue expectations: an accepted request never claimed a slot, @@ -194,10 +204,11 @@ func TestProcess(t *testing.T) { wantErr: true, }, { - name: "empty request id is not retryable", - payload: processPayload(t, ""), - setup: func(m dlqMocks) {}, - wantErr: true, + name: "empty request id is not retryable", + payload: processPayload(t, ""), + setup: func(m dlqMocks) {}, + wantErr: true, + wantMetric: "test.process_dlq_controller.process_dlq.empty_id_errors+queue=monorepo/main", }, } @@ -212,7 +223,12 @@ func TestProcess(t *testing.T) { payload = processPayload(t, testID) } - err := c.Process(context.Background(), delivery(t, ctrl, payload)) + err := c.Process(queueContext(), delivery(t, ctrl, payload)) + if tt.wantMetric != "" { + counter, ok := m.metricsScope.Snapshot().Counters()[tt.wantMetric] + require.True(t, ok) + assert.EqualValues(t, 1, counter.Value()) + } if tt.wantErr { require.Error(t, err) diff --git a/stovepipe/controller/dlq/request.go b/stovepipe/controller/dlq/request.go index bdf8f0169..89f4a63cd 100644 --- a/stovepipe/controller/dlq/request.go +++ b/stovepipe/controller/dlq/request.go @@ -72,7 +72,7 @@ func (c *requestController) Process(ctx context.Context, delivery consumer.Deliv pr := &stovepipemq.ProcessRequest{} if err := stovepipemq.Unmarshal(msg.Payload, pr); err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "deserialize_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "deserialize_errors", 1, metrics.TagsFromContext(ctx)...) // Decoding the same bytes normally fails deterministically, but this error is // still retried: the DLQ consumer's AlwaysRetryableProcessor (see Process doc) // classifies every error as retryable. That is deliberate — the recoverable @@ -85,13 +85,13 @@ func (c *requestController) Process(ctx context.Context, delivery consumer.Deliv return fmt.Errorf("failed to decode dlq payload: %w", err) } if pr.Id == "" { - metrics.NamedCounter(c.metricsScope, _opName, "empty_id_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "empty_id_errors", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("dlq payload decoded to empty request id") } store, err := c.stores.For(storage.Config{QueueName: pr.GetQueueName()}) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_resolve_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_resolve_errors", 1, metrics.TagsFromContext(ctx)...) // Non-retryable: a missing or unresolvable queue is a malformed message. return fmt.Errorf("failed to resolve storage for queue %q: %w", pr.GetQueueName(), err) } @@ -106,7 +106,7 @@ func (c *requestController) Process(ctx context.Context, delivery consumer.Deliv ) if err := failRequest(ctx, store, c.logger, pr.Id); err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "reconcile_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "reconcile_errors", 1, metrics.TagsFromContext(ctx)...) return err } diff --git a/stovepipe/controller/ingest.go b/stovepipe/controller/ingest.go index 68132080d..c3fb79daf 100644 --- a/stovepipe/controller/ingest.go +++ b/stovepipe/controller/ingest.go @@ -20,6 +20,7 @@ import ( "fmt" "github.com/uber-go/tally" + entityqueue "github.com/uber/submitqueue/platform/base/messagequeue" "github.com/uber/submitqueue/platform/consumer" "github.com/uber/submitqueue/platform/errs" "github.com/uber/submitqueue/platform/extension/counter" @@ -300,6 +301,7 @@ func (c *IngestController) publishProcess(ctx context.Context, id, queue string) return fmt.Errorf("failed to serialize process request: %w", err) } + ctx = entityqueue.WithQueueName(ctx, queue) if err := publish.Message(ctx, c.registry, stovepipemq.TopicKeyProcess, publish.IntentID(id), payload, queue); err != nil { return fmt.Errorf("failed to publish process request: %w", err) } diff --git a/stovepipe/controller/ingest_test.go b/stovepipe/controller/ingest_test.go index 0ead32a70..30d2cf8b5 100644 --- a/stovepipe/controller/ingest_test.go +++ b/stovepipe/controller/ingest_test.go @@ -22,6 +22,7 @@ import ( "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "github.com/uber-go/tally" + entityqueue "github.com/uber/submitqueue/platform/base/messagequeue" "github.com/uber/submitqueue/platform/consumer" "github.com/uber/submitqueue/platform/extension/counter" countermock "github.com/uber/submitqueue/platform/extension/counter/mock" @@ -117,6 +118,22 @@ func expectAdvanceLatestRequestIDNoOp(m ingestMocks, queue, id string) { }, nil) } +func TestPublishProcessCarriesQueueMetadata(t *testing.T) { + ctrl := gomock.NewController(t) + c, m := newIngestController(t, ctrl) + + var got entityqueue.Message + m.publisher.EXPECT().Publish(gomock.Any(), "process", gomock.Any()). + DoAndReturn(func(_ context.Context, _ string, msg entityqueue.Message) error { + got = msg + return nil + }) + + require.NoError(t, c.publishProcess(context.Background(), "request/monorepo/main/7", testQueue)) + assert.Equal(t, testQueue, got.PartitionKey) + assert.Equal(t, testQueue, got.Metadata[entityqueue.MetadataKeyQueueName]) +} + func TestIngestController_Ingest(t *testing.T) { tests := []struct { name string diff --git a/stovepipe/controller/process/BUILD.bazel b/stovepipe/controller/process/BUILD.bazel index 209f87f07..6db59c697 100644 --- a/stovepipe/controller/process/BUILD.bazel +++ b/stovepipe/controller/process/BUILD.bazel @@ -31,6 +31,7 @@ go_test( "//platform/consumer/mock:go_default_library", "//platform/errs:go_default_library", "//platform/extension/messagequeue/mock:go_default_library", + "//platform/metrics:go_default_library", "//stovepipe/core/messagequeue:go_default_library", "//stovepipe/entity:go_default_library", "//stovepipe/extension/queueconfig/default:go_default_library", diff --git a/stovepipe/controller/process/process.go b/stovepipe/controller/process/process.go index 0e71fd1c9..dc98184ec 100644 --- a/stovepipe/controller/process/process.go +++ b/stovepipe/controller/process/process.go @@ -87,35 +87,34 @@ func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) er pr := &stovepipemq.ProcessRequest{} if err := stovepipemq.Unmarshal(msg.Payload, pr); err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "deserialize_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "deserialize_errors", 1, metrics.TagsFromContext(ctx)...) // Non-retryable: a malformed message will never succeed regardless of retries. return fmt.Errorf("failed to deserialize process request: %w", err) } - store, err := c.stores.For(storage.Config{QueueName: pr.GetQueueName()}) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_resolve_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_resolve_errors", 1, metrics.TagsFromContext(ctx)...) // Non-retryable: a missing or unresolvable queue is a malformed message. return fmt.Errorf("failed to resolve storage for queue %q: %w", pr.GetQueueName(), err) } request, err := c.loadRequest(ctx, store, pr.Id) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1, metrics.TagsFromContext(ctx)...) return err } // The payload's queue must match the request's authoritative queue; a // mismatch is a malformed message. Non-retryable — reject to the DLQ. if pr.GetQueueName() != "" && pr.GetQueueName() != request.Queue { - metrics.NamedCounter(c.metricsScope, _opName, "queue_mismatch", 1) + metrics.NamedCounter(c.metricsScope, _opName, "queue_mismatch", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("payload queue %q does not match queue %q of request %s", pr.GetQueueName(), request.Queue, request.ID) } switch request.State { case entity.RequestStateProcessing: if err := c.publishBuild(ctx, request.ID, request.Queue); err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "publish_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "publish_errors", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("failed to publish request %s to build: %w", request.ID, err) } return nil @@ -142,7 +141,7 @@ func (c *Controller) processAccepted(ctx context.Context, store storage.Storage, queueRow, err := c.loadQueue(ctx, store, request.Queue) if err != nil { if !errs.IsRetryable(err) { - metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1, metrics.TagsFromContext(ctx)...) } return err } @@ -183,10 +182,10 @@ func (c *Controller) coalesce(ctx context.Context, store storage.Storage, reques return false, nil } if err := c.supersedeRequest(ctx, store, request); err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1, metrics.TagsFromContext(ctx)...) return false, err } - metrics.NamedCounter(c.metricsScope, _opName, "superseded", 1) + metrics.NamedCounter(c.metricsScope, _opName, "superseded", 1, metrics.TagsFromContext(ctx)...) c.logger.Infow("superseded request for newer head", "request_id", request.ID, "queue", request.Queue, @@ -207,14 +206,14 @@ func (c *Controller) admitLatestHead(ctx context.Context, store storage.Storage, for { if queueRow.InFlightCount >= cfg.MaxConcurrent { - return c.holdForBuildSlot(delivery, request, queueRow.InFlightCount, cfg.GateWaitDelayMs) + return c.holdForBuildSlot(ctx, delivery, request, queueRow.InFlightCount, cfg.GateWaitDelayMs) } if queueRow.LastGreenURI != "" && sc == nil { sc, err = c.sourceControl.For(sourcecontrol.Config{QueueName: request.Queue}) if err != nil { metrics.NamedCounter(c.metricsScope, _opName, "source_control_errors", 1, - metrics.NewTag("stage", "resolve"), + metrics.TagsFromContext(ctx, metrics.NewTag("stage", "resolve"))..., ) return fmt.Errorf("failed to resolve source control for queue %s: %w", request.Queue, err) } @@ -254,12 +253,12 @@ func (c *Controller) admitLatestHead(ctx context.Context, store storage.Storage, } if err := c.publishBuild(ctx, request.ID, request.Queue); err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "publish_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "publish_errors", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("failed to publish request %s to build: %w", request.ID, err) } metrics.NamedCounter(c.metricsScope, _opName, "admitted", 1, - metrics.NewTag("strategy", string(request.BuildStrategy)), + metrics.TagsFromContext(ctx, metrics.NewTag("strategy", string(request.BuildStrategy)))..., ) c.logger.Infow("admitted request to build", "request_id", request.ID, @@ -282,7 +281,7 @@ func (c *Controller) deriveBuildStrategy(ctx context.Context, sc sourcecontrol.S if err != nil { if sourcecontrol.IsNotFound(err) { metrics.NamedCounter(c.metricsScope, _opName, "strategy_fallbacks", 1, - metrics.NewTag("reason", "unknown_ancestry"), + metrics.TagsFromContext(ctx, metrics.NewTag("reason", "unknown_ancestry"))..., ) c.logger.Warnw("last-green URI is not in request history; using full build", "queue", request.Queue, @@ -292,7 +291,7 @@ func (c *Controller) deriveBuildStrategy(ctx context.Context, sc sourcecontrol.S return entity.BuildStrategyFull, "", nil } metrics.NamedCounter(c.metricsScope, _opName, "source_control_errors", 1, - metrics.NewTag("stage", "ancestry"), + metrics.TagsFromContext(ctx, metrics.NewTag("stage", "ancestry"))..., ) return entity.BuildStrategyUnknown, "", fmt.Errorf("failed to check ancestry for queue %s: %w", request.Queue, err) } @@ -394,7 +393,7 @@ func (c *Controller) releaseBuildSlot(ctx context.Context, store storage.Storage ) return } - metrics.NamedCounter(c.metricsScope, _opName, "slot_released", 1) + metrics.NamedCounter(c.metricsScope, _opName, "slot_released", 1, metrics.TagsFromContext(ctx)...) return } } @@ -430,9 +429,9 @@ func (c *Controller) supersedeRequest(ctx context.Context, store storage.Storage // delayMs and the gate is re-checked, without burning MaxAttempts — the partition // (keyed by queue name) waits with it. delayMs must be positive: a non-positive // hold would redeliver immediately and hot-loop the gate check. -func (c *Controller) holdForBuildSlot(delivery consumer.Delivery, request entity.Request, inFlightCount int32, delayMs int64) error { +func (c *Controller) holdForBuildSlot(ctx context.Context, delivery consumer.Delivery, request entity.Request, inFlightCount int32, delayMs int64) error { if delayMs <= 0 { - metrics.NamedCounter(c.metricsScope, _opName, "config_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "config_errors", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("requires a positive gate wait delay for queue %s, got %dms", request.Queue, delayMs) } diff --git a/stovepipe/controller/process/process_test.go b/stovepipe/controller/process/process_test.go index 71aae9a0c..0f5bc5845 100644 --- a/stovepipe/controller/process/process_test.go +++ b/stovepipe/controller/process/process_test.go @@ -27,6 +27,7 @@ import ( consumermock "github.com/uber/submitqueue/platform/consumer/mock" "github.com/uber/submitqueue/platform/errs" mqmock "github.com/uber/submitqueue/platform/extension/messagequeue/mock" + "github.com/uber/submitqueue/platform/metrics" stovepipemq "github.com/uber/submitqueue/stovepipe/core/messagequeue" "github.com/uber/submitqueue/stovepipe/entity" queueconfigdefault "github.com/uber/submitqueue/stovepipe/extension/queueconfig/default" @@ -45,6 +46,11 @@ const ( testURI = "git://repo/monorepo/main/abc123" ) +func queueContext(queueName string) context.Context { + ctx := entityqueue.WithQueueName(context.Background(), queueName) + return metrics.WithContextTags(ctx, metrics.NewTag("queue", queueName)) +} + type processMocks struct { reqStore *storagemock.MockRequestStore queueStore *storagemock.MockQueueStore @@ -109,7 +115,7 @@ func delivery(t *testing.T, ctrl *gomock.Controller, payload []byte) *consumermo func processPayload(t *testing.T, id string) []byte { t.Helper() - b, err := stovepipemq.Marshal(&stovepipemq.ProcessRequest{Id: id}) + b, err := stovepipemq.Marshal(&stovepipemq.ProcessRequest{Id: id, QueueName: testQueue}) require.NoError(t, err) return b } @@ -133,7 +139,7 @@ func TestProcessBuildPublishRequiresRegisteredTopic(t *testing.T) { ID: testID, Queue: testQueue, State: entity.RequestStateProcessing, Version: 2, }, nil) - err := c.Process(context.Background(), delivery(t, ctrl, processPayload(t, testID))) + err := c.Process(queueContext(testQueue), delivery(t, ctrl, processPayload(t, testID))) require.Error(t, err) assert.False(t, errs.IsRetryable(err)) @@ -166,6 +172,7 @@ func expectBuildPublish(t *testing.T, m processMocks, id string) { DoAndReturn(func(_ context.Context, _ string, msg entityqueue.Message) error { assert.Equal(t, id, msg.ID) assert.Equal(t, id, msg.PartitionKey) + assert.Equal(t, testQueue, msg.Metadata[entityqueue.MetadataKeyQueueName]) buildReq := &stovepipemq.BuildRequest{} require.NoError(t, stovepipemq.Unmarshal(msg.Payload, buildReq)) assert.Equal(t, id, buildReq.Id) @@ -236,7 +243,7 @@ func TestDeriveBuildStrategy(t *testing.T) { if tt.queue.LastGreenURI != "" { sc = m.sourceControl } - strategy, baseURI, err := c.deriveBuildStrategy(context.Background(), sc, tt.queue, acceptedRequest(testID)) + strategy, baseURI, err := c.deriveBuildStrategy(queueContext(tt.queue.Name), sc, tt.queue, acceptedRequest(testID)) if tt.wantErr { require.Error(t, err) @@ -280,7 +287,7 @@ func TestDeriveBuildStrategyEmitsSourceControlMetrics(t *testing.T) { m.sourceControl.EXPECT().IsAncestor(gomock.Any(), lastGreenURI, testURI).Return(false, tt.ancestryErr) _, _, err := c.deriveBuildStrategy( - context.Background(), + queueContext(testQueue), m.sourceControl, entity.Queue{Name: testQueue, LastGreenURI: lastGreenURI}, acceptedRequest(testID), @@ -291,7 +298,7 @@ func TestDeriveBuildStrategyEmitsSourceControlMetrics(t *testing.T) { } else { require.Error(t, err) } - counter, ok := scope.Snapshot().Counters()["test.process_controller.process."+tt.metricName+"+"+tt.metricTags] + counter, ok := scope.Snapshot().Counters()["test.process_controller.process."+tt.metricName+"+queue="+testQueue+","+tt.metricTags] require.True(t, ok) assert.Equal(t, int64(1), counter.Value()) }) @@ -311,9 +318,9 @@ func TestProcessEmitsAdmittedStrategyMetric(t *testing.T) { }, nil) expectAdmit(t, m, testID) - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, processPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(testQueue), delivery(t, ctrl, processPayload(t, testID)))) - counter, ok := scope.Snapshot().Counters()["test.process_controller.process.admitted+strategy=full"] + counter, ok := scope.Snapshot().Counters()["test.process_controller.process.admitted+queue=monorepo/main,strategy=full"] require.True(t, ok) assert.Equal(t, int64(1), counter.Value()) } @@ -336,9 +343,9 @@ func TestProcessEmitsSourceControlResolutionMetric(t *testing.T) { For(sourcecontrol.Config{QueueName: testQueue}). Return(nil, errors.New("source control unavailable")) - require.Error(t, c.Process(context.Background(), delivery(t, ctrl, processPayload(t, testID)))) + require.Error(t, c.Process(queueContext(testQueue), delivery(t, ctrl, processPayload(t, testID)))) - counter, ok := scope.Snapshot().Counters()["test.process_controller.process.source_control_errors+stage=resolve"] + counter, ok := scope.Snapshot().Counters()["test.process_controller.process.source_control_errors+queue=monorepo/main,stage=resolve"] require.True(t, ok) assert.Equal(t, int64(1), counter.Value()) } @@ -403,7 +410,7 @@ func TestProcessRederivesStrategyAfterQueueReload(t *testing.T) { m.reqStore.EXPECT().Update(gomock.Any(), updatedRequest, int32(1), int32(2)).Return(nil) expectBuildPublish(t, m, testID) - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, processPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(testQueue), delivery(t, ctrl, processPayload(t, testID)))) }) } } @@ -803,7 +810,7 @@ func TestProcess(t *testing.T) { d.EXPECT().Hold(tt.wantHoldMs) } - err := c.Process(context.Background(), d) + err := c.Process(queueContext(testQueue), d) if tt.wantErr { require.Error(t, err) @@ -825,7 +832,7 @@ func TestHoldForBuildSlotRequiresPositiveDelay(t *testing.T) { d := consumermock.NewMockDelivery(ctrl) // No Hold expectation: the guard must reject before recording a hold. - err := c.holdForBuildSlot(d, acceptedRequest(testID), 1, 0) + err := c.holdForBuildSlot(queueContext(testQueue), d, acceptedRequest(testID), 1, 0) require.Error(t, err) assert.False(t, errs.IsRetryable(err)) diff --git a/stovepipe/controller/record/BUILD.bazel b/stovepipe/controller/record/BUILD.bazel index c131992f3..03b8cbc07 100644 --- a/stovepipe/controller/record/BUILD.bazel +++ b/stovepipe/controller/record/BUILD.bazel @@ -26,6 +26,7 @@ go_test( "//platform/base/messagequeue:go_default_library", "//platform/consumer:go_default_library", "//platform/consumer/mock:go_default_library", + "//platform/metrics:go_default_library", "//stovepipe/core/messagequeue:go_default_library", "//stovepipe/entity:go_default_library", "//stovepipe/extension/sourcecontrol:go_default_library", diff --git a/stovepipe/controller/record/record.go b/stovepipe/controller/record/record.go index 5f7727605..f41b49afe 100644 --- a/stovepipe/controller/record/record.go +++ b/stovepipe/controller/record/record.go @@ -96,28 +96,27 @@ func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) er rec := &stovepipemq.Record{} if err := stovepipemq.Unmarshal(msg.Payload, rec); err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "deserialize_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "deserialize_errors", 1, metrics.TagsFromContext(ctx)...) // Non-retryable: a malformed message will never succeed regardless of retries. return fmt.Errorf("failed to deserialize record: %w", err) } - store, err := c.stores.For(storage.Config{QueueName: rec.GetQueueName()}) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_resolve_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_resolve_errors", 1, metrics.TagsFromContext(ctx)...) // Non-retryable: a missing or unresolvable queue is a malformed message. return fmt.Errorf("failed to resolve storage for queue %q: %w", rec.GetQueueName(), err) } request, err := c.loadRequest(ctx, store, rec.Id) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1, metrics.TagsFromContext(ctx)...) return err } // The payload's queue must match the request's authoritative queue; a // mismatch is a malformed message. Non-retryable — reject to the DLQ. if rec.GetQueueName() != "" && rec.GetQueueName() != request.Queue { - metrics.NamedCounter(c.metricsScope, _opName, "queue_mismatch", 1) + metrics.NamedCounter(c.metricsScope, _opName, "queue_mismatch", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("payload queue %q does not match queue %q of request %s", rec.GetQueueName(), request.Queue, request.ID) } @@ -128,7 +127,7 @@ func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) er return err } if !fact.IsGreen() { - metrics.NamedCounter(c.metricsScope, _opName, "not_green", 1) + metrics.NamedCounter(c.metricsScope, _opName, "not_green", 1, metrics.TagsFromContext(ctx)...) // Only the writer of the fact reports the latency: a redelivery adopts // the stored fact instead, and a second sample would count one break // twice in the distribution. @@ -139,7 +138,7 @@ func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) er } holdsBookmark, err := c.advanceLastGreen(ctx, store, request) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1, metrics.TagsFromContext(ctx)...) return err } if !holdsBookmark { @@ -153,20 +152,20 @@ func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) er case entity.RequestStateCancelled: // A cancelled build decided nothing about the commit, so it establishes // no fact. The identity stays unclaimed; the next commit re-validates. - metrics.NamedCounter(c.metricsScope, _opName, "cancelled", 1) + metrics.NamedCounter(c.metricsScope, _opName, "cancelled", 1, metrics.TagsFromContext(ctx)...) return nil case entity.RequestStateSuperseded: // Terminal without a build outcome. buildsignal never publishes for a // superseded request, so this is unreachable in practice. - metrics.NamedCounter(c.metricsScope, _opName, "superseded", 1) + metrics.NamedCounter(c.metricsScope, _opName, "superseded", 1, metrics.TagsFromContext(ctx)...) return nil default: // Non-retryable: buildsignal publishes only after committing the // outcome, so a non-terminal request here is a broken invariant that // retrying cannot fix. - metrics.NamedCounter(c.metricsScope, _opName, "invariant_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "invariant_errors", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("request %s reached record in non-terminal state %q", request.ID, request.State) } } @@ -193,7 +192,7 @@ func (c *Controller) recordFact(ctx context.Context, store storage.Storage, requ err := factStore.Create(ctx, fact) switch { case err == nil: - metrics.NamedCounter(c.metricsScope, _opName, "fact_created", 1) + metrics.NamedCounter(c.metricsScope, _opName, "fact_created", 1, metrics.TagsFromContext(ctx)...) c.logger.Infow("recorded validation fact", "queue", request.Queue, "request_id", request.ID, @@ -205,22 +204,22 @@ func (c *Controller) recordFact(ctx context.Context, store storage.Storage, requ case errors.Is(err, storage.ErrAlreadyExists): stored, getErr := factStore.Get(ctx, request.URI, wholeRepositoryProject) if getErr != nil { - metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1, metrics.TagsFromContext(ctx)...) return entity.ValidationFact{}, false, fmt.Errorf("failed to load the existing fact for uri %s: %w", request.URI, getErr) } if stored.RequestID != request.ID { // Two requests validating one URI would break the dedup ingest // enforces, so this is a broken invariant rather than a race to // resolve. Non-retryable: the stored fact is immutable. - metrics.NamedCounter(c.metricsScope, _opName, "invariant_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "invariant_errors", 1, metrics.TagsFromContext(ctx)...) return entity.ValidationFact{}, false, fmt.Errorf( "fact for uri %s is owned by request %s, not %s", request.URI, stored.RequestID, request.ID) } - metrics.NamedCounter(c.metricsScope, _opName, "fact_exists", 1) + metrics.NamedCounter(c.metricsScope, _opName, "fact_exists", 1, metrics.TagsFromContext(ctx)...) return stored, false, nil default: - metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1) + metrics.NamedCounter(c.metricsScope, _opName, "storage_errors", 1, metrics.TagsFromContext(ctx)...) return entity.ValidationFact{}, false, fmt.Errorf("failed to create the fact for uri %s: %w", request.URI, err) } } @@ -236,26 +235,25 @@ func (c *Controller) recordFact(ctx context.Context, store storage.Storage, requ // confined to failures and made once the fact is durable, and every way it can fail is // counted and swallowed so a reporting fault cannot retry an outcome already recorded. func (c *Controller) reportFailureDetectionLatency(ctx context.Context, request entity.Request) { - queueTag := metrics.NewTag("queue", request.Queue) strategyTag := metrics.NewTag("strategy", string(request.BuildStrategy)) // Only a strategy that validates a delta pins a base commit, so a full build has // no baseline to measure from. Its failures are counted rather than timed: absent // here is the ordinary case, not a fault. if request.BaseURI == "" { - metrics.NamedCounter(c.metricsScope, _opName, "failure_detection_missing", 1, queueTag, strategyTag) + metrics.NamedCounter(c.metricsScope, _opName, "failure_detection_missing", 1, metrics.TagsFromContext(ctx, strategyTag)...) return } sourceControl, err := c.sourceControl.For(sourcecontrol.Config{QueueName: request.Queue}) if err != nil { - c.failureDetectionUnobserved(request, "resolve_source_control", err) + c.failureDetectionUnobserved(ctx, request, "resolve_source_control", err) return } info, err := sourceControl.ChangeInfo(ctx, request.BaseURI) if err != nil { - c.failureDetectionUnobserved(request, "get_change_info", err) + c.failureDetectionUnobserved(ctx, request, "get_change_info", err) return } @@ -263,7 +261,7 @@ func (c *Controller) reportFailureDetectionLatency(ctx context.Context, request // broken extension contract rather than a lookup failure. Measuring from 1970 // would drop a decades-long sample into the distribution. if info.CreatedAt <= 0 { - c.failureDetectionUnobserved(request, "undated_change", nil) + c.failureDetectionUnobserved(ctx, request, "undated_change", nil) return } @@ -271,22 +269,21 @@ func (c *Controller) reportFailureDetectionLatency(ctx context.Context, request // negative latency would corrupt the distribution rather than describe it. latency := time.Since(time.UnixMilli(info.CreatedAt)) if latency < 0 { - c.failureDetectionUnobserved(request, "future_change", nil) + c.failureDetectionUnobserved(ctx, request, "future_change", nil) return } metrics.NamedHistogram(c.metricsScope, _opName, "failure_detection_latency", metrics.ChangeAgeBuckets, - queueTag, strategyTag, + metrics.TagsFromContext(ctx, strategyTag)..., ).RecordDuration(latency) } // failureDetectionUnobserved counts a latency that could not be observed, tagged with // the step that failed so an unmeasurable failure can be told apart from a broken // dependency. -func (c *Controller) failureDetectionUnobserved(request entity.Request, step string, err error) { +func (c *Controller) failureDetectionUnobserved(ctx context.Context, request entity.Request, step string, err error) { metrics.NamedCounter(c.metricsScope, _opName, "failure_detection_errors", 1, - metrics.NewTag("queue", request.Queue), - metrics.NewTag("step", step), + metrics.TagsFromContext(ctx, metrics.NewTag("step", step))..., ) c.logger.Warnw("failed to observe how long the build failure went undetected", "queue", request.Queue, @@ -348,7 +345,7 @@ func (c *Controller) advanceLastGreen(ctx context.Context, store storage.Storage return false, fmt.Errorf("failed to advance last green for queue %s: %w", request.Queue, err) } - metrics.NamedCounter(c.metricsScope, _opName, "last_green_advanced", 1) + metrics.NamedCounter(c.metricsScope, _opName, "last_green_advanced", 1, metrics.TagsFromContext(ctx)...) c.logger.Infow("advanced last green bookmark", "queue", request.Queue, "request_id", request.ID, @@ -364,11 +361,9 @@ func (c *Controller) advanceLastGreen(ctx context.Context, store storage.Storage // observability failure cannot turn a successful record operation into a retry, // which is why each cause is counted and logged separately instead of returned. func (c *Controller) emitLastGreenTimestamp(ctx context.Context, request entity.Request) { - queueTag := metrics.NewTag("queue", request.Queue) - sourceControl, err := c.sourceControl.For(sourcecontrol.Config{QueueName: request.Queue}) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "last_green_timestamp_resolve_errors", 1, queueTag) + metrics.NamedCounter(c.metricsScope, _opName, "last_green_timestamp_resolve_errors", 1, metrics.TagsFromContext(ctx)...) c.logger.Warnw("failed to resolve source control to report the last green timestamp", "queue", request.Queue, "error", err, @@ -378,7 +373,7 @@ func (c *Controller) emitLastGreenTimestamp(ctx context.Context, request entity. info, err := sourceControl.ChangeInfo(ctx, request.URI) if err != nil { - metrics.NamedCounter(c.metricsScope, _opName, "last_green_timestamp_errors", 1, queueTag) + metrics.NamedCounter(c.metricsScope, _opName, "last_green_timestamp_errors", 1, metrics.TagsFromContext(ctx)...) c.logger.Warnw("failed to look up the last green change timestamp", "queue", request.Queue, "uri", request.URI, @@ -391,7 +386,7 @@ func (c *Controller) emitLastGreenTimestamp(ctx context.Context, request entity. // is a broken extension contract rather than a lookup failure. Emitting it // anyway would publish a 1970 timestamp and read as an infinitely stale queue. if info.CreatedAt <= 0 { - metrics.NamedCounter(c.metricsScope, _opName, "last_green_timestamp_invalid", 1, queueTag) + metrics.NamedCounter(c.metricsScope, _opName, "last_green_timestamp_invalid", 1, metrics.TagsFromContext(ctx)...) c.logger.Warnw("source control reported no creation timestamp for the last green change", "queue", request.Queue, "uri", request.URI, @@ -407,7 +402,7 @@ func (c *Controller) emitLastGreenTimestamp(ctx context.Context, request entity. _opName, "last_green_timestamp_seconds", float64(time.UnixMilli(info.CreatedAt).Unix()), - queueTag, + metrics.TagsFromContext(ctx)..., ) } @@ -424,7 +419,7 @@ func (c *Controller) promote(ctx context.Context, request entity.Request) error sc, err := c.sourceControl.For(sourcecontrol.Config{QueueName: request.Queue}) if err != nil { metrics.NamedCounter(c.metricsScope, _opName, "source_control_errors", 1, - metrics.NewTag("stage", "resolve"), + metrics.TagsFromContext(ctx, metrics.NewTag("stage", "resolve"))..., ) return fmt.Errorf("failed to resolve source control for queue %s: %w", request.Queue, err) } @@ -432,7 +427,7 @@ func (c *Controller) promote(ctx context.Context, request entity.Request) error if err := sc.Promote(ctx, request.URI); err != nil { if sourcecontrol.IsNotFound(err) { metrics.NamedCounter(c.metricsScope, _opName, "promotions_skipped", 1, - metrics.NewTag("reason", "unknown_uri"), + metrics.TagsFromContext(ctx, metrics.NewTag("reason", "unknown_uri"))..., ) c.logger.Warnw("green commit is no longer on the queue's ref; skipping promotion", "queue", request.Queue, @@ -443,12 +438,12 @@ func (c *Controller) promote(ctx context.Context, request entity.Request) error } metrics.NamedCounter(c.metricsScope, _opName, "source_control_errors", 1, - metrics.NewTag("stage", "promote"), + metrics.TagsFromContext(ctx, metrics.NewTag("stage", "promote"))..., ) return fmt.Errorf("failed to promote uri %s of queue %s: %w", request.URI, request.Queue, err) } - metrics.NamedCounter(c.metricsScope, _opName, "promotions", 1) + metrics.NamedCounter(c.metricsScope, _opName, "promotions", 1, metrics.TagsFromContext(ctx)...) c.logger.Infow("promoted green commit", "queue", request.Queue, "request_id", request.ID, diff --git a/stovepipe/controller/record/record_test.go b/stovepipe/controller/record/record_test.go index 02aeda08a..bcbbee602 100644 --- a/stovepipe/controller/record/record_test.go +++ b/stovepipe/controller/record/record_test.go @@ -26,6 +26,7 @@ import ( entityqueue "github.com/uber/submitqueue/platform/base/messagequeue" "github.com/uber/submitqueue/platform/consumer" consumermock "github.com/uber/submitqueue/platform/consumer/mock" + "github.com/uber/submitqueue/platform/metrics" stovepipemq "github.com/uber/submitqueue/stovepipe/core/messagequeue" "github.com/uber/submitqueue/stovepipe/entity" "github.com/uber/submitqueue/stovepipe/extension/sourcecontrol" @@ -43,6 +44,11 @@ const ( testBaseURI = "git://remote/monorepo/main/base-sha" ) +func queueContext() context.Context { + ctx := entityqueue.WithQueueName(context.Background(), testQueue) + return metrics.WithContextTags(ctx, metrics.NewTag("queue", testQueue)) +} + // Metric names as they appear in a snapshot, so a case asserts on the series an // operator queries rather than on how the emit is composed. const ( @@ -228,7 +234,7 @@ func TestProcess_AdvancesBookmarkOnSuccess(t *testing.T) { Return(sourcecontrol.ChangeInfo{CreatedAt: testChangeTime.UnixMilli()}, nil) m.sourceControl.EXPECT().Promote(gomock.Any(), testURI).Return(nil) - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) assert.Equal(t, tt.wantURI, written.LastGreenURI) assert.Equal(t, testID, written.LastGreenRequestID) @@ -281,7 +287,7 @@ func TestProcess_TimestampReportingFailureDoesNotFailRecord(t *testing.T) { m.sourceControl.EXPECT().ChangeInfo(gomock.Any(), testURI).Return(tt.info, tt.err) m.sourceControl.EXPECT().Promote(gomock.Any(), testURI).Return(nil) - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) assert.Empty(t, m.metricsScope.Snapshot().Gauges()) counter, ok := m.metricsScope.Snapshot().Counters()[tt.wantCounter] require.True(t, ok) @@ -305,7 +311,7 @@ func TestProcess_UnresolvableSourceControlCountsTimestampFailure(t *testing.T) { m.queueStore.EXPECT().Get(gomock.Any(), testQueue).Return(queueRow("", "", 1), nil) m.queueStore.EXPECT().Update(gomock.Any(), gomock.Any(), int32(1), int32(2)).Return(nil) - require.Error(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.Error(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) assert.Empty(t, m.metricsScope.Snapshot().Gauges()) counter, ok := m.metricsScope.Snapshot().Counters()["record_controller.record.last_green_timestamp_resolve_errors+queue=monorepo/main"] require.True(t, ok) @@ -323,9 +329,12 @@ func TestProcess_RecordsBrokenFactWithoutAdvancing(t *testing.T) { m.expectFactCreated(&fact) // No queue reads or writes: a broken fact never moves the bookmark. - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) assert.Equal(t, entity.DegreeBroken, fact.Degree) assert.False(t, fact.IsGreen()) + counter, ok := m.metricsScope.Snapshot().Counters()["record_controller.record.not_green+queue=monorepo/main"] + require.True(t, ok) + assert.EqualValues(t, 1, counter.Value()) } func TestProcess_ReportsFailureDetectionLatency(t *testing.T) { @@ -338,7 +347,7 @@ func TestProcess_ReportsFailureDetectionLatency(t *testing.T) { m.sourceControl.EXPECT().ChangeInfo(gomock.Any(), testBaseURI). Return(sourcecontrol.ChangeInfo{CreatedAt: time.Now().Add(-time.Hour).UnixMilli()}, nil) - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) histogram, ok := m.metricsScope.Snapshot().Histograms()[failureDetectionLatency] require.True(t, ok) @@ -360,7 +369,7 @@ func TestProcess_FullBuildFailureHasNoBaseline(t *testing.T) { var fact entity.ValidationFact m.expectFactCreated(&fact) - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) snapshot := m.metricsScope.Snapshot() assert.Empty(t, snapshot.Histograms(), "a build with no baseline has no latency to report") @@ -381,7 +390,7 @@ func TestProcess_RedeliveredFailureIsNotResampled(t *testing.T) { m.factStore.EXPECT().Get(gomock.Any(), testURI, wholeRepositoryProject). Return(entity.ValidationFact{URI: testURI, Degree: entity.DegreeBroken, RequestID: testID}, nil) - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) assert.Empty(t, m.metricsScope.Snapshot().Histograms()) } @@ -437,7 +446,7 @@ func TestProcess_UnobservableDetectionLatencyDoesNotFailRecord(t *testing.T) { var fact entity.ValidationFact m.expectFactCreated(&fact) - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) snapshot := m.metricsScope.Snapshot() assert.Empty(t, snapshot.Histograms(), "no latency may be reported when it cannot be observed") @@ -485,7 +494,7 @@ func TestProcess_AdoptsExistingFactFromSameRequest(t *testing.T) { m.sourceControl.EXPECT().Promote(gomock.Any(), testURI).Return(nil) } - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) }) } } @@ -501,7 +510,7 @@ func TestProcess_ExistingFactFromDifferentRequestFails(t *testing.T) { Return(entity.ValidationFact{URI: testURI, Degree: entity.DegreeGreen, RequestID: "request/monorepo/main/1"}, nil) // The bookmark must not move on an identity this request does not own. - require.Error(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.Error(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) } func TestProcess_SkipsBookmarkWhenNotNewer(t *testing.T) { @@ -541,7 +550,7 @@ func TestProcess_SkipsBookmarkWhenNotNewer(t *testing.T) { m.sourceControl.EXPECT().Promote(gomock.Any(), testURI).Return(nil) } - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) assert.NotContains( t, m.metricsScope.Snapshot().Gauges(), @@ -568,7 +577,7 @@ func TestProcess_SkipsPromotionWhenCommitLeftTheRef(t *testing.T) { // it, so the message is acked rather than sent round again. m.sourceControl.EXPECT().Promote(gomock.Any(), testURI).Return(sourcecontrol.ErrNotFound) - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) } func TestProcess_PromotionErrorsPropagate(t *testing.T) { @@ -607,7 +616,7 @@ func TestProcess_PromotionErrorsPropagate(t *testing.T) { // The bookmark already advanced, so the redelivery re-promotes the // same commit; failing here is what makes that retry happen. - require.Error(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.Error(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) }) } } @@ -629,7 +638,7 @@ func TestProcess_TerminalWithoutFactDoesNotTouchStores(t *testing.T) { m.reqStore.EXPECT().Get(gomock.Any(), testID).Return(requestWithState(tt.state), nil) // Neither a fact nor a queue write: these outcomes decide nothing. - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) }) } } @@ -651,7 +660,7 @@ func TestProcess_NonTerminalRequestFails(t *testing.T) { m.reqStore.EXPECT().Get(gomock.Any(), testID).Return(requestWithState(tt.state), nil) - require.Error(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.Error(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) }) } } @@ -680,7 +689,7 @@ func TestProcess_RetriesBookmarkOnVersionMismatch(t *testing.T) { Return(sourcecontrol.ChangeInfo{CreatedAt: testChangeTime.UnixMilli()}, nil) m.sourceControl.EXPECT().Promote(gomock.Any(), testURI).Return(nil) - require.NoError(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) } func TestProcess_MalformedRequestIDFails(t *testing.T) { @@ -694,7 +703,7 @@ func TestProcess_MalformedRequestIDFails(t *testing.T) { m.queueStore.EXPECT().Get(gomock.Any(), testQueue). Return(queueRow("git://remote/monorepo/main/old", "not-a-request-id", 1), nil) - require.Error(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.Error(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) } func TestProcess_StorageErrorsPropagate(t *testing.T) { @@ -758,7 +767,7 @@ func TestProcess_StorageErrorsPropagate(t *testing.T) { c, m := newController(t, ctrl) tt.setup(m) - require.Error(t, c.Process(context.Background(), delivery(t, ctrl, recordPayload(t, testID)))) + require.Error(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) }) } } @@ -767,7 +776,7 @@ func TestProcess_MalformedPayloadFails(t *testing.T) { ctrl := gomock.NewController(t) c, _ := newController(t, ctrl) - require.Error(t, c.Process(context.Background(), delivery(t, ctrl, []byte("not-protojson")))) + require.Error(t, c.Process(queueContext(), delivery(t, ctrl, []byte("not-protojson")))) } func TestProcess_QueueMismatchFails(t *testing.T) { @@ -782,5 +791,5 @@ func TestProcess_QueueMismatchFails(t *testing.T) { payload, err := stovepipemq.Marshal(&stovepipemq.Record{Id: testID, QueueName: "monorepo/other"}) require.NoError(t, err) - require.Error(t, c.Process(context.Background(), delivery(t, ctrl, payload))) + require.Error(t, c.Process(queueContext(), delivery(t, ctrl, payload))) }