diff --git a/core/cli/deadline_test.go b/core/cli/deadline_test.go new file mode 100644 index 0000000..8bc8008 --- /dev/null +++ b/core/cli/deadline_test.go @@ -0,0 +1,90 @@ +package cli + +import ( + "context" + "strings" + "testing" + "time" + + "github.com/spf13/cobra" + + "github.com/NDDev-OpenNetwork/github-device-sync/core/domain" +) + +// A deadline is not a changed repository. `module update-pin --apply` used to +// report GDS_STALE_PLAN when its own context expired mid-observation, which +// sends the reader looking for a concurrent writer that does not exist. +func TestExpiredDeadlineIsNamedAsADeadline(t *testing.T) { + exitCode, envelope, _ := executeJSON(t, "--json", "--timeout", "1ns", "doctor") + if exitCode == 0 { + t.Fatalf("an expired deadline must not succeed: %#v", envelope) + } + if !containsFinding(envelope.Findings, "GDS_COMMAND_DEADLINE_EXCEEDED") { + t.Fatalf("expired deadline was not named as one: %#v", envelope.Findings) + } + for _, finding := range envelope.Findings { + if finding.Code != "GDS_COMMAND_DEADLINE_EXCEEDED" { + continue + } + if !strings.Contains(finding.Message, "not a changed repository") { + t.Fatalf("deadline finding does not say what it is not: %q", finding.Message) + } + if finding.Evidence["flag"] != "--timeout" { + t.Fatalf("deadline finding does not name the flag: %#v", finding.Evidence) + } + } +} + +// A successful command must not collect the finding just because it finished +// near its deadline. +func TestSuccessfulCommandIsNotLabelledADeadline(t *testing.T) { + _, envelope, _ := executeJSON(t, "--json", "identity", "new", "device") + if containsFinding(envelope.Findings, "GDS_COMMAND_DEADLINE_EXCEEDED") { + t.Fatalf("a successful command must not report a deadline: %#v", envelope.Findings) + } +} + +func deadlineFor(t *testing.T, lanes bool, flagSet bool) time.Duration { + t.Helper() + runner := &executor{options: options{cwd: ".", timeout: 2 * time.Minute}} + command := &cobra.Command{Use: "probe"} + command.Flags().DurationVar(&runner.options.timeout, "timeout", 2*time.Minute, "command deadline") + if flagSet { + if err := command.Flags().Set("timeout", "90s"); err != nil { + t.Fatal(err) + } + } + command.SetContext(context.Background()) + var observed time.Duration + operation := func(ctx context.Context) domain.Envelope { + if deadline, ok := ctx.Deadline(); ok { + observed = time.Until(deadline).Round(time.Second) + } + return domain.Success("probe", nil) + } + var err error + if lanes { + err = runner.runLanes(command, operation) + } else { + err = runner.run(command, operation) + } + if err != nil { + t.Fatal(err) + } + return observed +} + +// Commands that execute another repository's verification lanes need more than +// the deadline sized for a read -- update-pin runs them twice, once to plan and +// once to re-observe before mutating -- but an explicit --timeout always wins. +func TestLaneCommandsGetALongerDefaultUnlessTheCallerChose(t *testing.T) { + if got := deadlineFor(t, false, false); got > 3*time.Minute { + t.Fatalf("ordinary command deadline = %s, want the 2m read default", got) + } + if got := deadlineFor(t, true, false); got < 15*time.Minute { + t.Fatalf("lane command deadline = %s, want the longer default", got) + } + if got := deadlineFor(t, true, true); got > 2*time.Minute { + t.Fatalf("explicit --timeout was overridden: %s", got) + } +} diff --git a/core/cli/root.go b/core/cli/root.go index daccfc0..95261c8 100644 --- a/core/cli/root.go +++ b/core/cli/root.go @@ -4,6 +4,7 @@ package cli import ( "context" "encoding/json" + "errors" "fmt" "io" "runtime" @@ -1859,7 +1860,9 @@ func (executor *executor) modulePinCommand() *cobra.Command { Use: "update-pin", Short: "Update one exact consumer gitlink to a finalized module commit", Args: cobra.NoArgs, RunE: func(child *cobra.Command, _ []string) error { - return executor.run(child, func(ctx context.Context) domain.Envelope { + // Plan and apply both run the module's required lanes at the target + // commit, so this needs the lane deadline rather than the read one. + return executor.runLanes(child, func(ctx context.Context) domain.Envelope { if selectedModes(plan, applyPlanID, verifyOperationID) != 1 { return domain.NewEnvelope("gds module update-pin", domain.ExitInput, nil, domain.Finding{ Code: "GDS_MODULE_PIN_MODE_REQUIRED", Severity: domain.SeverityHigh, @@ -2753,9 +2756,34 @@ func (executor *executor) doctorCommand() *cobra.Command { return command } +// laneCommandTimeout is the default deadline for commands that execute another +// repository's declared verification lanes rather than reading state. Two +// minutes is right for a read and far too short for a command that runs a +// module's test suite twice -- once to plan, once to re-observe before the +// mutation -- which is how a working `module update-pin` came to look broken. +const laneCommandTimeout = 20 * time.Minute + func (executor *executor) run( command *cobra.Command, operation func(context.Context) domain.Envelope, +) error { + return executor.runWithin(command, 0, operation) +} + +// runLanes is run for commands that execute a module's verification lanes. An +// explicit --timeout always wins; the longer default applies only when the +// caller did not choose one. +func (executor *executor) runLanes( + command *cobra.Command, + operation func(context.Context) domain.Envelope, +) error { + return executor.runWithin(command, laneCommandTimeout, operation) +} + +func (executor *executor) runWithin( + command *cobra.Command, + minimum time.Duration, + operation func(context.Context) domain.Envelope, ) error { if executor.options.timeout <= 0 { envelope := domain.NewEnvelope("gds "+command.Name(), domain.ExitInput, nil, domain.Finding{ @@ -2766,9 +2794,26 @@ func (executor *executor) run( executor.result = &envelope return nil } - ctx, cancel := context.WithTimeout(command.Context(), executor.options.timeout) + deadline := executor.options.timeout + if minimum > deadline && !command.Flags().Changed("timeout") { + deadline = minimum + } + ctx, cancel := context.WithTimeout(command.Context(), deadline) defer cancel() envelope := operation(ctx) + // A deadline is not a changed repository. Without this, an expired context + // surfaces as whatever the interrupted step reported -- for update-pin that + // was GDS_STALE_PLAN, "the repository changed before its first mutation + // step", which sends the reader looking for a concurrent writer that does + // not exist. Say what actually happened, and say how long it had. + if errors.Is(ctx.Err(), context.DeadlineExceeded) && envelope.ExitCode != 0 { + envelope.Findings = append(envelope.Findings, domain.Finding{ + Code: "GDS_COMMAND_DEADLINE_EXCEEDED", + Severity: domain.SeverityHigh, + Message: "The command deadline expired before the operation finished; any earlier finding describes an interrupted step, not a changed repository.", + Evidence: map[string]any{"deadline": deadline.String(), "flag": "--timeout"}, + }) + } executor.result = &envelope return nil } diff --git a/docs/contracts/lifecycles-v1.md b/docs/contracts/lifecycles-v1.md index 45b48a9..99f81c3 100644 --- a/docs/contracts/lifecycles-v1.md +++ b/docs/contracts/lifecycles-v1.md @@ -139,6 +139,16 @@ absent one: the consumer holds the commit it is about to pin. The relaxation is exactly one gitlink wide; a staged, untracked or conflicted path, or a second unstaged one, still refuses with `GDS_MODULE_PIN_CONSUMER_STATE_UNSAFE`. +`update-pin` runs the module's required lanes twice -- once when planning at +the target commit, and once when the engine re-observes its preconditions before +the mutation -- so it defaults to a twenty-minute deadline rather than the +two-minute one sized for a read. An explicit `--timeout` always wins. Before +that, the default expired mid-observation and the engine reported +`GDS_STALE_PLAN`, "the repository changed before its first mutation step", which +sends the reader looking for a concurrent writer that does not exist. Any +command whose deadline expires now also carries +`GDS_COMMAND_DEADLINE_EXCEEDED`, naming the deadline and the flag. + Applying a pin needs no approval. The only mutation is a gitlink rewrite in the consumer's own working tree: it writes no provider, replaces no credential and publishes nothing, and the consumer's pull request and checks are its real gate.