diff --git a/pkg/api/control_handlers.go b/pkg/api/control_handlers.go index d3de18199..711062fd5 100644 --- a/pkg/api/control_handlers.go +++ b/pkg/api/control_handlers.go @@ -26,9 +26,32 @@ func controlStatus(accepted bool) string { return "rejected" } +// controlErrorMetricStatus classifies a failed control operation for the +// control-operation metric. The three outcomes want different operator +// responses: "error" is a failure to investigate, "rejected" is a request the +// operator must reissue differently, and "satisfied" is a request the apply's +// state already covers — a repeat command, which needs no response at all and +// must not inflate the rejection rate operators alert on. +func controlErrorMetricStatus(err error) string { + switch { + case IsControlOperationSatisfied(err): + return "satisfied" + case controlOperationHTTPStatus(err) < http.StatusInternalServerError: + return "rejected" + default: + return "error" + } +} + type controlOperationHTTPError struct { status int err error + // satisfied marks a rejection whose cause is the operator's own intent + // already being the apply's state — a cancel on a cancelled apply, a stop on + // a stopped one. The request cannot proceed, but nothing went wrong and + // there is nothing for the operator to do differently, so callers report it + // as an outcome rather than escalating it as a failure. + satisfied bool } func (e *controlOperationHTTPError) Error() string { @@ -48,6 +71,28 @@ func controlConflictf(format string, args ...any) error { } } +// controlSatisfiedf marks an operator request the apply's current state already +// satisfies. It carries the same conflict status as controlConflictf — the +// request still cannot proceed — but callers can tell the two apart, because a +// command whose effect is already in place is not one the operator needs to +// retry, escalate, or hear about through a failure comment. +func controlSatisfiedf(format string, args ...any) error { + return &controlOperationHTTPError{ + status: http.StatusConflict, + err: fmt.Errorf(format, args...), + satisfied: true, + } +} + +// IsControlOperationSatisfied reports whether a control operation was rejected +// because the apply is already in the state the operator asked for. Callers use +// it to answer informationally instead of routing the operator to support for a +// command that got them exactly what they wanted. +func IsControlOperationSatisfied(err error) bool { + var httpErr *controlOperationHTTPError + return errors.As(err, &httpErr) && httpErr.satisfied +} + func controlOperationHTTPStatus(err error) int { var httpErr *controlOperationHTTPError if errors.As(err, &httpErr) { @@ -465,11 +510,7 @@ func (s *Service) handleCutover(w http.ResponseWriter, r *http.Request) { } if err := s.rejectControlIfStopPending(r.Context(), "cutover", apply); err != nil { - status := "error" - if controlOperationHTTPStatus(err) < http.StatusInternalServerError { - status = "rejected" - } - metrics.RecordControlOperation(r.Context(), "cutover", apply.Database, apply.Deployment, apply.Environment, status) + metrics.RecordControlOperation(r.Context(), "cutover", apply.Database, apply.Deployment, apply.Environment, controlErrorMetricStatus(err)) s.writeControlError(w, "cutover", apply, err) return } @@ -709,11 +750,7 @@ func (s *Service) executeStopForApply(ctx context.Context, client tern.Client, a } resp, responseStatus, err := s.queueStopForApplyOwner(ctx, apply, caller) if err != nil { - status := "error" - if controlOperationHTTPStatus(err) < http.StatusInternalServerError { - status = "rejected" - } - metrics.RecordControlOperation(ctx, "stop", apply.Database, apply.Deployment, apply.Environment, status) + metrics.RecordControlOperation(ctx, "stop", apply.Database, apply.Deployment, apply.Environment, controlErrorMetricStatus(err)) return nil, 0, err } metrics.RecordControlOperation(ctx, "stop", apply.Database, apply.Deployment, apply.Environment, controlStatus(resp.Accepted)) @@ -895,17 +932,19 @@ func (s *Service) ExecuteCancel(ctx context.Context, req apitypes.ControlRequest func (s *Service) executeCancelForApply(ctx context.Context, client tern.Client, apply *storage.Apply, caller string) (*apitypes.CancelResponse, int, error) { caller = resolveCaller(ctx, caller) + // A stopped apply is terminal but still cancellable — stopping leaves the + // change half-applied, and cancel is how an operator settles it. + if state.IsState(apply.State, state.Apply.Cancelled) { + metrics.RecordControlOperation(ctx, "cancel", apply.Database, apply.Deployment, apply.Environment, "satisfied") + return nil, 0, controlSatisfiedf("the schema change is already cancelled") + } if state.IsTerminalApplyState(apply.State) && !state.IsState(apply.State, state.Apply.Stopped) { metrics.RecordControlOperation(ctx, "cancel", apply.Database, apply.Deployment, apply.Environment, "rejected") return nil, 0, controlConflictf("schema change is already terminal (current state: %s)", apply.State) } resp, responseStatus, err := s.queueCancelForApplyOwner(ctx, apply, caller) if err != nil { - status := "error" - if controlOperationHTTPStatus(err) < http.StatusInternalServerError { - status = "rejected" - } - metrics.RecordControlOperation(ctx, "cancel", apply.Database, apply.Deployment, apply.Environment, status) + metrics.RecordControlOperation(ctx, "cancel", apply.Database, apply.Deployment, apply.Environment, controlErrorMetricStatus(err)) return nil, 0, err } metrics.RecordControlOperation(ctx, "cancel", apply.Database, apply.Deployment, apply.Environment, controlStatus(resp.Accepted)) @@ -1058,6 +1097,9 @@ func (s *Service) queueStopForApplyOwner(ctx context.Context, apply *storage.App if resp, responseStatus, found, err := s.pendingStopResponseIfPresent(ctx, apply); err != nil || found { return resp, responseStatus, err } + if state.IsState(apply.State, state.Apply.Stopped) { + return nil, "", controlSatisfiedf("the schema change is already stopped") + } if state.IsTerminalApplyState(apply.State) { return nil, "", controlConflictf("schema change is already terminal (current state: %s)", apply.State) } @@ -1261,19 +1303,11 @@ func (s *Service) executeStartForApply(ctx context.Context, client tern.Client, return nil, 0, err } if err := s.completeResolvedStopBeforeStart(ctx, client, apply, caller); err != nil { - status := "error" - if controlOperationHTTPStatus(err) < http.StatusInternalServerError { - status = "rejected" - } - metrics.RecordControlOperation(ctx, "start", apply.Database, apply.Deployment, apply.Environment, status) + metrics.RecordControlOperation(ctx, "start", apply.Database, apply.Deployment, apply.Environment, controlErrorMetricStatus(err)) return nil, 0, err } if err := s.rejectControlIfStopPending(ctx, "start", apply); err != nil { - status := "error" - if controlOperationHTTPStatus(err) < http.StatusInternalServerError { - status = "rejected" - } - metrics.RecordControlOperation(ctx, "start", apply.Database, apply.Deployment, apply.Environment, status) + metrics.RecordControlOperation(ctx, "start", apply.Database, apply.Deployment, apply.Environment, controlErrorMetricStatus(err)) return nil, 0, err } @@ -1306,11 +1340,7 @@ func (s *Service) executeStartForApply(ctx context.Context, client tern.Client, err = startNotAllowedForState(apply) } if err != nil { - status := "error" - if controlOperationHTTPStatus(err) < http.StatusInternalServerError { - status = "rejected" - } - metrics.RecordControlOperation(ctx, "start", apply.Database, apply.Deployment, apply.Environment, status) + metrics.RecordControlOperation(ctx, "start", apply.Database, apply.Deployment, apply.Environment, controlErrorMetricStatus(err)) return nil, 0, err } @@ -1775,11 +1805,7 @@ func (s *Service) acceptedReleaseResponse(ctx context.Context, apply *storage.Ap } func (s *Service) recordReleaseRejectionMetric(ctx context.Context, apply *storage.Apply, err error) { - status := "error" - if controlOperationHTTPStatus(err) < http.StatusInternalServerError { - status = "rejected" - } - metrics.RecordControlOperation(ctx, "release", apply.Database, apply.Deployment, apply.Environment, status) + metrics.RecordControlOperation(ctx, "release", apply.Database, apply.Deployment, apply.Environment, controlErrorMetricStatus(err)) } // releaseControlRequestMetadata is the (currently empty) metadata payload stored diff --git a/pkg/api/control_handlers_test.go b/pkg/api/control_handlers_test.go index 79047344d..d0f0db632 100644 --- a/pkg/api/control_handlers_test.go +++ b/pkg/api/control_handlers_test.go @@ -43,6 +43,26 @@ func TestIsInternalControlError(t *testing.T) { }) } +// A control request the apply's state already satisfies is distinguishable from +// a rejection the operator must act on, so callers can answer it informationally +// instead of escalating a command that got them what they asked for. It keeps +// the conflict status either way: the request still cannot proceed. +func TestIsControlOperationSatisfied(t *testing.T) { + satisfied := controlSatisfiedf("the schema change is already cancelled") + assert.True(t, IsControlOperationSatisfied(satisfied)) + assert.False(t, IsInternalControlError(satisfied)) + assert.Equal(t, http.StatusConflict, ControlOperationHTTPStatus(satisfied)) + assert.Equal(t, "satisfied", controlErrorMetricStatus(satisfied)) + + assert.True(t, IsControlOperationSatisfied(fmt.Errorf("execute cancel: %w", satisfied)), + "a wrapped satisfied intent is still satisfied") + + conflict := controlConflictf("schema change is already terminal (current state: %s)", "completed") + assert.False(t, IsControlOperationSatisfied(conflict)) + assert.Equal(t, "rejected", controlErrorMetricStatus(conflict)) + assert.Equal(t, "error", controlErrorMetricStatus(errors.New("storage unavailable"))) +} + // A failed control operation is triaged from logs alone, so the failure line // must carry the apply's full triage attributes — including external_id, the // join key to the data plane's logs — alongside the error itself. diff --git a/pkg/webhook/control.go b/pkg/webhook/control.go index a1f5ae31f..a51461ecb 100644 --- a/pkg/webhook/control.go +++ b/pkg/webhook/control.go @@ -33,6 +33,33 @@ func (h *Handler) logControlCommandError(command, repo string, pr int, applyID, } } +// postControlCommandSatisfied answers a control command the apply's state +// already covers — a cancel on a cancelled apply, a stop on a stopped one. +// Reissuing a control command is how an operator confirms one landed, so the +// second one is expected traffic: it gets an informational reply with no +// support-channel link, and an INFO log rather than the WARN a rejection earns. +// Treating a satisfied intent as a failure sends an operator who already got +// what they wanted looking for an incident that does not exist. +func (h *Handler) postControlCommandSatisfied( + repo string, pr int, installationID int64, requestedBy string, + result CommandResult, actionName string, err error, +) { + h.logger.Info(actionName+" PR command was already satisfied by the schema change's current state", + "repo", repo, + "pr", pr, + "apply_id", result.ApplyID, + "environment", result.Environment, + "requested_by", requestedBy, + "detail", err.Error()) + h.postComment(repo, pr, installationID, templates.RenderControlCommandSatisfied(templates.ControlCommandSatisfiedData{ + Command: actionName, + ApplyID: result.ApplyID, + Environment: result.Environment, + RequestedBy: requestedBy, + Detail: err.Error(), + })) +} + func (h *Handler) loadApplyForPRControl(ctx context.Context, repo string, pr int, installationID int64, requestedBy string, result CommandResult, command string) (*storage.Apply, bool) { if result.ApplyID == "" { if h.silentUsageErrorOnUnscopedFanOut(repo, result.Tenant) { @@ -188,6 +215,10 @@ func runControlCommand[R any]( Caller: caller, }) if err != nil { + if api.IsControlOperationSatisfied(err) { + h.postControlCommandSatisfied(repo, pr, installationID, requestedBy, result, actionName, err) + return nil + } h.logControlCommandError(actionName, repo, pr, result.ApplyID, result.Environment, requestedBy, err) h.postCommandError(repo, pr, installationID, actionName, result.Environment, requestedBy, err.Error()) return nil diff --git a/pkg/webhook/control_integration_test.go b/pkg/webhook/control_integration_test.go index 3a2de8d4d..8c4b5d082 100644 --- a/pkg/webhook/control_integration_test.go +++ b/pkg/webhook/control_integration_test.go @@ -20,6 +20,7 @@ import ( "github.com/block/schemabot/pkg/storage" "github.com/block/schemabot/pkg/storage/mysqlstore" "github.com/block/schemabot/pkg/tern" + "github.com/block/schemabot/pkg/webhook/templates" "github.com/block/spirit/pkg/utils" _ "github.com/go-sql-driver/mysql" "github.com/stretchr/testify/assert" @@ -1106,6 +1107,125 @@ func postRevertCommand(t *testing.T, h *Handler, applyIdentifier, user string) { assert.Contains(t, rr.Body.String(), "revert started") } +// captureCommentsAndReactions routes the PR comment and reaction endpoints into +// channels the caller reads, so a test can assert on what a command answered. +func captureCommentsAndReactions(t *testing.T, mux *http.ServeMux) (chan string, chan string) { + t.Helper() + comments := make(chan string, 10) + reactions := make(chan string, 10) + mux.HandleFunc("POST /repos/octocat/hello-world/issues/1/comments", func(w http.ResponseWriter, r *http.Request) { + var body struct { + Body string `json:"body"` + } + require.NoError(t, json.NewDecoder(r.Body).Decode(&body)) + comments <- body.Body + w.WriteHeader(http.StatusCreated) + _ = json.NewEncoder(w).Encode(map[string]any{"id": 99}) + }) + mux.HandleFunc("POST /repos/octocat/hello-world/issues/comments/42/reactions", func(w http.ResponseWriter, r *http.Request) { + var body struct { + Content string `json:"content"` + } + require.NoError(t, json.NewDecoder(r.Body).Decode(&body)) + reactions <- body.Content + w.WriteHeader(http.StatusCreated) + _ = json.NewEncoder(w).Encode(map[string]any{"id": 1}) + }) + return comments, reactions +} + +// seedTerminalControlApply seeds a control-command apply already settled in the +// given terminal state, so a command asking for that same state has nothing left +// to do. +func seedTerminalControlApply(t *testing.T, store storage.Storage, db *sql.DB, applyIdentifier, database, applyState string) int64 { + t.Helper() + cleanupStopCommandTestRows(t, db, applyIdentifier, database) + t.Cleanup(func() { cleanupStopCommandTestRows(t, db, applyIdentifier, database) }) + + applyID := createStopCommandApply(t, store, applyIdentifier, database) + stored, err := store.Applies().GetByApplyIdentifier(t.Context(), applyIdentifier) + require.NoError(t, err) + require.NotNil(t, stored) + stored.State = applyState + stored.UpdatedAt = time.Now().UTC() + require.NoError(t, store.Applies().Update(t.Context(), stored)) + return applyID +} + +// Reissuing a control command is how an operator confirms the first one landed, +// so the second one must not read as a failure. A cancel on an already-cancelled +// schema change, and a stop on an already-stopped one, get the outcome they +// asked for: an informational reply with no support-channel escalation, and no +// second durable control request. +func TestE2ERepeatControlCommandOnSettledApplyAnswersInformationally(t *testing.T) { + ctx := t.Context() + schemabotDB, err := sql.Open("mysql", e2eSchemabotDSN) + require.NoError(t, err) + require.NoError(t, schemabotDB.PingContext(ctx)) + t.Cleanup(func() { utils.CloseAndLog(schemabotDB) }) + store := mysqlstore.New(schemabotDB) + + tests := []struct { + name string + applyState string + database string + identifier string + operation storage.ControlOperation + post func(t *testing.T, h *Handler, applyIdentifier, user string) + wantDetail string + }{ + { + name: "cancel on a cancelled schema change", + applyState: state.Apply.Cancelled, + database: "cancel_pr_comments_settled_db", + identifier: "apply_ca11e0ed", + operation: storage.ControlOperationCancel, + post: postCancelCommand, + wantDetail: "the schema change is already cancelled", + }, + { + name: "stop on a stopped schema change", + applyState: state.Apply.Stopped, + database: "stop_pr_comments_settled_db", + identifier: "apply_5709bed0", + operation: storage.ControlOperationStop, + post: postStopCommand, + wantDetail: "the schema change is already stopped", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + applyID := seedTerminalControlApply(t, store, schemabotDB, tt.identifier, tt.database, tt.applyState) + + client, mux := setupGitHubServer(t) + comments, reactions := captureCommentsAndReactions(t, mux) + + service := apiServiceForStopCommandTest(t, store, tt.database) + service.RegisterTernClient(tt.database, "staging", &stopCommandTernClient{}) + h := &Handler{ + service: service, + ghClients: ghclient.NewSingleClientSet(defaultAppName, &fakeClientFactory{client: ghclient.NewInstallationClient(client, testLogger())}), + logger: testLogger(), + } + + tt.post(t, h, tt.identifier, "alice") + comment := readComment(t, comments) + assert.Contains(t, comment, "Nothing to "+tt.operation) + assert.Contains(t, comment, tt.wantDetail) + assert.Contains(t, comment, "`"+tt.identifier+"`") + assert.NotContains(t, comment, "Failed") + assert.False(t, templates.OffersSupportChannel(comment), + "a command that got the operator what they asked for must not route them to support") + + pending, err := store.ControlRequests().GetPending(ctx, applyID, tt.operation) + require.NoError(t, err) + assert.Nil(t, pending, "a settled schema change must not accrue another control request") + assertReactionEventually(t, reactions) + }) + } +} + func readComment(t *testing.T, comments chan string) string { t.Helper() select { diff --git a/pkg/webhook/templates/issue_comment.go b/pkg/webhook/templates/issue_comment.go index 01316f9b8..0ea436114 100644 --- a/pkg/webhook/templates/issue_comment.go +++ b/pkg/webhook/templates/issue_comment.go @@ -112,6 +112,37 @@ func RenderVolumeInvalidLevel() string { storage.MinVolume, storage.MaxVolume)) } +// ControlCommandSatisfiedData contains data for the reply to a control command +// the apply's current state already satisfies. +type ControlCommandSatisfiedData struct { + Command string + ApplyID string + Environment string + RequestedBy string + // Detail names the state that already covers the command, as a clause the + // reply reads back — e.g. "the schema change is already cancelled". + Detail string +} + +// RenderControlCommandSatisfied renders the reply to a control command the +// apply's current state already covers — a cancel on a cancelled apply, a stop +// on a stopped one. The operator got the outcome they asked for, so this +// deliberately carries no support-channel link and no failure framing: routing +// someone to support for a command that worked sends them chasing an incident +// that does not exist. +func RenderControlCommandSatisfied(data ControlCommandSatisfiedData) string { + body := fmt.Sprintf("## ✅ Nothing to %s\n\n", data.Command) + + fmt.Sprintf("**Apply**: `%s`\n", data.ApplyID) + if data.Environment != "" { + body += fmt.Sprintf("**Environment**: `%s`\n", data.Environment) + } + if data.RequestedBy != "" { + body += fmt.Sprintf("**Requested by**: @%s\n", data.RequestedBy) + } + return body + fmt.Sprintf("\nThe `%s` command had no effect because %s. Nothing further is needed.\n", + data.Command, data.Detail) +} + // RenderStopCommandAccepted renders the acknowledgement posted when a PR // comment stop command records durable stop intent. func RenderStopCommandAccepted(data StopCommandAcceptedData) string {