diff --git a/doc/rfc/stovepipe/request-log.md b/doc/rfc/stovepipe/request-log.md index a16820a3b..965dabb54 100644 --- a/doc/rfc/stovepipe/request-log.md +++ b/doc/rfc/stovepipe/request-log.md @@ -9,7 +9,9 @@ Stovepipe retains an append-only request log for each validation request. Its in - `validation_fact_recorded`; - `project_facts_recorded`; - `record_abandoned`; -- `build_analysis_abandoned`. +- `build_analysis_abandoned`; +- `build_analysis_completed`; +- `repair_submitted`. The model deliberately follows SubmitQueue's distinction between statuses describing where a request is and events describing important activity that does not move it. It remains a bounded request-lifecycle log rather than a generic event bus or an audit of every correlated operation. @@ -34,7 +36,7 @@ The following remain with their owning entities, metrics, or structured logs: - Queue latest-request and last-green bookmarks; - source-control promotion; -- project analysis and individual project facts; +- individual issue observations and project facts; - hooks and downstream notifications; - build-slot claims, waits, and releases; - queue handoffs, delivery attempts, holds, nacks, and visibility timeouts; @@ -103,7 +105,7 @@ The core column shape follows SubmitQueue's `RequestLog`, except Stovepipe omits Metadata is never used for occurrence identity, filtering, or control flow. Nil and empty maps are equivalent. The initial entity and storage contract treats the map as opaque JSON; writer and projection work may later define and enforce keys such as `superseded_by_request_id`, `build_id`, and `fact_degree`. Producers must not store credentials, raw dependency errors, stack traces, or unbounded payloads. The initial public history API does not expose the raw map. -Immutable Request context such as URI, build strategy, base URI, and terminal build id remains on `Request` and is resolved there rather than copied into log records or history responses. Build status and version remain on `Build`; the triggered and finished event kinds plus the terminal Request state describe the lifecycle without duplicating Build snapshots. When a build established the terminal state, that state entry records its id as occurrence context. Diagnostic error codes remain in structured logs until a concrete public vocabulary is required. +The URI, selected build strategy and baseline, and terminal build ID remain durable context on `Request`. State-log writers copy the relevant context into metadata so retries can reproduce the same occurrence. Build status and version remain on `Build`; the triggered and finished event kinds plus the terminal Request state describe the lifecycle without duplicating Build snapshots. When a build established the terminal state, that state entry records its id as occurrence context. Record failures carry a bounded `record_stage` in their structured failure attribution. The DLQ retains only recognized stage values in `record_abandoned` metadata; missing or unrecognized values become `unknown`. Raw error messages remain in structured logs. ## Vocabularies @@ -126,8 +128,12 @@ Immutable Request context such as URI, build strategy, base URI, and terminal bu | `build_finished` | The Build first reached a write-once terminal status. | Build ID metadata and status-change time | | `validation_fact_recorded` | The immutable whole-repository fact became durable. | Degree metadata and fact creation time | | `project_facts_recorded` | All project validation facts returned for a request became durable. | Project-fact count metadata and completion time | -| `record_abandoned` | Record-stage work stopped after exhausting primary retries. | Event retention time | +| `record_abandoned` | Record-stage work stopped; earlier facts may already be durable. | Bounded `record_stage` metadata and event retention time | | `build_analysis_abandoned` | Build analysis could not complete; issue observations may be incomplete. This is not a validation verdict. | Build ID metadata and event retention time | +| `build_analysis_completed` | Final analysis of a terminal build completed and its issue observations are durable, including an empty result. | Build ID metadata and event retention time | +| `repair_submitted` | A submitted repair ID was durably associated with a build issue. This does not assert repair completion. | Build ID, fix ID, task ID, unit ID metadata and event retention time | + +The bounded record stages are `prepare`, `resolve_project_results`, `record_validation_fact`, `retain_validation_fact`, `record_project_facts`, `apply_derived_caches`, and `publish_notification`. `record_abandoned` identifies the incomplete part of the stage without retracting facts already recorded. In particular, promotion or notification failure does not change the validation verdict. Build running and unchanged polls are not retained. Trigger and terminal result explain the request outcome without turning polling into an unbounded log. Individual project facts remain outside the vocabulary; one batch-completion event summarizes their durable recording. @@ -162,8 +168,10 @@ SubmitQueue applies that identity to the message carrying a log to its materiali | Build finished | Request ID, event kind, and build ID | | Validation fact recorded | Request ID, event kind, and whole-repository fact identity | | Project facts recorded | Request ID, event kind, and the completed project-fact batch | +| Build analysis completed | Request ID, event kind, and build ID | +| Repair submitted | Request ID, event kind, and a bounded hash of the build, task, unit, and fix IDs | -The controller passes the materializer the same queue-scoped storage aggregate used for the source write. The materializer preserves a supplied occurrence time or assigns the current time immediately before the first insertion attempt, then calls `RequestLogStore.Create`. If the ID already exists, it loads the stored record and compares the explicitly designated stable semantic fields. The first successfully retained timestamp is authoritative and is not compared with a later retry's newly sampled time. Metadata keys emitted by both records must agree, while a key present on only one record remains compatible so an additive metadata rollout does not turn retries of older occurrences into conflicts. Compatible content is idempotent success; conflicting content is an internal consistency error, and the stored record is never overwritten or enriched. +The controller passes the materializer the same queue-scoped storage aggregate used for the source write. The materializer preserves a supplied occurrence time or assigns the current time immediately before the first insertion attempt, then calls `RequestLogStore.Create`. If the ID already exists, it loads the stored record and compares the explicitly designated stable semantic fields. The first successfully retained timestamp is authoritative and is not compared with a later retry's newly sampled time. Metadata keys emitted by both records must agree, except that `superseded_by_request_id` may identify different newer heads for the same superseded transition; the first retained value remains authoritative. A key present on only one record remains compatible so an additive metadata rollout does not turn retries of older occurrences into conflicts. Compatible content is idempotent success; conflicting content is an internal consistency error, and the stored record is never overwritten or enriched. ## Storage Contract @@ -218,9 +226,13 @@ The `project_facts_recorded` event also projects its retained timestamp into `Re | Buildsignal | Persist terminal Build and retain `build_finished`; CAS the Request outcome and retain its terminal state. | Existing terminal Build and Request outcome each ensure their own entry before record publication. | | Record | Create or verify the whole-repository fact, then retain `validation_fact_recorded`; after recording project facts, retain one `project_facts_recorded` event. | An identical whole-repository fact and project-fact batch ensure their events before bookmark or promotion work. | | Record DLQ | Retain `record_abandoned`, then acknowledge the remaining record work. | The stable event ID makes history retention idempotent without replaying facts, bookmarks, promotion, or hooks. | +| Build analysis | Persist final observations, then retain `build_analysis_completed` for a terminal build. | A repeated final pass verifies existing observations and retries the same history occurrence before acknowledgment. | | Build analysis DLQ | Retain `build_analysis_abandoned` without rerunning detection or changing validation state. | One stable event per build deduplicates recovery deliveries; only state reads and history retention retry. | +| Fix | Persist the repair association, then retain `repair_submitted`. | An existing fix ID repairs history without calling the executor again; a concurrent association uses the stored winner. | | Reconciler | CAS an unrecoverable non-terminal Request to failed, then retain failed. | An existing terminal Request is repaired from its persisted outcome without relabeling it. | +Supersession records an observed newer queue head as `superseded_by_request_id` history metadata. If retention fails, a retry may observe a later head: any newer head explains the same superseded transition. The first retained occurrence stays immutable, including its observed head. If the queue bookmark is empty or stale during repair, the metadata is omitted rather than inventing a replacement. + Build running and unchanged polls create no entry. A failed runner trigger that creates no Build creates no event. Cancelled and superseded requests create no validation fact. No controller infers an outcome reason from `RequestStateFailed` alone, invents a broken fact, or records DLQ as the domain reason. @@ -277,7 +289,7 @@ Rejected because bookmarks, promotion, project facts, hooks, and operational boo ### Use a generic versioned envelope -Rejected for six request states and three explanatory events. Explicit fields are simpler to inspect, constrain, test, and expose. A future migration should be justified by actual vocabulary growth. +Rejected for the bounded request-state and explanatory-event vocabulary. Explicit fields are simpler to inspect, constrain, test, and expose. A future migration should be justified by actual vocabulary growth. ### Copy SubmitQueue's log topic diff --git a/service/stovepipe/server/main.go b/service/stovepipe/server/main.go index f13f8b8cb..b88f4c2ff 100644 --- a/service/stovepipe/server/main.go +++ b/service/stovepipe/server/main.go @@ -409,7 +409,7 @@ func registerPrimaryControllers( } count++ - analysisController := buildanalysis.NewController(logger, scope, store, detectorFactory, stovepipemq.TopicKeyBuildAnalysis, "stovepipe-buildanalysis") + analysisController := buildanalysis.NewController(logger, scope, store, materializer, detectorFactory, stovepipemq.TopicKeyBuildAnalysis, "stovepipe-buildanalysis") if err := c.Register(analysisController); err != nil { return count, fmt.Errorf("failed to register buildanalysis controller: %w", err) } diff --git a/stovepipe/controller/build/build_analysis_test.go b/stovepipe/controller/build/build_analysis_test.go index e6b2cfcfd..04bc79b6c 100644 --- a/stovepipe/controller/build/build_analysis_test.go +++ b/stovepipe/controller/build/build_analysis_test.go @@ -118,7 +118,7 @@ func TestBuildAnalysisPipeline(t *testing.T) { ) analysisController := buildanalysis.NewController(zap.NewNop().Sugar(), tally.NoopScope, - staticStorageFactory{store: m.store}, detectorFactory, stovepipemq.TopicKeyBuildAnalysis, "analysis") + staticStorageFactory{store: m.store}, m.materializer, detectorFactory, stovepipemq.TopicKeyBuildAnalysis, "analysis") statusController := buildsignal.NewController(zap.NewNop().Sugar(), tally.NoopScope, staticStorageFactory{store: m.store}, m.materializer, m.runnerFactory, buildController.registry, stovepipemq.TopicKeyBuildSignal, "signal") diff --git a/stovepipe/controller/buildanalysis/buildanalysis.go b/stovepipe/controller/buildanalysis/buildanalysis.go index 4ebaff55e..2027a9012 100644 --- a/stovepipe/controller/buildanalysis/buildanalysis.go +++ b/stovepipe/controller/buildanalysis/buildanalysis.go @@ -27,6 +27,7 @@ import ( "github.com/uber/submitqueue/platform/metrics" "github.com/uber/submitqueue/stovepipe/core/loader" stovepipemq "github.com/uber/submitqueue/stovepipe/core/messagequeue" + "github.com/uber/submitqueue/stovepipe/core/requestlog" "github.com/uber/submitqueue/stovepipe/entity" "github.com/uber/submitqueue/stovepipe/extension/buildissue" "github.com/uber/submitqueue/stovepipe/extension/storage" @@ -43,6 +44,7 @@ type Controller struct { logger *zap.SugaredLogger metricsScope tally.Scope stores storage.Factory + materializer requestlog.Materializer detectorFactory buildissue.DetectorFactory topicKey consumer.TopicKey consumerGroup string @@ -52,6 +54,7 @@ func NewController( logger *zap.SugaredLogger, scope tally.Scope, stores storage.Factory, + materializer requestlog.Materializer, detectorFactory buildissue.DetectorFactory, topicKey consumer.TopicKey, consumerGroup string, @@ -60,6 +63,7 @@ func NewController( logger: logger.Named("buildanalysis_controller"), metricsScope: scope.SubScope("buildanalysis_controller"), stores: stores, + materializer: materializer, detectorFactory: detectorFactory, topicKey: topicKey, consumerGroup: consumerGroup, @@ -141,6 +145,12 @@ func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) (r // even if the build finishes while detection is running. if !build.Status.IsTerminal() { delivery.Hold(PollDelayMs) + } else { + log := requestlog.NewRequestEventLog(request, entity.RequestEventBuildAnalysisCompleted, build.ID, + map[string]string{requestlog.MetadataKeyBuildID: build.ID}) + if err := c.materializer.PersistLog(ctx, store, log); err != nil { + return fmt.Errorf("failed to retain completed build analysis for request %s: %w", request.ID, err) + } } c.logger.Debugw("build analysis pass complete", diff --git a/stovepipe/controller/buildanalysis/buildanalysis_test.go b/stovepipe/controller/buildanalysis/buildanalysis_test.go index 2cb3376e3..34cf8f037 100644 --- a/stovepipe/controller/buildanalysis/buildanalysis_test.go +++ b/stovepipe/controller/buildanalysis/buildanalysis_test.go @@ -27,6 +27,8 @@ import ( "github.com/uber/submitqueue/platform/errs" "github.com/uber/submitqueue/platform/metrics" stovepipemq "github.com/uber/submitqueue/stovepipe/core/messagequeue" + "github.com/uber/submitqueue/stovepipe/core/requestlog" + requestlogmock "github.com/uber/submitqueue/stovepipe/core/requestlog/mock" "github.com/uber/submitqueue/stovepipe/entity" "github.com/uber/submitqueue/stovepipe/extension/buildissue" buildissuemock "github.com/uber/submitqueue/stovepipe/extension/buildissue/mock" @@ -76,7 +78,9 @@ func newTestController(t *testing.T) (*Controller, analysisMocks) { m.requests.EXPECT().Get(gomock.Any(), gomock.Any()).DoAndReturn(func(context.Context, string) (entity.Request, error) { return *m.request, nil }).AnyTimes() m.store.EXPECT().GetBuildIssueStore().Return(m.issues).AnyTimes() - c := NewController(zap.NewNop().Sugar(), m.scope, m.stores, m.detectorFactory, + materializer := requestlogmock.NewMockMaterializer(ctrl) + materializer.EXPECT().PersistLog(gomock.Any(), m.store, gomock.Any()).Return(nil).AnyTimes() + c := NewController(zap.NewNop().Sugar(), m.scope, m.stores, materializer, m.detectorFactory, stovepipemq.TopicKeyBuildAnalysis, "stovepipe-buildanalysis") return c, m @@ -464,3 +468,33 @@ func TestCancelledAnalysisDoesNotHold(t *testing.T) { }) } } + +func TestProcessRetriesFinalAnalysisHistoryAfterPersistingIssues(t *testing.T) { + c, m := newTestController(t) + logs := requestlogmock.NewMockMaterializer(m.ctrl) + c.materializer = logs + issue := entity.BuildIssue{TaskID: "validation", UnitID: "unit"} + for i, logErr := range []error{assert.AnError, nil} { + detected := m.expectPass(entity.BuildStatusFailed, []entity.BuildIssue{issue}, nil) + writeErr := error(nil) + if i > 0 { + writeErr = storage.ErrAlreadyExists + } + saved := m.issues.EXPECT().Create(gomock.Any(), testBuildID, issue).Return(writeErr).After(detected) + logs.EXPECT().PersistLog(gomock.Any(), m.store, gomock.Any()).DoAndReturn( + func(_ context.Context, _ storage.Storage, log entity.RequestLog) error { + assert.Equal(t, "event/build_analysis_completed/"+testBuildID, log.ID) + assert.Equal(t, m.request.ID, log.RequestID) + assert.Equal(t, entity.RequestEventBuildAnalysisCompleted, log.Event) + assert.Equal(t, map[string]string{requestlog.MetadataKeyBuildID: testBuildID}, log.Metadata) + assert.Zero(t, log.RequestVersion) + return logErr + }).After(saved) + err := c.Process(context.Background(), m.delivery(t)) + if logErr != nil { + require.ErrorIs(t, err, logErr) + } else { + require.NoError(t, err) + } + } +} diff --git a/stovepipe/controller/fix/BUILD.bazel b/stovepipe/controller/fix/BUILD.bazel index 0d8d045d1..2f7eda6af 100644 --- a/stovepipe/controller/fix/BUILD.bazel +++ b/stovepipe/controller/fix/BUILD.bazel @@ -13,6 +13,7 @@ go_library( "//platform/consumer:go_default_library", "//platform/metrics:go_default_library", "//stovepipe/core/messagequeue:go_default_library", + "//stovepipe/core/requestlog:go_default_library", "//stovepipe/entity:go_default_library", "//stovepipe/extension/fixer:go_default_library", "//stovepipe/extension/storage:go_default_library", @@ -34,6 +35,8 @@ go_test( "//platform/consumer/mock:go_default_library", "//platform/errs:go_default_library", "//stovepipe/core/messagequeue:go_default_library", + "//stovepipe/core/requestlog:go_default_library", + "//stovepipe/core/requestlog/mock:go_default_library", "//stovepipe/entity:go_default_library", "//stovepipe/extension/fixer:go_default_library", "//stovepipe/extension/fixer/mock:go_default_library", diff --git a/stovepipe/controller/fix/README.md b/stovepipe/controller/fix/README.md index bca017ade..34d8ff601 100644 --- a/stovepipe/controller/fix/README.md +++ b/stovepipe/controller/fix/README.md @@ -7,3 +7,5 @@ A returned fix ID is associated with the issue through `BuildIssueStore.Update`, Issue tracking calls [`fixrequest.Publish`](../../core/fixrequest/publish.go) after persisting both the build observation and open issue. Publications for the same build share a message identity and partition. The one-per-build limit is controller policy. Submission precedes persistence, so overlapping deliveries, crashes, and failed writes can still produce duplicate executor calls. Issue recovery remains separate from repair association. + +After an association is durable, the controller retains `repair_submitted` in the owning request history with the build, task, unit, and fix IDs. An existing association repairs missing history without calling the executor again. The event describes the persisted association, including the winner of a concurrent update, and does not imply repair completion. diff --git a/stovepipe/controller/fix/fix.go b/stovepipe/controller/fix/fix.go index 51b331828..96187a080 100644 --- a/stovepipe/controller/fix/fix.go +++ b/stovepipe/controller/fix/fix.go @@ -17,12 +17,15 @@ package fix import ( "context" + "crypto/sha256" + "encoding/hex" "errors" "fmt" "github.com/uber-go/tally" "github.com/uber/submitqueue/platform/consumer" "github.com/uber/submitqueue/platform/metrics" + "github.com/uber/submitqueue/stovepipe/core/requestlog" "github.com/uber/submitqueue/stovepipe/entity" "github.com/uber/submitqueue/stovepipe/extension/fixer" "github.com/uber/submitqueue/stovepipe/extension/storage" @@ -35,6 +38,7 @@ type Controller struct { logger *zap.SugaredLogger metricsScope tally.Scope stores storage.Factory + materializer requestlog.Materializer executors fixer.Factory topicKey consumer.TopicKey consumerGroup string @@ -44,6 +48,7 @@ func NewController( logger *zap.SugaredLogger, scope tally.Scope, stores storage.Factory, + materializer requestlog.Materializer, executors fixer.Factory, topicKey consumer.TopicKey, consumerGroup string, @@ -52,6 +57,7 @@ func NewController( logger: logger.Named("fix_controller"), metricsScope: scope.SubScope("fix_controller"), stores: stores, + materializer: materializer, executors: executors, topicKey: topicKey, consumerGroup: consumerGroup, @@ -63,13 +69,16 @@ func (c *Controller) processBuild(ctx context.Context, queueName, buildID string if err != nil { return fmt.Errorf("failed to resolve repair storage: %w", err) } - observation, found, err := findIssueToFix(ctx, store.GetBuildIssueStore(), store.GetOpenIssueStore(), buildID) + observation, found, err := selectRepairObservation(ctx, store.GetBuildIssueStore(), store.GetOpenIssueStore(), buildID) if err != nil { return fmt.Errorf("failed to select an issue for build %q: %w", buildID, err) } if !found { return nil } + if observation.FixID != "" { + return c.persistRepairSubmittedLog(ctx, store, queueName, buildID, observation) + } executor, err := c.executors.For(fixer.Config{QueueName: queueName}) if err != nil { @@ -112,12 +121,13 @@ func (c *Controller) processBuild(ctx context.Context, queueName, buildID string if current.FixID == "" { return err } + updated = current c.logger.Warnw("preserving previously recorded repair association", "queue", queueName, "build_id", buildID, "task_id", issue.TaskID, "unit_id", issue.UnitID, "fix_id", current.FixID, "submitted_fix_id", fixID) } - return nil + return c.persistRepairSubmittedLog(ctx, store, queueName, buildID, updated) } func (c *Controller) Name() string { return "fix" } @@ -126,7 +136,7 @@ func (c *Controller) TopicKey() consumer.TopicKey { return c.topicKey } func (c *Controller) ConsumerGroup() string { return c.consumerGroup } -func findIssueToFix(ctx context.Context, observations storage.BuildIssueStore, openIssues storage.OpenIssueStore, buildID string) (entity.BuildIssue, bool, error) { +func selectRepairObservation(ctx context.Context, observations storage.BuildIssueStore, openIssues storage.OpenIssueStore, buildID string) (entity.BuildIssue, bool, error) { bounds := storage.BuildIssueRange{Limit: buildIssuePageSize} var candidate entity.BuildIssue found := false @@ -140,7 +150,7 @@ func findIssueToFix(ctx context.Context, observations storage.BuildIssueStore, o } for _, record := range page { if record.FixID != "" { - return entity.BuildIssue{}, false, nil + return record, true, nil } if found { continue @@ -160,3 +170,30 @@ func findIssueToFix(ctx context.Context, observations storage.BuildIssueStore, o bounds.After = storage.BuildIssueCursor{TaskID: last.TaskID, UnitID: last.UnitID} } } + +func (c *Controller) persistRepairSubmittedLog(ctx context.Context, store storage.Storage, queueName, buildID string, observation entity.BuildIssue) error { + build, err := store.GetBuildStore().Get(ctx, buildID) + if err != nil { + return fmt.Errorf("failed to load repaired build %s: %w", buildID, err) + } + request, err := store.GetRequestStore().Get(ctx, build.RequestID) + if err != nil { + return fmt.Errorf("failed to load repaired request %s: %w", build.RequestID, err) + } + if request.Queue != queueName { + return fmt.Errorf("request queue %q does not match repair queue %q", request.Queue, queueName) + } + // Distinct repair associations need distinct occurrences; hashing bounds the composite ID. + identity := sha256.Sum256([]byte(fmt.Sprintf("%q/%q/%q/%q", buildID, observation.TaskID, observation.UnitID, observation.FixID))) + log := requestlog.NewRequestEventLog(request, entity.RequestEventRepairSubmitted, hex.EncodeToString(identity[:]), + map[string]string{ + requestlog.MetadataKeyBuildID: buildID, + requestlog.MetadataKeyFixID: observation.FixID, + requestlog.MetadataKeyTaskID: observation.TaskID, + requestlog.MetadataKeyUnitID: observation.UnitID, + }) + if err := c.materializer.PersistLog(ctx, store, log); err != nil { + return fmt.Errorf("failed to retain submitted repair for request %s: %w", request.ID, err) + } + return nil +} diff --git a/stovepipe/controller/fix/fix_test.go b/stovepipe/controller/fix/fix_test.go index a1c575245..ffc50c93c 100644 --- a/stovepipe/controller/fix/fix_test.go +++ b/stovepipe/controller/fix/fix_test.go @@ -23,6 +23,8 @@ import ( "github.com/uber-go/tally" "github.com/uber/submitqueue/platform/consumer" "github.com/uber/submitqueue/platform/errs" + "github.com/uber/submitqueue/stovepipe/core/requestlog" + requestlogmock "github.com/uber/submitqueue/stovepipe/core/requestlog/mock" "github.com/uber/submitqueue/stovepipe/entity" "github.com/uber/submitqueue/stovepipe/extension/fixer" fixermock "github.com/uber/submitqueue/stovepipe/extension/fixer/mock" @@ -65,7 +67,15 @@ func newTestController(t *testing.T) (*Controller, controllerMocks) { } m.store.EXPECT().GetOpenIssueStore().Return(m.issues).AnyTimes() m.store.EXPECT().GetBuildIssueStore().Return(m.observations).AnyTimes() - return NewController(zap.New(core).Sugar(), tally.NoopScope, m.stores, m.executors, + builds := storagemock.NewMockBuildStore(ctrl) + requests := storagemock.NewMockRequestStore(ctrl) + materializer := requestlogmock.NewMockMaterializer(ctrl) + m.store.EXPECT().GetBuildStore().Return(builds).AnyTimes() + m.store.EXPECT().GetRequestStore().Return(requests).AnyTimes() + builds.EXPECT().Get(gomock.Any(), testBuildID).Return(entity.Build{ID: testBuildID, RequestID: "1"}, nil).AnyTimes() + requests.EXPECT().Get(gomock.Any(), "1").Return(entity.Request{ID: "1", Queue: testQueue}, nil).AnyTimes() + materializer.EXPECT().PersistLog(gomock.Any(), m.store, gomock.Any()).Return(nil).AnyTimes() + return NewController(zap.New(core).Sugar(), tally.NoopScope, m.stores, materializer, m.executors, consumer.TopicKey("fix"), "stovepipe-fix"), m } @@ -320,3 +330,72 @@ func TestProcessBuildReturnsErrorsBeforeSubmission(t *testing.T) { }) } } + +func TestProcessBuildRepairsHistoryWithoutResubmitting(t *testing.T) { + controller, m := newTestController(t) + logs := requestlogmock.NewMockMaterializer(m.ctrl) + controller.materializer = logs + observation := issueWithFixID(testIssue(), "fix/1") + m.stores.EXPECT().For(storage.Config{QueueName: testQueue}).Return(m.store, nil).Times(2) + m.observations.EXPECT().List(gomock.Any(), testBuildID, storage.BuildIssueRange{Limit: buildIssuePageSize}).Return([]entity.BuildIssue{observation}, nil).Times(2) + var firstID string + for _, logErr := range []error{assert.AnError, nil} { + logs.EXPECT().PersistLog(gomock.Any(), m.store, gomock.Any()).DoAndReturn( + func(_ context.Context, _ storage.Storage, log entity.RequestLog) error { + assert.Equal(t, entity.RequestEventRepairSubmitted, log.Event) + assert.NotEmpty(t, log.ID) + if firstID == "" { + firstID = log.ID + } else { + assert.Equal(t, firstID, log.ID) + } + assert.Equal(t, "1", log.RequestID) + assert.Equal(t, map[string]string{ + requestlog.MetadataKeyBuildID: testBuildID, + requestlog.MetadataKeyFixID: observation.FixID, + requestlog.MetadataKeyTaskID: observation.TaskID, + requestlog.MetadataKeyUnitID: observation.UnitID, + }, log.Metadata) + return logErr + }) + err := controller.processBuild(context.Background(), testQueue, testBuildID) + if logErr != nil { + require.ErrorIs(t, err, logErr) + } else { + require.NoError(t, err) + } + } +} + +func TestProcessBuildRecordsHistoryAfterAssociation(t *testing.T) { + for _, competing := range []bool{false, true} { + name := "submitted repair" + if competing { + name = "competing repair wins" + } + t.Run(name, func(t *testing.T) { + controller, m := newTestController(t) + logs := requestlogmock.NewMockMaterializer(m.ctrl) + controller.materializer = logs + issue := testIssue() + m.expectIssue(issue) + submitted := m.executor.EXPECT().Submit(gomock.Any(), issue).Return("fix/submitted", nil) + updated := m.observations.EXPECT().Update(gomock.Any(), testBuildID, issueWithFixID(issue, "fix/submitted"), int32(0), int32(1)).After(submitted) + wantFixID := "fix/submitted" + last := updated + if competing { + updated.Return(storage.ErrVersionMismatch) + wantFixID = "fix/winner" + last = m.observations.EXPECT().Get(gomock.Any(), testBuildID, issue.TaskID, issue.UnitID).Return(issueWithFixID(issue, wantFixID), nil).After(updated) + } else { + updated.Return(nil) + } + logs.EXPECT().PersistLog(gomock.Any(), m.store, gomock.Any()).DoAndReturn( + func(_ context.Context, _ storage.Storage, log entity.RequestLog) error { + assert.Equal(t, wantFixID, log.Metadata[requestlog.MetadataKeyFixID]) + return nil + }).After(last) + require.NoError(t, controller.processBuild(context.Background(), testQueue, testBuildID)) + }) + } +} diff --git a/stovepipe/controller/process/process.go b/stovepipe/controller/process/process.go index f334f70bd..00b929fe2 100644 --- a/stovepipe/controller/process/process.go +++ b/stovepipe/controller/process/process.go @@ -141,7 +141,11 @@ func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) er } return nil case entity.RequestStateSuperseded: - return c.persistStateLog(ctx, store, request, entity.RequestOutcomeReasonSupersededByNewerHead) + queueRow, err := c.loadQueue(ctx, store, request.Queue) + if err != nil { + return err + } + return c.persistSupersededLog(ctx, store, request, queueRow.LatestRequestID) case entity.RequestStateSucceeded, entity.RequestStateFailed, entity.RequestStateCancelled: // Terminal: a newer head preempted this request, or its build already finished. // A stale redelivery has nothing left to do. @@ -213,7 +217,7 @@ func (c *Controller) coalesce(ctx context.Context, store storage.Storage, reques if request.State != entity.RequestStateSuperseded { return true, nil } - if err := c.persistStateLog(ctx, store, request, entity.RequestOutcomeReasonSupersededByNewerHead); err != nil { + if err := c.persistSupersededLog(ctx, store, request, latestRequestID); err != nil { return false, err } metrics.NamedCounter(c.metricsScope, _opName, "superseded", 1, metrics.TagsFromContext(ctx)...) @@ -317,6 +321,23 @@ func (c *Controller) persistStateLog(ctx context.Context, store storage.Storage, return nil } +func (c *Controller) persistSupersededLog(ctx context.Context, store storage.Storage, request entity.Request, latestRequestID string) error { + log := requestlog.NewRequestStateLog(request, entity.RequestOutcomeReasonSupersededByNewerHead) + if latestRequestID != "" { + comparison, err := entity.CompareRequestID(latestRequestID, request.ID) + if err != nil { + return fmt.Errorf("failed to compare request ids for queue %s: %w", request.Queue, err) + } + if comparison > 0 { + log.Metadata[requestlog.MetadataKeySupersededByRequestID] = latestRequestID + } + } + if err := c.materializer.PersistLog(ctx, store, log); err != nil { + return fmt.Errorf("failed to record superseded state for request %s: %w", request.ID, err) + } + return nil +} + // deriveBuildStrategy chooses the validation scope and baseline from the queue's last-known-good commit. // The caller resolves source control once and persists the returned values only after successfully claiming a build slot. func (c *Controller) deriveBuildStrategy(ctx context.Context, sc sourcecontrol.SourceControl, queueRow entity.Queue, request entity.Request) (strategy entity.BuildStrategy, baseURI string, err error) { diff --git a/stovepipe/controller/process/process_test.go b/stovepipe/controller/process/process_test.go index cd8ef4c61..17411ad5a 100644 --- a/stovepipe/controller/process/process_test.go +++ b/stovepipe/controller/process/process_test.go @@ -222,6 +222,17 @@ func expectStateLog(t *testing.T, m processMocks, request entity.Request, reason ).Return(nil) } +func supersededStateLog(request entity.Request, newerID string) entity.RequestLog { + log := requestlog.NewRequestStateLog(request, entity.RequestOutcomeReasonSupersededByNewerHead) + log.Metadata[requestlog.MetadataKeySupersededByRequestID] = newerID + return log +} + +func expectSupersededLog(t *testing.T, m processMocks, request entity.Request, newerID string) *gomock.Call { + t.Helper() + return m.materializer.EXPECT().PersistLog(gomock.Any(), m.store, supersededStateLog(request, newerID)).Return(nil) +} + func expectStartValidationAnnounce(t *testing.T, m processMocks, id string) *gomock.Call { t.Helper() @@ -514,7 +525,8 @@ func TestProcess(t *testing.T) { ID: testID, Queue: testQueue, State: entity.RequestStateSuperseded, Version: 2, } m.reqStore.EXPECT().Get(gomock.Any(), testID).Return(request, nil) - expectStateLog(t, m, request, entity.RequestOutcomeReasonSupersededByNewerHead) + m.queueStore.EXPECT().Get(gomock.Any(), testQueue).Return(entity.Queue{Name: testQueue, LatestRequestID: "99"}, nil) + expectSupersededLog(t, m, request, "99") }, }, { @@ -525,10 +537,11 @@ func TestProcess(t *testing.T) { ID: testID, Queue: testQueue, State: entity.RequestStateSuperseded, Version: 2, } m.reqStore.EXPECT().Get(gomock.Any(), testID).Return(request, nil) + m.queueStore.EXPECT().Get(gomock.Any(), testQueue).Return(entity.Queue{Name: testQueue, LatestRequestID: "99"}, nil) m.materializer.EXPECT().PersistLog( gomock.Any(), m.store, - requestlog.NewRequestStateLog(request, entity.RequestOutcomeReasonSupersededByNewerHead), + supersededStateLog(request, "99"), ).Return(errors.New("db down")) }, }, @@ -804,7 +817,7 @@ func TestProcess(t *testing.T) { updateCall := m.reqStore.EXPECT().Update(gomock.Any(), superseded, int32(1), int32(2)).Return(nil) loggedRequest := superseded loggedRequest.Version = 2 - expectStateLog(t, m, loggedRequest, entity.RequestOutcomeReasonSupersededByNewerHead).After(updateCall) + expectSupersededLog(t, m, loggedRequest, "9").After(updateCall) }, }, { @@ -909,7 +922,7 @@ func TestProcess(t *testing.T) { updateCall := m.reqStore.EXPECT().Update(gomock.Any(), updated, int32(1), int32(2)).Return(nil) loggedRequest := updated loggedRequest.Version = 2 - expectStateLog(t, m, loggedRequest, entity.RequestOutcomeReasonSupersededByNewerHead).After(updateCall) + expectSupersededLog(t, m, loggedRequest, testID).After(updateCall) }, }, { @@ -932,7 +945,7 @@ func TestProcess(t *testing.T) { m.materializer.EXPECT().PersistLog( gomock.Any(), m.store, - requestlog.NewRequestStateLog(request, entity.RequestOutcomeReasonSupersededByNewerHead), + supersededStateLog(request, testID), ).Return(errors.New("db down")).After(updateCall) }, }, @@ -953,7 +966,7 @@ func TestProcess(t *testing.T) { ID: testOlderID, Queue: testQueue, State: entity.RequestStateSuperseded, Version: 2, } reloadCall := m.reqStore.EXPECT().Get(gomock.Any(), testOlderID).Return(reloaded, nil) - expectStateLog(t, m, reloaded, entity.RequestOutcomeReasonSupersededByNewerHead).After(reloadCall) + expectSupersededLog(t, m, reloaded, testID).After(reloadCall) }, }, { @@ -1052,3 +1065,53 @@ func TestHoldForBuildSlotRequiresPositiveDelay(t *testing.T) { require.Error(t, err) assert.False(t, errs.IsRetryable(err)) } + +func TestSupersededHistoryRepairsWithLaterHead(t *testing.T) { + ctrl := gomock.NewController(t) + c, m := newController(t, ctrl) + request := acceptedRequest(testOlderID) + latest := testID + m.reqStore.EXPECT().Get(gomock.Any(), testOlderID).DoAndReturn(func(context.Context, string) (entity.Request, error) { return request, nil }).Times(2) + m.queueStore.EXPECT().Get(gomock.Any(), testQueue).DoAndReturn(func(context.Context, string) (entity.Queue, error) { + return entity.Queue{Name: testQueue, LatestRequestID: latest}, nil + }).Times(2) + m.reqStore.EXPECT().Update(gomock.Any(), gomock.Any(), int32(1), int32(2)).DoAndReturn( + func(_ context.Context, updated entity.Request, _, version int32) error { + request = updated + request.Version = version + return nil + }) + var first entity.RequestLog + gomock.InOrder( + m.materializer.EXPECT().PersistLog(gomock.Any(), m.store, gomock.Any()).DoAndReturn(func(_ context.Context, _ storage.Storage, log entity.RequestLog) error { + first = log + assert.Equal(t, testID, log.Metadata[requestlog.MetadataKeySupersededByRequestID]) + return assert.AnError + }), + m.materializer.EXPECT().PersistLog(gomock.Any(), m.store, gomock.Any()).DoAndReturn(func(_ context.Context, _ storage.Storage, log entity.RequestLog) error { + assert.Equal(t, first.ID, log.ID) + assert.Equal(t, "99", log.Metadata[requestlog.MetadataKeySupersededByRequestID]) + return nil + }), + ) + require.ErrorIs(t, c.Process(queueContext(testQueue), delivery(t, ctrl, processPayload(t, testOlderID))), assert.AnError) + latest = "99" + require.NoError(t, c.Process(queueContext(testQueue), delivery(t, ctrl, processPayload(t, testOlderID)))) +} + +func TestSupersededHistoryOmitsStaleBookmark(t *testing.T) { + for _, latestID := range []string{"", testID, testOlderID} { + t.Run("latest="+latestID, func(t *testing.T) { + ctrl := gomock.NewController(t) + c, m := newController(t, ctrl) + request := acceptedRequest(testID) + request.State = entity.RequestStateSuperseded + request.Version = 2 + m.reqStore.EXPECT().Get(gomock.Any(), testID).Return(request, nil) + m.queueStore.EXPECT().Get(gomock.Any(), testQueue).Return(entity.Queue{Name: testQueue, LatestRequestID: latestID}, nil) + expectStateLog(t, m, request, entity.RequestOutcomeReasonSupersededByNewerHead) + + require.NoError(t, c.Process(queueContext(testQueue), delivery(t, ctrl, processPayload(t, testID)))) + }) + } +} diff --git a/stovepipe/controller/record/BUILD.bazel b/stovepipe/controller/record/BUILD.bazel index edb3275ae..fe1440a61 100644 --- a/stovepipe/controller/record/BUILD.bazel +++ b/stovepipe/controller/record/BUILD.bazel @@ -12,6 +12,7 @@ go_library( "//api/base/hook:go_default_library", "//platform/base/messagequeue:go_default_library", "//platform/consumer:go_default_library", + "//platform/errs:go_default_library", "//platform/hook:go_default_library", "//platform/metrics:go_default_library", "//stovepipe/core/hookevent:go_default_library", @@ -40,6 +41,7 @@ go_test( "//platform/base/messagequeue:go_default_library", "//platform/consumer:go_default_library", "//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/hookevent:go_default_library", diff --git a/stovepipe/controller/record/dlq.go b/stovepipe/controller/record/dlq.go index c3a7fcde2..5daf46ca6 100644 --- a/stovepipe/controller/record/dlq.go +++ b/stovepipe/controller/record/dlq.go @@ -124,7 +124,15 @@ func (c *DLQController) Process(ctx context.Context, delivery consumer.Delivery) return fmt.Errorf("failed to load request %s for record dlq: %w", rec.GetId(), err) } originalFailure, hasFailure := delivery.Failure() - log := requestlog.NewRequestEventLog(request, entity.RequestEventRecordAbandoned, "repository", nil) + stage, _ := originalFailure.Detail[requestlog.MetadataKeyRecordStage].(string) + switch stage { + case _recordStagePrepare, _recordStageProjectResults, _recordStageRepositoryFact, + _recordStageRepositoryHistory, _recordStageProjectFacts, _recordStageDerivedCaches, _recordStageNotification: + default: + stage = _recordStageUnknown + } + log := requestlog.NewRequestEventLog(request, entity.RequestEventRecordAbandoned, "repository", + map[string]string{requestlog.MetadataKeyRecordStage: stage}) if err := c.materializer.PersistLog(ctx, store, log); err != nil { metrics.NamedCounter(c.metricsScope, _dlqOpName, "history_errors", 1, metrics.TagsFromContext(ctx)...) return fmt.Errorf("failed to retain abandoned record work for request %s: %w", request.ID, err) diff --git a/stovepipe/controller/record/dlq_test.go b/stovepipe/controller/record/dlq_test.go index b326ddad3..7725abf02 100644 --- a/stovepipe/controller/record/dlq_test.go +++ b/stovepipe/controller/record/dlq_test.go @@ -27,6 +27,7 @@ import ( "github.com/uber/submitqueue/platform/consumer" consumermock "github.com/uber/submitqueue/platform/consumer/mock" stovepipemq "github.com/uber/submitqueue/stovepipe/core/messagequeue" + "github.com/uber/submitqueue/stovepipe/core/requestlog" requestlogmock "github.com/uber/submitqueue/stovepipe/core/requestlog/mock" "github.com/uber/submitqueue/stovepipe/entity" "github.com/uber/submitqueue/stovepipe/extension/storage" @@ -56,10 +57,12 @@ func TestDLQControllerRetainsAbandonedRecordHistory(t *testing.T) { name string failure failure.Failure hasFailure bool + wantStage string }{ { name: "promotion failure", - failure: failure.Failure{Message: "failed to promote: permission denied"}, + wantStage: _recordStageDerivedCaches, + failure: failure.Failure{Message: "failed to promote: permission denied", Detail: map[string]any{requestlog.MetadataKeyRecordStage: _recordStageDerivedCaches}}, hasFailure: true, }, { @@ -67,9 +70,9 @@ func TestDLQControllerRetainsAbandonedRecordHistory(t *testing.T) { failure: failure.Failure{Message: "hook publish failed"}, hasFailure: true, }, - { - name: "missing failure attribution", - }, + {name: "missing failure attribution"}, + {name: "unrecognized context is not retained", failure: failure.Failure{Detail: map[string]any{requestlog.MetadataKeyRecordStage: "arbitrary provider response"}}, hasFailure: true}, + {name: "non-string context is not retained", failure: failure.Failure{Detail: map[string]any{requestlog.MetadataKeyRecordStage: 17}}, hasFailure: true}, } for _, tt := range tests { @@ -83,7 +86,11 @@ func TestDLQControllerRetainsAbandonedRecordHistory(t *testing.T) { assert.Equal(t, "event/record_abandoned/repository", log.ID) assert.Equal(t, testID, log.RequestID) assert.Empty(t, log.State) - assert.Empty(t, log.Metadata) + stage := tt.wantStage + if stage == "" { + stage = _recordStageUnknown + } + assert.Equal(t, map[string]string{requestlog.MetadataKeyRecordStage: stage}, log.Metadata) return nil }, ) diff --git a/stovepipe/controller/record/record.go b/stovepipe/controller/record/record.go index 07ab866f9..bee30ad7d 100644 --- a/stovepipe/controller/record/record.go +++ b/stovepipe/controller/record/record.go @@ -42,6 +42,7 @@ import ( basehook "github.com/uber/submitqueue/api/base/hook" entityqueue "github.com/uber/submitqueue/platform/base/messagequeue" "github.com/uber/submitqueue/platform/consumer" + "github.com/uber/submitqueue/platform/errs" platformhook "github.com/uber/submitqueue/platform/hook" "github.com/uber/submitqueue/platform/metrics" "github.com/uber/submitqueue/stovepipe/core/hookevent" @@ -74,7 +75,17 @@ type Controller struct { var _ consumer.Controller = (*Controller)(nil) // _opName is the metric operation name shared by every emit in this file. -const _opName = "record" +const ( + _opName = "record" + _recordStageUnknown = "unknown" + _recordStagePrepare = "prepare" + _recordStageProjectResults = "resolve_project_results" + _recordStageRepositoryFact = "record_validation_fact" + _recordStageRepositoryHistory = "retain_validation_fact" + _recordStageProjectFacts = "record_project_facts" + _recordStageDerivedCaches = "apply_derived_caches" + _recordStageNotification = "publish_notification" +) // wholeRepositoryProject is the project component of a fact covering the whole // repository rather than one project within it. @@ -114,7 +125,13 @@ func NewController( // buildsignal stamps the outcome on the request before publishing here, so a // request without a build outcome is a producer invariant violation rather // than a state this stage waits for. -func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) error { +func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) (retErr error) { + stage := _recordStagePrepare + defer func() { + if retErr != nil { + retErr = errs.Detail(retErr, map[string]any{requestlog.MetadataKeyRecordStage: stage}) + } + }() msg := delivery.Message() rec := &stovepipemq.Record{} @@ -148,29 +165,36 @@ func (c *Controller) Process(ctx context.Context, delivery consumer.Delivery) er switch request.State { case entity.RequestStateSucceeded, entity.RequestStateFailed: + stage = _recordStageProjectResults results, err := c.resolveProjectResults(ctx, request) if err != nil { return err } + stage = _recordStageRepositoryFact fact, created, err := c.recordFact(ctx, store, request, results) if err != nil { return err } + stage = _recordStageRepositoryHistory if err := c.persistValidationFactRecordedLog(ctx, store, request, fact); err != nil { return err } + stage = _recordStageProjectFacts if err := c.persistProjectFacts(ctx, store, request, results); err != nil { return err } + stage = _recordStageDerivedCaches if err := c.applyFactToDerivedCaches(ctx, store, request, fact, created); err != nil { return err } + stage = _recordStageNotification return c.publishHookEvent(ctx, request, hookevent.NewValidationRepositoryRecorded(request)) 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.TagsFromContext(ctx)...) + stage = _recordStageNotification return c.publishHookEvent(ctx, request, hookevent.NewValidationRepositoryCancelled(request)) case entity.RequestStateSuperseded: diff --git a/stovepipe/controller/record/record_test.go b/stovepipe/controller/record/record_test.go index 95dc05b93..2ae4762fc 100644 --- a/stovepipe/controller/record/record_test.go +++ b/stovepipe/controller/record/record_test.go @@ -28,6 +28,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/errs" mqmock "github.com/uber/submitqueue/platform/extension/messagequeue/mock" "github.com/uber/submitqueue/platform/metrics" "github.com/uber/submitqueue/stovepipe/core/hookevent" @@ -1323,3 +1324,60 @@ func TestProcessRetriesProjectPersistenceWithImmutablePartialFact(t *testing.T) require.NoError(t, c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID)))) assert.Len(t, m.hooks.events, 1) } + +func TestProcessAttributesIncompleteRecordStage(t *testing.T) { + for _, stage := range []string{_recordStagePrepare, _recordStageProjectResults, _recordStageRepositoryFact, _recordStageRepositoryHistory, _recordStageProjectFacts, _recordStageDerivedCaches, _recordStageNotification} { + t.Run(stage, func(t *testing.T) { + ctrl := gomock.NewController(t) + c, m := newController(t, ctrl) + cause := errs.NewRetryableError(assert.AnError) + expectRecordStageFailure(ctrl, c, m, stage, cause) + err := c.Process(queueContext(), delivery(t, ctrl, recordPayload(t, testID))) + require.ErrorIs(t, err, cause) + assert.True(t, errs.IsRetryable(err)) + assert.Equal(t, stage, errs.Attribution(err).Detail[requestlog.MetadataKeyRecordStage]) + }) + } +} + +func expectRecordStageFailure(ctrl *gomock.Controller, c *Controller, m recordMocks, stage string, cause error) { + if stage == _recordStagePrepare { + m.reqStore.EXPECT().Get(gomock.Any(), testID).Return(entity.Request{}, cause) + return + } + m.reqStore.EXPECT().Get(gomock.Any(), testID).Return(requestWithState(entity.RequestStateSucceeded), nil) + if stage == _recordStageProjectResults { + factory := projectstatusmock.NewMockResolverFactory(ctrl) + c.projectStatusResolverFactory = factory + factory.EXPECT().For(projectstatus.ResolverConfig{QueueName: testQueue}).Return(nil, cause) + return + } + if stage == _recordStageRepositoryFact { + m.factStore.EXPECT().Create(gomock.Any(), gomock.Any()).Return(cause) + return + } + var fact entity.ValidationFact + m.expectFactCreated(&fact) + logs := requestlogmock.NewMockMaterializer(ctrl) + c.materializer = logs + repositoryLog := logs.EXPECT().PersistLog(gomock.Any(), m.store, gomock.Cond(func(log entity.RequestLog) bool { return log.Event == entity.RequestEventValidationFactRecorded })) + if stage == _recordStageRepositoryHistory { + repositoryLog.Return(cause) + return + } + repositoryLog.Return(nil) + projectLog := logs.EXPECT().PersistLog(gomock.Any(), m.store, gomock.Cond(func(log entity.RequestLog) bool { return log.Event == entity.RequestEventProjectFactsRecorded })).After(repositoryLog) + if stage == _recordStageProjectFacts { + projectLog.Return(cause) + return + } + projectLog.Return(nil) + if stage == _recordStageDerivedCaches { + m.queueStore.EXPECT().Get(gomock.Any(), testQueue).Return(entity.Queue{}, cause) + return + } + m.queueStore.EXPECT().Get(gomock.Any(), testQueue).Return(queueRow(testURI, testID, 1), nil) + m.sourceControl.EXPECT().ChangeInfo(gomock.Any(), testURI).Return(sourcecontrol.ChangeInfo{}, nil) + m.sourceControl.EXPECT().Promote(gomock.Any(), testURI).Return(nil) + m.hooks.err = cause +} diff --git a/stovepipe/core/requestlog/materializer.go b/stovepipe/core/requestlog/materializer.go index 2eb424ae7..5313b4fde 100644 --- a/stovepipe/core/requestlog/materializer.go +++ b/stovepipe/core/requestlog/materializer.go @@ -44,6 +44,16 @@ const ( MetadataKeyProjectFactCount = "project_fact_count" // MetadataKeyBaseURI records the selected build baseline; an empty value means a full build. MetadataKeyBaseURI = "base_uri" + // MetadataKeySupersededByRequestID identifies a newer head observed for a superseded request. + MetadataKeySupersededByRequestID = "superseded_by_request_id" + // MetadataKeyRecordStage identifies the incomplete part of abandoned record work. + MetadataKeyRecordStage = "record_stage" + // MetadataKeyFixID identifies the submitted repair associated with a build issue. + MetadataKeyFixID = "fix_id" + // MetadataKeyTaskID identifies the build task associated with a repair. + MetadataKeyTaskID = "task_id" + // MetadataKeyUnitID identifies the build unit associated with a repair. + MetadataKeyUnitID = "unit_id" ) // Materializer retains request-log occurrences and advances their derived read models. @@ -179,16 +189,21 @@ func sameSemanticOccurrence(stored, candidate entity.RequestLog) bool { stored.Event == candidate.Event && stored.RequestVersion == candidate.RequestVersion && stored.OutcomeReason == candidate.OutcomeReason && - metadataCompatible(stored.Metadata, candidate.Metadata) + metadataCompatible(stored, candidate) } -func metadataCompatible(stored, candidate map[string]string) bool { - // Keys present on only one side permit additive rollout against older immutable rows. Values - // emitted by both versions must still agree. - for key, storedValue := range stored { - if candidateValue, ok := candidate[key]; ok && candidateValue != storedValue { - return false +func metadataCompatible(stored, candidate entity.RequestLog) bool { + // Absent keys permit additive rollout. Producers validate superseding heads; + // retries can observe different heads, and the retained value wins. + for key, storedValue := range stored.Metadata { + candidateValue, ok := candidate.Metadata[key] + if !ok || candidateValue == storedValue { + continue } + if key == MetadataKeySupersededByRequestID && stored.State == entity.RequestStateSuperseded { + continue + } + return false } return true } diff --git a/stovepipe/core/requestlog/materializer_test.go b/stovepipe/core/requestlog/materializer_test.go index 037fd344a..5e92c6bca 100644 --- a/stovepipe/core/requestlog/materializer_test.go +++ b/stovepipe/core/requestlog/materializer_test.go @@ -242,6 +242,48 @@ func TestMaterializerExistingConflictingOccurrenceFails(t *testing.T) { require.Error(t, materializer.PersistLog(context.Background(), stores, NewRequestStateLog(request, entity.RequestOutcomeReasonBuildSucceeded))) } +func TestMaterializerSupersessionWithDifferentObservedHead(t *testing.T) { + for _, tt := range []struct { + name string + key string + stored string + retry string + wantErr bool + }{ + {name: "later head", key: MetadataKeySupersededByRequestID, stored: "9", retry: "10"}, + {name: "earlier observation still newer than request", key: MetadataKeySupersededByRequestID, stored: "10", retry: "9"}, + {name: "different baseline conflicts", key: MetadataKeyBaseURI, stored: "git://repo/base", retry: "git://repo/other", wantErr: true}, + } { + t.Run(tt.name, func(t *testing.T) { + materializer, stores, logs, summaries, _ := newTestMaterializer(t) + stored := NewRequestStateLog(entity.Request{ + ID: testRequestID, Queue: testQueue, State: entity.RequestStateSuperseded, Version: 2, + }, entity.RequestOutcomeReasonSupersededByNewerHead) + stored.TimestampMs = testNowMs - 1000 + stored.Metadata[tt.key] = tt.stored + candidate := stored + candidate.TimestampMs = 0 + candidate.Metadata = map[string]string{tt.key: tt.retry} + logs.EXPECT().Create(gomock.Any(), gomock.Any()).Return(storage.ErrAlreadyExists) + logs.EXPECT().Get(gomock.Any(), testRequestID, candidate.ID).Return(stored, nil) + if !tt.wantErr { + summaries.EXPECT().Get(gomock.Any(), testRequestID).Return(seededRequestSummary(), nil) + summaries.EXPECT().Update(gomock.Any(), gomock.Any(), int32(1), int32(2)).DoAndReturn( + func(_ context.Context, summary entity.RequestSummary, _, _ int32) error { + assert.Equal(t, stored.TimestampMs, summary.StateTimestampMs) + return nil + }) + } + err := materializer.PersistLog(context.Background(), stores, candidate) + if tt.wantErr { + require.Error(t, err) + return + } + require.NoError(t, err) + }) + } +} + func TestMaterializerStorageFailures(t *testing.T) { tests := []struct { name string @@ -400,3 +442,21 @@ func TestMaterializerRetainsOtherEventsWithoutProjectingSummary(t *testing.T) { }) } } + +func TestMaterializerRetainsNewEventsIdempotentlyWithoutChangingSummary(t *testing.T) { + for _, event := range []entity.RequestEvent{entity.RequestEventBuildAnalysisCompleted, entity.RequestEventRepairSubmitted} { + t.Run(string(event), func(t *testing.T) { + materializer, stores, logs, _, _ := newTestMaterializer(t) + log := NewRequestEventLog(entity.Request{ID: testRequestID, Queue: testQueue}, event, "build/1", map[string]string{MetadataKeyBuildID: "build/1"}) + stored := log + stored.TimestampMs = testNowMs + gomock.InOrder( + logs.EXPECT().Create(gomock.Any(), stored).Return(nil), + logs.EXPECT().Create(gomock.Any(), stored).Return(storage.ErrAlreadyExists), + logs.EXPECT().Get(gomock.Any(), testRequestID, log.ID).Return(stored, nil), + ) + require.NoError(t, materializer.PersistLog(context.Background(), stores, log)) + require.NoError(t, materializer.PersistLog(context.Background(), stores, log)) + }) + } +} diff --git a/stovepipe/entity/request_log.go b/stovepipe/entity/request_log.go index 7c53434c4..d69ca3e22 100644 --- a/stovepipe/entity/request_log.go +++ b/stovepipe/entity/request_log.go @@ -34,6 +34,10 @@ const ( RequestEventRecordAbandoned RequestEvent = "record_abandoned" // RequestEventBuildAnalysisAbandoned records incomplete build analysis, not a validation outcome. RequestEventBuildAnalysisAbandoned RequestEvent = "build_analysis_abandoned" + // RequestEventBuildAnalysisCompleted records that final build issue observations are durable. + RequestEventBuildAnalysisCompleted RequestEvent = "build_analysis_completed" + // RequestEventRepairSubmitted records a durable association between a build issue and a submitted repair. + RequestEventRepairSubmitted RequestEvent = "repair_submitted" ) // RequestOutcomeReason identifies the durable domain reason for a terminal request state. @@ -139,7 +143,7 @@ func (e RequestLog) validateEvent() error { return fmt.Errorf("event log must not contain request-state context") } switch e.Event { - case RequestEventBuildTriggered, RequestEventBuildFinished, RequestEventValidationFactRecorded, RequestEventProjectFactsRecorded, RequestEventRecordAbandoned, RequestEventBuildAnalysisAbandoned: + case RequestEventBuildTriggered, RequestEventBuildFinished, RequestEventValidationFactRecorded, RequestEventProjectFactsRecorded, RequestEventRecordAbandoned, RequestEventBuildAnalysisAbandoned, RequestEventBuildAnalysisCompleted, RequestEventRepairSubmitted: default: return fmt.Errorf("unknown request event %q", e.Event) } diff --git a/test/integration/stovepipe/extension/storage/mysql/storage_test.go b/test/integration/stovepipe/extension/storage/mysql/storage_test.go index 298696d72..8eb329e2f 100644 --- a/test/integration/stovepipe/extension/storage/mysql/storage_test.go +++ b/test/integration/stovepipe/extension/storage/mysql/storage_test.go @@ -23,6 +23,7 @@ import ( "github.com/stretchr/testify/require" "github.com/stretchr/testify/suite" "github.com/uber-go/tally" + "github.com/uber/submitqueue/stovepipe/core/requestlog" "github.com/uber/submitqueue/stovepipe/entity" "github.com/uber/submitqueue/stovepipe/extension/storage" mysqlstorage "github.com/uber/submitqueue/stovepipe/extension/storage/mysql" @@ -413,3 +414,31 @@ type mysqlFactory struct { func (f mysqlFactory) For(config storage.Config) (storage.Storage, error) { return f.backend.For(config.QueueName) } + +func (s *MySQLRequestStoreSuite) TestSupersessionHistoryPreservesFirstObservedHead() { + request := entity.Request{ID: "20", Queue: "monorepo/main", URI: "git://repo/superseded", State: entity.RequestStateAccepted, Version: 1} + require.NoError(s.T(), s.store.Create(s.ctx, request)) + stores, err := s.backend.For(request.Queue) + require.NoError(s.T(), err) + materializer := requestlog.NewMaterializer(tally.NoopScope) + require.NoError(s.T(), materializer.PersistLog(s.ctx, stores, requestlog.NewRequestStateLog(request, entity.RequestOutcomeReasonUnknown))) + updated := request + updated.State = entity.RequestStateSuperseded + require.NoError(s.T(), s.store.Update(s.ctx, updated, 1, 2)) + reloaded, err := s.store.Get(s.ctx, request.ID) + require.NoError(s.T(), err) + log := requestlog.NewRequestStateLog(reloaded, entity.RequestOutcomeReasonSupersededByNewerHead) + log.Metadata[requestlog.MetadataKeySupersededByRequestID] = "21" + require.NoError(s.T(), materializer.PersistLog(s.ctx, stores, log)) + retry := log + retry.Metadata = map[string]string{requestlog.MetadataKeySupersededByRequestID: "22"} + require.NoError(s.T(), materializer.PersistLog(s.ctx, stores, retry)) + history, err := stores.GetRequestLogStore().List(s.ctx, request.ID) + require.NoError(s.T(), err) + require.Len(s.T(), history, 2) + for _, occurrence := range history { + if occurrence.State == entity.RequestStateSuperseded { + require.Equal(s.T(), "21", occurrence.Metadata[requestlog.MetadataKeySupersededByRequestID]) + } + } +}