diff --git a/.surface b/.surface index 2df0a4638..9b7eee49c 100644 --- a/.surface +++ b/.surface @@ -130,6 +130,9 @@ ARG basecamp config set 01 ARG basecamp config trust 00 [path] ARG basecamp config unset 00 ARG basecamp config untrust 00 [path] +ARG basecamp connect discard 00 +ARG basecamp connect import 00 +ARG basecamp connect redispatch 00 ARG basecamp docs archive 00 ARG basecamp docs doc create 00 ARG basecamp docs doc create 01 [content] @@ -669,8 +672,16 @@ CMD basecamp config trust CMD basecamp config unset CMD basecamp config untrust CMD basecamp connect +CMD basecamp connect discard +CMD basecamp connect doctor +CMD basecamp connect import +CMD basecamp connect redispatch +CMD basecamp connect release CMD basecamp connect setup +CMD basecamp connect shadow +CMD basecamp connect shadow promote CMD basecamp connect show +CMD basecamp connect status CMD basecamp docs CMD basecamp docs archive CMD basecamp docs doc @@ -5351,6 +5362,7 @@ FLAG basecamp connect --count type=bool FLAG basecamp connect --driver type=string FLAG basecamp connect --help type=bool FLAG basecamp connect --hints type=bool +FLAG basecamp connect --hold type=bool FLAG basecamp connect --ids-only type=bool FLAG basecamp connect --in type=string FLAG basecamp connect --jq type=string @@ -5368,6 +5380,111 @@ FLAG basecamp connect --stats type=bool FLAG basecamp connect --styled type=bool FLAG basecamp connect --todolist type=string FLAG basecamp connect --verbose type=count +FLAG basecamp connect discard --account type=string +FLAG basecamp connect discard --agent type=bool +FLAG basecamp connect discard --cache-dir type=string +FLAG basecamp connect discard --count type=bool +FLAG basecamp connect discard --help type=bool +FLAG basecamp connect discard --hints type=bool +FLAG basecamp connect discard --ids-only type=bool +FLAG basecamp connect discard --in type=string +FLAG basecamp connect discard --jq type=string +FLAG basecamp connect discard --json type=bool +FLAG basecamp connect discard --markdown type=bool +FLAG basecamp connect discard --md type=bool +FLAG basecamp connect discard --no-hints type=bool +FLAG basecamp connect discard --no-stats type=bool +FLAG basecamp connect discard --profile type=string +FLAG basecamp connect discard --project type=string +FLAG basecamp connect discard --quiet type=bool +FLAG basecamp connect discard --stats type=bool +FLAG basecamp connect discard --styled type=bool +FLAG basecamp connect discard --todolist type=string +FLAG basecamp connect discard --verbose type=count +FLAG basecamp connect doctor --account type=string +FLAG basecamp connect doctor --agent type=bool +FLAG basecamp connect doctor --cache-dir type=string +FLAG basecamp connect doctor --count type=bool +FLAG basecamp connect doctor --help type=bool +FLAG basecamp connect doctor --hints type=bool +FLAG basecamp connect doctor --ids-only type=bool +FLAG basecamp connect doctor --in type=string +FLAG basecamp connect doctor --jq type=string +FLAG basecamp connect doctor --json type=bool +FLAG basecamp connect doctor --markdown type=bool +FLAG basecamp connect doctor --md type=bool +FLAG basecamp connect doctor --no-hints type=bool +FLAG basecamp connect doctor --no-stats type=bool +FLAG basecamp connect doctor --profile type=string +FLAG basecamp connect doctor --project type=string +FLAG basecamp connect doctor --quiet type=bool +FLAG basecamp connect doctor --stats type=bool +FLAG basecamp connect doctor --styled type=bool +FLAG basecamp connect doctor --todolist type=string +FLAG basecamp connect doctor --verbose type=count +FLAG basecamp connect import --account type=string +FLAG basecamp connect import --agent type=bool +FLAG basecamp connect import --cache-dir type=string +FLAG basecamp connect import --count type=bool +FLAG basecamp connect import --help type=bool +FLAG basecamp connect import --hints type=bool +FLAG basecamp connect import --ids-only type=bool +FLAG basecamp connect import --in type=string +FLAG basecamp connect import --jq type=string +FLAG basecamp connect import --json type=bool +FLAG basecamp connect import --markdown type=bool +FLAG basecamp connect import --md type=bool +FLAG basecamp connect import --no-hints type=bool +FLAG basecamp connect import --no-stats type=bool +FLAG basecamp connect import --profile type=string +FLAG basecamp connect import --project type=string +FLAG basecamp connect import --quiet type=bool +FLAG basecamp connect import --stats type=bool +FLAG basecamp connect import --styled type=bool +FLAG basecamp connect import --todolist type=string +FLAG basecamp connect import --verbose type=count +FLAG basecamp connect redispatch --account type=string +FLAG basecamp connect redispatch --agent type=bool +FLAG basecamp connect redispatch --cache-dir type=string +FLAG basecamp connect redispatch --count type=bool +FLAG basecamp connect redispatch --help type=bool +FLAG basecamp connect redispatch --hints type=bool +FLAG basecamp connect redispatch --ids-only type=bool +FLAG basecamp connect redispatch --in type=string +FLAG basecamp connect redispatch --jq type=string +FLAG basecamp connect redispatch --json type=bool +FLAG basecamp connect redispatch --markdown type=bool +FLAG basecamp connect redispatch --md type=bool +FLAG basecamp connect redispatch --no-hints type=bool +FLAG basecamp connect redispatch --no-stats type=bool +FLAG basecamp connect redispatch --profile type=string +FLAG basecamp connect redispatch --project type=string +FLAG basecamp connect redispatch --quiet type=bool +FLAG basecamp connect redispatch --stats type=bool +FLAG basecamp connect redispatch --styled type=bool +FLAG basecamp connect redispatch --todolist type=string +FLAG basecamp connect redispatch --verbose type=count +FLAG basecamp connect release --account type=string +FLAG basecamp connect release --agent type=bool +FLAG basecamp connect release --cache-dir type=string +FLAG basecamp connect release --count type=bool +FLAG basecamp connect release --help type=bool +FLAG basecamp connect release --hints type=bool +FLAG basecamp connect release --ids-only type=bool +FLAG basecamp connect release --in type=string +FLAG basecamp connect release --jq type=string +FLAG basecamp connect release --json type=bool +FLAG basecamp connect release --markdown type=bool +FLAG basecamp connect release --md type=bool +FLAG basecamp connect release --no-hints type=bool +FLAG basecamp connect release --no-stats type=bool +FLAG basecamp connect release --profile type=string +FLAG basecamp connect release --project type=string +FLAG basecamp connect release --quiet type=bool +FLAG basecamp connect release --stats type=bool +FLAG basecamp connect release --styled type=bool +FLAG basecamp connect release --todolist type=string +FLAG basecamp connect release --verbose type=count FLAG basecamp connect setup --account type=string FLAG basecamp connect setup --agent type=bool FLAG basecamp connect setup --allow type=stringArray @@ -5404,6 +5521,48 @@ FLAG basecamp connect setup --verbose type=count FLAG basecamp connect setup --watch-completions type=stringArray FLAG basecamp connect setup --worker type=string FLAG basecamp connect setup --worktrees type=bool +FLAG basecamp connect shadow --account type=string +FLAG basecamp connect shadow --agent type=bool +FLAG basecamp connect shadow --cache-dir type=string +FLAG basecamp connect shadow --count type=bool +FLAG basecamp connect shadow --help type=bool +FLAG basecamp connect shadow --hints type=bool +FLAG basecamp connect shadow --ids-only type=bool +FLAG basecamp connect shadow --in type=string +FLAG basecamp connect shadow --jq type=string +FLAG basecamp connect shadow --json type=bool +FLAG basecamp connect shadow --markdown type=bool +FLAG basecamp connect shadow --md type=bool +FLAG basecamp connect shadow --no-hints type=bool +FLAG basecamp connect shadow --no-stats type=bool +FLAG basecamp connect shadow --profile type=string +FLAG basecamp connect shadow --project type=string +FLAG basecamp connect shadow --quiet type=bool +FLAG basecamp connect shadow --stats type=bool +FLAG basecamp connect shadow --styled type=bool +FLAG basecamp connect shadow --todolist type=string +FLAG basecamp connect shadow --verbose type=count +FLAG basecamp connect shadow promote --account type=string +FLAG basecamp connect shadow promote --agent type=bool +FLAG basecamp connect shadow promote --cache-dir type=string +FLAG basecamp connect shadow promote --count type=bool +FLAG basecamp connect shadow promote --help type=bool +FLAG basecamp connect shadow promote --hints type=bool +FLAG basecamp connect shadow promote --ids-only type=bool +FLAG basecamp connect shadow promote --in type=string +FLAG basecamp connect shadow promote --jq type=string +FLAG basecamp connect shadow promote --json type=bool +FLAG basecamp connect shadow promote --markdown type=bool +FLAG basecamp connect shadow promote --md type=bool +FLAG basecamp connect shadow promote --no-hints type=bool +FLAG basecamp connect shadow promote --no-stats type=bool +FLAG basecamp connect shadow promote --profile type=string +FLAG basecamp connect shadow promote --project type=string +FLAG basecamp connect shadow promote --quiet type=bool +FLAG basecamp connect shadow promote --stats type=bool +FLAG basecamp connect shadow promote --styled type=bool +FLAG basecamp connect shadow promote --todolist type=string +FLAG basecamp connect shadow promote --verbose type=count FLAG basecamp connect show --account type=string FLAG basecamp connect show --agent type=bool FLAG basecamp connect show --cache-dir type=string @@ -5425,6 +5584,28 @@ FLAG basecamp connect show --stats type=bool FLAG basecamp connect show --styled type=bool FLAG basecamp connect show --todolist type=string FLAG basecamp connect show --verbose type=count +FLAG basecamp connect status --account type=string +FLAG basecamp connect status --agent type=bool +FLAG basecamp connect status --cache-dir type=string +FLAG basecamp connect status --count type=bool +FLAG basecamp connect status --help type=bool +FLAG basecamp connect status --hints type=bool +FLAG basecamp connect status --ids-only type=bool +FLAG basecamp connect status --in type=string +FLAG basecamp connect status --jq type=string +FLAG basecamp connect status --json type=bool +FLAG basecamp connect status --markdown type=bool +FLAG basecamp connect status --md type=bool +FLAG basecamp connect status --no-hints type=bool +FLAG basecamp connect status --no-stats type=bool +FLAG basecamp connect status --profile type=string +FLAG basecamp connect status --project type=string +FLAG basecamp connect status --quiet type=bool +FLAG basecamp connect status --shadow type=bool +FLAG basecamp connect status --stats type=bool +FLAG basecamp connect status --styled type=bool +FLAG basecamp connect status --todolist type=string +FLAG basecamp connect status --verbose type=count FLAG basecamp docs --account type=string FLAG basecamp docs --agent type=bool FLAG basecamp docs --cache-dir type=string @@ -18604,8 +18785,16 @@ SUB basecamp config trust SUB basecamp config unset SUB basecamp config untrust SUB basecamp connect +SUB basecamp connect discard +SUB basecamp connect doctor +SUB basecamp connect import +SUB basecamp connect redispatch +SUB basecamp connect release SUB basecamp connect setup +SUB basecamp connect shadow +SUB basecamp connect shadow promote SUB basecamp connect show +SUB basecamp connect status SUB basecamp docs SUB basecamp docs archive SUB basecamp docs doc diff --git a/e2e/smoke/smoke_lifecycle.bats b/e2e/smoke/smoke_lifecycle.bats index df00a6567..2c052c281 100644 --- a/e2e/smoke/smoke_lifecycle.bats +++ b/e2e/smoke/smoke_lifecycle.bats @@ -24,6 +24,34 @@ load smoke_helper mark_out_of_scope "Reads the connector policy a connected profile's setup wrote — covered by Go tests in internal/commands" } +@test "connect status is out of scope" { + mark_out_of_scope "Reads a local connector ledger the smoke account does not have — covered by Go tests in internal/commands and internal/connector" +} + +@test "connect doctor is out of scope" { + mark_out_of_scope "Needs a set-up connector profile and starts its MCP server — covered by Go tests in internal/commands" +} + +@test "connect redispatch is out of scope" { + mark_out_of_scope "Decides a record in a local connector ledger — covered by Go tests in internal/commands and internal/connector" +} + +@test "connect discard is out of scope" { + mark_out_of_scope "Decides a record in a local connector ledger — covered by Go tests in internal/commands and internal/connector" +} + +@test "connect release is out of scope" { + mark_out_of_scope "Clears the hold in a local connector ledger — covered by Go tests in internal/commands and internal/connector" +} + +@test "connect shadow promote is out of scope" { + mark_out_of_scope "Moves a local shadow ledger — covered by Go tests, including a process killed at every step, in internal/connector" +} + +@test "connect import is out of scope" { + mark_out_of_scope "Applies a reconciliation file to a local connector ledger — covered by Go tests in internal/commands and internal/connector" +} + @test "auth refresh is out of scope" { mark_out_of_scope "Requires OAuth credentials" } diff --git a/internal/commands/commands.go b/internal/commands/commands.go index 8c2c75b7a..a742a76a3 100644 --- a/internal/commands/commands.go +++ b/internal/commands/commands.go @@ -146,7 +146,7 @@ func CommandCategories() []CommandCategory { {Name: "bonfire", Category: "additional", Description: "Multi-chat orchestration", Actions: []string{"split", "layout"}, Experimental: true, DevOnly: true}, {Name: "api", Category: "additional", Description: "Raw API access"}, {Name: "mcp", Category: "additional", Description: "Serve Basecamp to MCP clients over stdio"}, - {Name: "connect", Category: "additional", Description: "Set up a local agent connector for a Basecamp agent", Actions: []string{"setup", "show"}}, + {Name: "connect", Category: "additional", Description: "Run a local agent connector for a Basecamp agent, and see and decide what it runs", Actions: []string{"setup", "show", "status", "doctor", "redispatch", "discard", "release", "shadow", "import"}}, {Name: "help", Category: "additional", Description: "Show help"}, {Name: "version", Category: "additional", Description: "Show version"}, }, diff --git a/internal/commands/connect.go b/internal/commands/connect.go index f8453cbd1..a5e0ee389 100644 --- a/internal/commands/connect.go +++ b/internal/commands/connect.go @@ -50,7 +50,17 @@ object per line (events seen, verdicts, dispatches, lifecycle messages; never content), and logs go to stderr. SIGINT and SIGTERM cancel live workers with stop reason shutdown, settle them, and exit 130 and 143. --shadow admits and logs in an -isolated state directory and dispatches nothing. macOS and Linux only.`, +isolated state directory and dispatches nothing. --hold sets a durable hold: +intake and admission run, nothing dispatches or posts, and earlier records +wait for review, until basecamp connect release. macOS and Linux only. + + basecamp connect status what it heard, holds and ran + basecamp connect doctor what it needs to run + basecamp connect redispatch <id> authorize a record to run + basecamp connect discard <id> close a record without running it + basecamp connect release clear the hold + basecamp connect shadow promote make the shadow ledger the connector's, held + basecamp connect import <file> apply a cutover reconciliation file`, Example: ` basecamp connect setup -P agent --operator-profile me --route 12345=/src/app basecamp connect -P agent basecamp connect -P agent --project 12345 --shadow`, @@ -64,9 +74,8 @@ isolated state directory and dispatches nothing. macOS and Linux only.`, }, } addConnectRunFlags(cmd, &run) - cmd.AddCommand(newConnectSetupCmd()) - cmd.AddCommand(newConnectWorkerMCPCmd()) - cmd.AddCommand(newConnectShowCmd()) + cmd.AddCommand(newConnectSetupCmd(), newConnectWorkerMCPCmd(), newConnectShowCmd(), newConnectStatusCmd(), newConnectDoctorCmd(), + newConnectRedispatchCmd(), newConnectDiscardCmd(), newConnectReleaseCmd(), newConnectShadowCmd(), newConnectImportCmd()) return cmd } diff --git a/internal/commands/connect_doctor.go b/internal/commands/connect_doctor.go new file mode 100644 index 000000000..2055492b1 --- /dev/null +++ b/internal/commands/connect_doctor.go @@ -0,0 +1,226 @@ +package commands + +import ( + "context" + "errors" + "fmt" + "os" + "os/exec" + "path/filepath" + "runtime" + "strconv" + "time" + + "github.com/spf13/cobra" + + "github.com/basecamp/basecamp-sdk/go/pkg/basecamp" + + "github.com/basecamp/basecamp-cli/internal/connector" + "github.com/basecamp/basecamp-cli/internal/connector/setup" + "github.com/basecamp/basecamp-cli/internal/output" + "github.com/basecamp/basecamp-cli/internal/richtext" +) + +// mcpHandshakeTimeout bounds doctor's MCP handshake. A var so a test can +// shorten it; production only reads it, and a test that changes it must not +// run in parallel. +var mcpHandshakeTimeout = 30 * time.Second + +func newConnectDoctorCmd() *cobra.Command { + return &cobra.Command{ + Use: "doctor", + Short: "Check what the connector needs to run", + Long: `Check the connector for a set-up profile: connect.json, the token, the agent's +identity, the stream ticket mint, the account feed, the ledger (its gaps, open +losses, hold and messages waiting for a person), the worker binary the driver +runs, and a handshake with the agent's Basecamp MCP server, started with a +worker's environment (without the basecamp_connect domain, which only a +dispatched task's token opens). + +It writes nothing to the connector's ledger and posts nothing to Basecamp. +Renewing the profile's own credential, which every command does when its token +is due, may still write the credential store.`, + Example: ` basecamp connect doctor -P agent`, + Args: cobra.NoArgs, + RunE: runConnectDoctor, + } +} + +func runConnectDoctor(cmd *cobra.Command, _ []string) error { + ctx := cmd.Context() + if os.Getenv("BASECAMP_TOKEN") != "" { + return errEnvTokenShadows("doctor checks the agent its profile holds, and BASECAMP_TOKEN would override it") + } + p, err := loadConnectProfile(cmd) + if err != nil { + return err + } + checks := []setup.Check{{Name: "connect.json", Status: setup.StatusPass, + Message: fmt.Sprintf("Agent person %d in account %s, driver %s, worker %s", p.file.Agent.PersonID, p.file.AccountID, p.file.Driver, p.file.WorkerName())}} + checks = append(checks, driverChecks(p)...) + + agent, agentErr := verifiedConnectAgent(ctx, p) + if agentErr != nil { + checks = append(checks, setup.Check{Name: "Token and identity", Status: setup.StatusFail, Message: errorMessage(agentErr), + Hint: "Reconnect the agent's profile, then run basecamp connect setup again."}) + } else { + checks = append(checks, + setup.Check{Name: "Token", Status: setup.StatusPass, Message: "The profile's credential yields a token"}, + setup.Check{Name: "Identity", Status: setup.StatusPass, Message: fmt.Sprintf("Person %d, as connect.json names", agent.personID)}, + setup.TicketCheck(ctx, agent.reader, agent.kind), + feedCheck(ctx, agent.client.ForAccount(agent.account)), + ) + } + checks = append(checks, ledgerChecks(ctx, p)...) + checks = append(checks, workerBinaryChecks(p.file)...) + checks = append(checks, mcpHandshakeCheck(ctx, p.name)) + + result := summarizeChecks(asDoctorChecks(checks)) + title := "Connector doctor for profile " + strconv.Quote(p.name) + if p.app.Output.EffectiveFormat() == output.FormatStyled { + renderChecksStyled(cmd.OutOrStdout(), title, result) + if result.Failed > 0 { + return doctorNotReady(checks) + } + return nil + } + if result.Failed > 0 { + return doctorNotReady(checks) + } + return p.app.OK(result, output.WithSummary(result.Summary())) +} + +func errorMessage(err error) string { + var apiErr *output.Error + if errors.As(err, &apiErr) { + return apiErr.Message + } + return richtext.SanitizeSingleLine(err.Error()) +} + +func doctorNotReady(checks []setup.Check) error { + report := &setup.Report{} + report.Add(checks...) + failures := report.Failed() + msg := "The connector is not ready:" + hint := "" + for _, c := range failures { + msg += " " + c.Name + ": " + c.Message + ";" + if hint == "" { + hint = c.Hint + } + } + return &output.Error{Code: codeNotReady, Message: msg[:len(msg)-1], Hint: hint} +} + +// feedCheck polls one page of the account feed at the present, as the +// connector's poll lane does. The page is dropped; its position is a resumable +// token and is never shown. +func feedCheck(ctx context.Context, account *basecamp.AccountClient) setup.Check { + c := setup.Check{Name: "Account feed"} + _, err := account.EventFeed().PollEvents(ctx, &basecamp.PollEventsOptions{Since: "now", ActorTypes: []string{"person"}}) + if err != nil { + c.Status, c.Message = setup.StatusFail, "Polling the account feed failed: "+setup.ErrorText(err) + c.Hint = "The account event feed has to be enabled for this account and the agent." + return c + } + c.Status, c.Message = setup.StatusPass, "The agent can poll the account feed" + return c +} + +// ledgerChecks reports what the ledger records that a person should know: +// gaps with their epoch ids, losses, the hold, and lifecycle messages that +// wait for a decision. It reads the ledger read-only. +func ledgerChecks(ctx context.Context, p connectProfile) []setup.Check { + dir, err := connectStatePath(p.file, false) + if err != nil { + return []setup.Check{{Name: "Ledger", Status: setup.StatusFail, Message: errorMessage(err)}} + } + ledger, err := connector.OpenLedgerReadOnly(ctx, filepath.Join(dir, connector.LedgerFile)) + if errors.Is(err, os.ErrNotExist) { + return []setup.Check{{Name: "Ledger", Status: setup.StatusSkip, Message: "No ledger yet: the connector has not run"}} + } + if err != nil { + return []setup.Check{{Name: "Ledger", Status: setup.StatusFail, Message: errorMessage(err)}} + } + defer func() { _ = ledger.Close() }() + s, err := ledger.Status(ctx, nil) + if err != nil { + return []setup.Check{{Name: "Ledger", Status: setup.StatusFail, Message: errorMessage(err)}} + } + checks := []setup.Check{{Name: "Ledger", Status: setup.StatusPass, Message: fmt.Sprintf("Schema %d, private, readable", s.SchemaVersion)}} + for _, g := range s.Gaps { + msg := fmt.Sprintf("A %s gap was recorded at %s", g.Class, g.DetectedAt.UTC().Format(time.RFC3339)) + if g.EpochAfterID != nil { + msg += fmt.Sprintf("; history at or below event %d is gone", *g.EpochAfterID) + } + checks = append(checks, setup.Check{Name: fmt.Sprintf("Gap %d", g.ID), Status: setup.StatusWarn, Message: msg}) + } + if len(s.Losses) > 0 || s.Unrecovered > 0 { + checks = append(checks, setup.Check{Name: "Losses", Status: setup.StatusWarn, + Message: fmt.Sprintf("%d overflow losses open, %d event ids unrecovered", len(s.Losses), s.Unrecovered)}) + } + if s.Hold != nil { + checks = append(checks, setup.Check{Name: "Hold", Status: setup.StatusWarn, + Message: fmt.Sprintf("Held since %s by %s: nothing dispatches or posts", s.Hold.HeldAt.UTC().Format(time.RFC3339), richtext.SanitizeSingleLine(s.Hold.HeldBy)), + Hint: "Review held records in basecamp connect status, then basecamp connect release -P " + shellQuote(p.name)}) + } + if len(s.Indeterminate) > 0 { + checks = append(checks, setup.Check{Name: "Lifecycle messages", Status: setup.StatusWarn, + Message: fmt.Sprintf("%d messages may or may not have been posted and wait for a person", len(s.Indeterminate))}) + } + return checks +} + +// workerBinaries are the executables the configured driver runs for the +// configured worker. +func workerBinaries(file setup.File) []string { + worker := file.WorkerName() + if file.Driver == setup.DriverACP { + switch worker { + case setup.WorkerClaude: + return []string{"claude-agent-acp"} + default: + return []string{worker + "-acp"} + } + } + return []string{worker} +} + +func workerBinaryChecks(file setup.File) []setup.Check { + bins := workerBinaries(file) + checks := make([]setup.Check, 0, len(bins)) + for _, bin := range bins { + c := setup.Check{Name: "Worker " + bin} + path, err := exec.LookPath(bin) + if err != nil { + c.Status, c.Message = setup.StatusFail, fmt.Sprintf("%s is not on PATH", bin) + c.Hint = "Install it, or put it on the PATH the connector starts with." + } else { + c.Status, c.Message = setup.StatusPass, richtext.SanitizeSingleLine(path) + } + checks = append(checks, c) + } + return checks +} + +// driverChecks refuses what the run command refuses: doctor never calls a +// connector ready that would not start. +func driverChecks(p connectProfile) []setup.Check { + var checks []setup.Check + if !connectSupportedOS(runtime.GOOS) { + checks = append(checks, setup.Check{Name: "Platform", Status: setup.StatusFail, + Message: fmt.Sprintf("The connector does not run on %s: it ends a worker by its process group and start time, which macOS and Linux alone can say", runtime.GOOS)}) + } + if p.file.Driver != setup.DriverSpawn { + checks = append(checks, setup.Check{Name: "Driver", Status: setup.StatusFail, + Message: fmt.Sprintf("Driver %q is not available yet; the connector runs %q", p.file.Driver, setup.DriverSpawn), + Hint: "basecamp connect setup -P " + shellQuote(p.name) + " --driver spawn"}) + } + if p.file.Worktrees { + checks = append(checks, setup.Check{Name: "Worktrees", Status: setup.StatusFail, + Message: "connect.json asks for worktrees, which this basecamp does not support yet, and the connector refuses to start with them", + Hint: "basecamp connect setup -P " + shellQuote(p.name) + " --worktrees=false"}) + } + return checks +} diff --git a/internal/commands/connect_doctor_mcp_other.go b/internal/commands/connect_doctor_mcp_other.go new file mode 100644 index 000000000..d7900f751 --- /dev/null +++ b/internal/commands/connect_doctor_mcp_other.go @@ -0,0 +1,13 @@ +//go:build !unix + +package commands + +import ( + "context" + + "github.com/basecamp/basecamp-cli/internal/connector/setup" +) + +func mcpHandshakeCheck(context.Context, string) setup.Check { + return setup.Check{Name: "MCP handshake", Status: setup.StatusSkip, Message: "The connector runs on macOS and Linux only"} +} diff --git a/internal/commands/connect_doctor_mcp_unix.go b/internal/commands/connect_doctor_mcp_unix.go new file mode 100644 index 000000000..6659fbc93 --- /dev/null +++ b/internal/commands/connect_doctor_mcp_unix.go @@ -0,0 +1,103 @@ +//go:build unix + +package commands + +import ( + "context" + "fmt" + "os" + "os/exec" + "syscall" + + "github.com/modelcontextprotocol/go-sdk/mcp" + + "github.com/basecamp/basecamp-cli/internal/connector" + "github.com/basecamp/basecamp-cli/internal/connector/driver" + "github.com/basecamp/basecamp-cli/internal/connector/setup" + "github.com/basecamp/basecamp-cli/internal/version" +) + +// mcpServerCommand is the agent's MCP server as a worker's is started: this +// binary's mcp command on the profile. A test seam. +var mcpServerCommand = func(profile string) (string, []string, error) { + exe, err := os.Executable() + return exe, []string{"mcp", "--profile", profile}, err +} + +// mcpHandshakeCheck starts the agent's Basecamp MCP server with the +// environment and process group the dispatcher gives a worker's, through this +// binary's ordinary mcp command rather than the worker subcommand, completes the MCP +// handshake and lists its tools, then ends the group it started. It does not +// serve the basecamp_connect domain: that needs a live task's token, which +// only a dispatch mints, and doctor starts no task. The connector's ledger, +// which that domain reads, is checked on its own. +func mcpHandshakeCheck(ctx context.Context, profile string) setup.Check { + c := setup.Check{Name: "MCP handshake"} + exe, args, err := mcpServerCommand(profile) + if err != nil { + c.Status, c.Message = setup.StatusFail, "Cannot locate this binary: "+err.Error() + return c + } + ctx, cancel := context.WithTimeout(ctx, mcpHandshakeTimeout) + defer cancel() + + cmd := exec.CommandContext(ctx, exe, args...) //nolint:gosec // this binary, with a validated profile name + cmd.Env = driver.BuildEnv(append(append([]string{}, driver.BaseEnv...), connector.MCPServerEnv...), os.LookupEnv, nil) + cmd.SysProcAttr = &syscall.SysProcAttr{Setpgid: true} + // The context bounds the MCP calls, not the process: this function alone + // ends the process and alone waits on it, so its group is always signaled + // while the leader is unreaped and the group id is still this command's. + cmd.Cancel = func() error { return nil } + stdin, err := cmd.StdinPipe() + if err != nil { + c.Status, c.Message = setup.StatusFail, "Cannot start the agent's MCP server: "+setup.ErrorText(err) + return c + } + stdout, err := cmd.StdoutPipe() + if err != nil { + c.Status, c.Message = setup.StatusFail, "Cannot start the agent's MCP server: "+setup.ErrorText(err) + return c + } + if err := cmd.Start(); err != nil { + c.Status, c.Message = setup.StatusFail, "Cannot start the agent's MCP server: "+setup.ErrorText(err) + return c + } + leader := cmd.Process.Pid + var session *mcp.ClientSession + defer func() { + if session != nil { + _ = session.Close() + } + // The group, then the leader: nothing else waits on it, so it is not + // reaped before this signal, and a descendant goes with it. + if leader > 1 { + _ = syscall.Kill(-leader, syscall.SIGKILL) + } + _ = stdin.Close() + _ = stdout.Close() + _ = cmd.Wait() + }() + + client := mcp.NewClient(&mcp.Implementation{Name: "basecamp-connect-doctor", Version: version.Version}, nil) + session, err = client.Connect(ctx, &mcp.IOTransport{Reader: stdout, Writer: stdin}, nil) + if err != nil { + session = nil + c.Status, c.Message = setup.StatusFail, "The agent's MCP server did not complete the handshake: "+setup.ErrorText(err) + c.Hint = "Run basecamp mcp -P " + shellQuote(profile) + " and read its stderr." + return c + } + tools := 0 + for _, err := range session.Tools(ctx, nil) { + if err != nil { + c.Status, c.Message = setup.StatusFail, "The agent's MCP server did not list its tools: "+setup.ErrorText(err) + return c + } + tools++ + } + if tools == 0 { + c.Status, c.Message = setup.StatusFail, "The agent's MCP server lists no tools" + return c + } + c.Status, c.Message = setup.StatusPass, fmt.Sprintf("The agent's MCP server (basecamp mcp -P %s) answered with %d tools; the basecamp_connect domain is served only to a dispatched worker", shellQuote(profile), tools) + return c +} diff --git a/internal/commands/connect_operator.go b/internal/commands/connect_operator.go new file mode 100644 index 000000000..66e034a2d --- /dev/null +++ b/internal/commands/connect_operator.go @@ -0,0 +1,786 @@ +package commands + +import ( + "context" + "errors" + "fmt" + "io" + "os" + "os/user" + "path/filepath" + "strconv" + "strings" + "time" + + "github.com/spf13/cobra" + + "github.com/basecamp/basecamp-sdk/go/pkg/basecamp" + + "github.com/basecamp/basecamp-cli/internal/appctx" + "github.com/basecamp/basecamp-cli/internal/config" + "github.com/basecamp/basecamp-cli/internal/connector" + "github.com/basecamp/basecamp-cli/internal/connector/admission" + "github.com/basecamp/basecamp-cli/internal/connector/driver" + "github.com/basecamp/basecamp-cli/internal/connector/setup" + "github.com/basecamp/basecamp-cli/internal/output" + "github.com/basecamp/basecamp-cli/internal/richtext" +) + +// The operator's commands on a connector's ledger: status, redispatch, +// discard, release, shadow promote and import. doctor is in connect_doctor.go. +// Each resolves the connector from the profile's connect.json, locally. + +// connectProfile is a set-up profile, read without the network. +type connectProfile struct { + app *appctx.App + name string + file setup.File +} + +func loadConnectProfile(cmd *cobra.Command) (connectProfile, error) { + app := appctx.FromContext(cmd.Context()) + if app == nil { + return connectProfile{}, errors.New("app not initialized") + } + name := app.Config.ActiveProfile + if name == "" { + return connectProfile{}, output.ErrUsageHint("This needs the agent's profile", "Pass -P/--profile <name>, a profile set up with `basecamp connect setup`.") + } + if !isValidProfileName(name) { + return connectProfile{}, output.ErrUsage(fmt.Sprintf("Invalid profile name %q", name)) + } + path, err := setup.Path(config.GlobalConfigDir(), name) + if err != nil { + return connectProfile{}, output.ErrUsage(err.Error()) + } + file, err := setup.Load(path) + switch { + case errors.Is(err, os.ErrNotExist): + return connectProfile{}, output.ErrUsageHint(fmt.Sprintf("Profile %q is not set up as a connector", name), "Run: basecamp connect setup -P "+shellQuote(name)) + case err != nil: + return connectProfile{}, output.ErrUsage("connect.json cannot be used: " + err.Error()) + } + return connectProfile{app: app, name: name, file: file}, nil +} + +// operatorName is who a decision is recorded as: the local user who ran it. +func operatorName() string { + name := "" + if u, err := user.Current(); err == nil { + name = u.Username + } + if name == "" { + name = os.Getenv("USER") + } + if name == "" { + name = "unknown" + } + return "local:" + richtext.SanitizeSingleLine(name) +} + +func parseEventIDArg(raw string) (int64, error) { + id, err := strconv.ParseInt(strings.TrimSpace(raw), 10, 64) + if err != nil || id <= 0 { + return 0, output.ErrUsage(fmt.Sprintf("Invalid event id %q: expected a positive number", raw)) + } + return id, nil +} + +// openConnectLedger opens the connector's ledger for a decision. It must +// already exist: a decision is about records the connector wrote. The returned +// func releases whatever the open holds, and is never nil. +// +// requireStopped takes the instance lock for the whole command, for the work +// that cannot run beside a connector (an import). Otherwise the lock is taken +// only when the ledger is older than this build, because opening it then +// migrates it, and a connector running on the older schema must not have its +// triggers replaced underneath it. Either way the lock is the authority: the +// metadata beside it is written best-effort and says nothing on its own. +func openConnectLedger(ctx context.Context, p connectProfile, requireStopped bool) (*connector.Ledger, func(), error) { + done := func() {} + dir, err := connectStatePath(p.file, false) + if err != nil { + return nil, done, err + } + path := filepath.Join(dir, connector.LedgerFile) + if _, err := os.Lstat(path); errors.Is(err, os.ErrNotExist) { + return nil, done, output.ErrUsageHint(fmt.Sprintf("Profile %q's connector has no ledger yet", p.name), "Run the connector first: basecamp connect -P "+shellQuote(p.name)) + } + // Opening for a decision migrates the ledger, and a connector running on + // an older binary's schema must not have its triggers replaced under it. + // The instance lock is what says no connector is running — the metadata + // beside it is diagnostic — so it is taken before the migration and held + // until the ledger is closed. + outOfDate := false + if reader, err := connector.OpenLedgerReadOnly(ctx, path); err == nil { + _ = reader.Close() + } else if errors.Is(err, connector.ErrLedgerOutOfDate) { + outOfDate = true + } else if !errors.Is(err, os.ErrNotExist) { + return nil, done, err + } + if requireStopped || outOfDate { + lock, lockErr := connector.AcquireInstanceLock(dir, p.file.AccountID, p.file.Agent.PersonID, time.Now()) + switch { + case errors.Is(lockErr, connector.ErrAlreadyRunning) && outOfDate: + return nil, done, output.ErrUsageHint( + "The connector is running on a ledger older than this build, and this command would migrate it underneath it: "+lockErr.Error(), + "Stop the connector, run this command, and start it again.") + case errors.Is(lockErr, connector.ErrAlreadyRunning): + return nil, done, &output.Error{Code: output.CodeLockUnavailable, Message: lockErr.Error(), + Hint: "Stop the connector before this command."} + case lockErr != nil: + return nil, done, lockErr + } + done = func() { _ = lock.Release() } + } + ledger, err := connector.OpenLedger(path) //nolint:contextcheck // OpenLedger migrates on its own context + if err != nil { + done() + return nil, func() {}, err + } + // A verdict a redispatch writes calls for the lifecycle messages a running + // connector's verdict would: the same intents, which the connector's outbox + // sends. + ledger.SetHooks(connector.LifecycleHooks(ledger, connector.LifecycleOptions{})) + return ledger, func() { + _ = ledger.Close() + done() + }, nil +} + +func decisionError(err error) error { + if errors.Is(err, connector.ErrDecisionRefused) || errors.Is(err, connector.ErrNoSuchRecord) { + msg := strings.TrimPrefix(err.Error(), "connector: ") + return output.ErrUsage(strings.TrimSuffix(msg, ": "+connector.ErrDecisionRefused.Error())) + } + return err +} + +// --- status --------------------------------------------------------------- + +func newConnectStatusCmd() *cobra.Command { + var shadow bool + cmd := &cobra.Command{ + Use: "status", + Short: "Show what the connector heard, holds and ran", + Long: `Show the connector's ledger: what its instance lock file says, the hold, the +feed position (whether one is held, never the position), the last poll-served id, +gaps and losses, queue depths, live tasks, retained worktrees, lifecycle +messages waiting for a person, held records, and the last 20 dispatches with +their outcomes. + +It reads the ledger read-only and takes no lock, so it works while the +connector runs. It shows no content, no feed position and no token; a held +record's recording URL is shown so a person can open what was asked.`, + Example: ` basecamp connect status -P agent + basecamp connect status -P agent --shadow --json`, + Args: cobra.NoArgs, + RunE: func(cmd *cobra.Command, _ []string) error { + return runConnectStatus(cmd, shadow) + }, + } + cmd.Flags().BoolVar(&shadow, "shadow", false, "Show the shadow run's ledger") + return cmd +} + +// connectStatusReport is status's output. +type connectStatusReport struct { + Profile string `json:"profile"` + Shadow bool `json:"shadow"` + LockHolder *connectLockHolder `json:"lock_holder,omitempty"` + Status connector.Status `json:"status"` +} + +// connectLockHolder is what a connector wrote beside its instance lock. It is +// diagnostic, not an answer: the metadata is written best effort after the +// lock is taken, it stays behind after a crash, and a pid may since belong to +// another process. Status never takes the lock, so it cannot say more. +type connectLockHolder struct { + PID int `json:"pid"` + StartedAt string `json:"started_at"` + // PID is present, absent or unknown — signal 0's answer, where the + // platform can give one. Present says a process has that pid, not that it + // is that connector. + PIDStatus string `json:"pid_status"` +} + +func runConnectStatus(cmd *cobra.Command, shadow bool) error { + p, err := loadConnectProfile(cmd) + if err != nil { + return err + } + dir, err := connectStatePath(p.file, shadow) + if err != nil { + return err + } + ledger, err := connector.OpenLedgerReadOnly(cmd.Context(), filepath.Join(dir, connector.LedgerFile)) + if errors.Is(err, os.ErrNotExist) { + if shadow { + return output.ErrUsageHint(fmt.Sprintf("Profile %q has no shadow ledger", p.name), "Run the shadow connector first: basecamp connect -P "+shellQuote(p.name)+" --shadow") + } + return output.ErrUsageHint(fmt.Sprintf("Profile %q's connector has no ledger yet", p.name), "Run the connector first: basecamp connect -P "+shellQuote(p.name)) + } + if err != nil { + return err + } + defer func() { _ = ledger.Close() }() + status, err := ledger.Status(cmd.Context(), nil) + if err != nil { + return err + } + for i, t := range status.Tasks { + status.Tasks[i].Worker = recordedWorkerState(t) + status.Tasks[i].Taker = recordedTakerState(t) + } + report := connectStatusReport{Profile: p.name, Shadow: shadow, Status: status} + if holder, ok := connector.InstanceHolder(dir, p.file.AccountID, p.file.Agent.PersonID); ok { + report.LockHolder = &connectLockHolder{PID: holder.PID, StartedAt: holder.StartedAt, PIDStatus: processPresence(holder.PID)} + } + if p.app.Output.EffectiveFormat() == output.FormatStyled { + renderConnectStatus(cmd.OutOrStdout(), report) + return nil + } + return p.app.OK(report, output.WithSummary(connectStatusSummary(report))) +} + +func connectStatusSummary(r connectStatusReport) string { + parts := []string{} + if r.Status.Hold != nil { + parts = append(parts, "held") + } + parts = append(parts, + fmt.Sprintf("%d live tasks", len(r.Status.Tasks)), + fmt.Sprintf("%d held records", len(r.Status.Held)), + fmt.Sprintf("%d indeterminate messages", len(r.Status.Indeterminate))) + return strings.Join(parts, ", ") +} + +func renderConnectStatus(w io.Writer, r connectStatusReport) { + s := r.Status + clean := richtext.SanitizeSingleLine + stamp := func(t time.Time) string { return t.UTC().Format("2006-01-02 15:04:05Z") } + title := "Connector status for profile " + strconv.Quote(r.name()) + if r.Shadow { + title += " (shadow)" + } + fmt.Fprintf(w, "%s\n\n", title) + + switch { + case r.LockHolder == nil: + fmt.Fprintf(w, " Lock file none beside the ledger\n") + case r.LockHolder.PIDStatus == pidPresent: + fmt.Fprintf(w, " Lock file pid %d since %s, and a process with that pid is there (diagnostic: status takes no lock)\n", + r.LockHolder.PID, clean(r.LockHolder.StartedAt)) + case r.LockHolder.PIDStatus == pidAbsent: + fmt.Fprintf(w, " Lock file pid %d since %s, and no process has that pid (left behind by a crash, or ended)\n", + r.LockHolder.PID, clean(r.LockHolder.StartedAt)) + default: + fmt.Fprintf(w, " Lock file pid %d since %s; whether that process exists cannot be said here\n", + r.LockHolder.PID, clean(r.LockHolder.StartedAt)) + } + if s.Connection != nil { + fmt.Fprintf(w, " Last run %s at %s", clean(s.Connection.State), stamp(s.Connection.ChangedAt)) + if s.Connection.Detail != "" { + fmt.Fprintf(w, " (%s)", clean(s.Connection.Detail)) + } + fmt.Fprintln(w) + } + if s.Hold != nil { + fmt.Fprintf(w, " Hold set by %s at %s (%s, generation %d): nothing dispatches or posts until release\n", + clean(s.Hold.HeldBy), stamp(s.Hold.HeldAt), clean(s.Hold.Cause), s.Hold.Generation) + } else { + fmt.Fprintf(w, " Hold none\n") + } + for _, pos := range s.Positions { + held := "no position" + if pos.HasPosition { + held = "position held" + } + fmt.Fprintf(w, " Feed %s; last poll-served id %d; updated %s\n", held, pos.LastPollServedID, stamp(pos.UpdatedAt)) + } + for _, g := range s.Gaps { + epoch := "" + if g.EpochAfterID != nil { + epoch = fmt.Sprintf(", epoch after %d", *g.EpochAfterID) + } + fmt.Fprintf(w, " Gap %s at %s%s\n", clean(g.Class), stamp(g.DetectedAt), epoch) + } + for _, l := range s.Losses { + fmt.Fprintf(w, " Loss %d dropped, %d still missing, window ends %s\n", l.Dropped, l.Missing, stamp(l.DeadlineAt)) + } + if s.Unrecovered > 0 { + fmt.Fprintf(w, " Unrecovered %d event ids\n", s.Unrecovered) + } + + fmt.Fprintf(w, "\n Queues ") + for _, state := range []string{"seen", "admitted", "queued", "blocked", "dispatched", "held"} { + fmt.Fprintf(w, " %s %d", state, s.Queues[state]) + } + fmt.Fprintln(w) + for reason, n := range s.Blocked { + fmt.Fprintf(w, " Blocked %s: %d\n", clean(reason), n) + } + if s.Review > 0 || s.AuthorizedBlocked > 0 || s.RedispatchPending > 0 { + fmt.Fprintf(w, " Review %d tagged, %d authorized and blocked, %d redispatches waiting for their task\n", s.Review, s.AuthorizedBlocked, s.RedispatchPending) + } + + fmt.Fprintf(w, "\n Live tasks %d\n", len(s.Tasks)) + for _, t := range s.Tasks { + fmt.Fprintf(w, " task %d %s %s pid %d (%s) token taker pid %d (%s) since %s events %v in %s\n", + t.TaskID, clean(t.AttemptID), clean(t.State), t.PID, clean(t.Worker), t.TakerPID, clean(t.Taker), stamp(t.LaunchedAt), t.EventIDs, clean(t.WorkDir)) + } + if !s.WorktreesKnown { + fmt.Fprintf(w, " Worktrees unavailable until the worktree driver lands: this build cannot say whether any are retained\n") + } else { + fmt.Fprintf(w, " Worktrees %d retained\n", len(s.Worktrees)) + for _, wt := range s.Worktrees { + fmt.Fprintf(w, " %s %s\n", clean(wt.Path), clean(wt.Reason)) + } + } + fmt.Fprintf(w, " Indeterminate %d lifecycle messages wait for a person\n", len(s.Indeterminate)) + for _, in := range s.Indeterminate { + fmt.Fprintf(w, " intent %d %s event %d %s on %d\n", in.ID, clean(in.Kind), in.EventID, clean(in.MessageKind), in.RecordingID) + } + fmt.Fprintf(w, " Held records %d (redispatch or discard each)\n", len(s.Held)) + for _, h := range s.Held { + fmt.Fprintf(w, " event %d %s %s %s\n", h.EventID, clean(h.EventType), clean(h.Trigger), clean(h.RecordingURL)) + } + + fmt.Fprintf(w, "\n Last dispatches\n") + if len(s.Dispatches) == 0 { + fmt.Fprintf(w, " none\n") + } + for _, d := range s.Dispatches { + outcomes := make([]string, 0, len(d.Events)) + for _, e := range d.Events { + o := e.Outcome + if o == "" { + o = e.Delivery + } + if e.Withdrawn { + o = "withdrawn" + } + outcomes = append(outcomes, fmt.Sprintf("%d:%s", e.EventID, clean(o))) + } + fmt.Fprintf(w, " %s task %d %s %s %s\n", stamp(d.LaunchedAt), d.TaskID, clean(d.State), clean(d.StopReason), strings.Join(outcomes, " ")) + } + fmt.Fprintln(w) +} + +func (r connectStatusReport) name() string { return r.Profile } + +// --- redispatch ----------------------------------------------------------- + +func newConnectRedispatchCmd() *cobra.Command { + return &cobra.Command{ + Use: "redispatch <event_id>", + Short: "Authorize a record to run again, or for the first time", + Long: `Authorize a record the connector will not run on its own. + +Accepted for a completed record whose outcome is unknown or failed, every +blocked record, and a held one. Refused for a success, a discarded record, and +anything live. The replaced task's token is retired, its worker is stopped, +and who authorized it is recorded. + +A completed or held record is admitted at once (a completed one whose task is +still running, when that task ends). A blocked record keeps its state and +runs what blocked it again — the read, the events lookup, the route check — +and is admitted the moment that succeeds; if it blocks again, the record stays +blocked with the authorization, and redispatch runs it again. While the hold +stands the record is authorized and nothing launches until release. + +It works on the ledger's transactions, so it is safe while the connector runs; +the running connector dispatches what it admits.`, + Example: ` basecamp connect redispatch -P agent 9876543210`, + Args: cobra.ExactArgs(1), + RunE: func(cmd *cobra.Command, args []string) error { + return runConnectRedispatch(cmd, args[0]) + }, + } +} + +// connectRedispatchReport is redispatch's output. +type connectRedispatchReport struct { + connector.RedispatchResult + // WorkerSignaled says a signal was sent to the replaced worker's recorded + // process group; WorkerState says whether it is gone. + WorkerSignaled bool `json:"worker_signaled,omitempty"` + // WorkerState is what became of it: stopped, gone, held (its group still + // runs and was not proven this task's to signal), unverified, or + // not_recorded (the attempt had no worker process recorded yet). + WorkerState string `json:"worker_state,omitempty"` + WorkerNote string `json:"worker_note,omitempty"` + // Verdict is what running the prerequisite again decided. + Verdict string `json:"verdict,omitempty"` + VerdictNote string `json:"verdict_reason,omitempty"` + RerunSkipped string `json:"rerun_skipped,omitempty"` +} + +func runConnectRedispatch(cmd *cobra.Command, raw string) error { + ctx := cmd.Context() + id, err := parseEventIDArg(raw) + if err != nil { + return err + } + // Before the ledger is opened, let alone written: a redispatch may run the + // record's prerequisite as the agent, and a token in the environment would + // decide that as somebody else. + if os.Getenv("BASECAMP_TOKEN") != "" { + return errEnvTokenShadows("a redispatch runs a record's prerequisite as the agent its profile holds, and BASECAMP_TOKEN would override it") + } + p, err := loadConnectProfile(cmd) + if err != nil { + return err + } + ledger, done, err := openConnectLedger(cmd.Context(), p, false) + if err != nil { + return err + } + defer done() + + res, err := ledger.Redispatch(ctx, id, operatorName()) + if err != nil { + return decisionError(err) + } + report := connectRedispatchReport{RedispatchResult: res} + if res.Worker != nil { + stop := stopReplacedWorker(driver.Process{ + PID: res.Worker.PID, PGID: res.Worker.PGID, StartedAt: res.Worker.StartedAt, + }, driver.DefaultGrace) + report.WorkerSignaled, report.WorkerState, report.WorkerNote = stop.signaled, stop.state, stop.note + } + if res.Rerun { + verdict, reason, err := rerunPrerequisite(ctx, p, ledger, id) + if err != nil { + report.RerunSkipped = errorMessage(err) + } else { + report.Verdict, report.VerdictNote = verdict, reason + } + } + return p.app.OK(report, output.WithSummary(redispatchSummary(report))) +} + +func redispatchSummary(r connectRedispatchReport) string { + var s string + switch { + case r.Pending && r.SupersededTaskID > 0: + s = fmt.Sprintf("Event %d authorized; admitted when its task %d ends", r.EventID, r.SupersededTaskID) + case r.Pending: + s = fmt.Sprintf("Event %d authorized; admitted when the task it is on ends", r.EventID) + case r.Admitted: + s = fmt.Sprintf("Event %d admitted", r.EventID) + case r.Verdict != "": + s = fmt.Sprintf("Event %d authorized; its prerequisite ran again: %s", r.EventID, r.Verdict) + if r.VerdictNote != "" { + s += " (" + r.VerdictNote + ")" + } + case r.RerunSkipped != "": + s = fmt.Sprintf("Event %d authorized; its prerequisite did not run here (%s). Read basecamp connect status before redispatching it again: something else may have decided it", r.EventID, r.RerunSkipped) + default: + s = fmt.Sprintf("Event %d authorized", r.EventID) + } + if r.Held { + s += "; the hold stands, so nothing launches until release" + } + return s +} + +// rerunPrerequisite decides a blocked record again, as the agent, exactly as +// the connector's admission would: the verdict is revision-guarded, so a +// running connector deciding it at the same time is not a second verdict. +func rerunPrerequisite(ctx context.Context, p connectProfile, ledger *connector.Ledger, id int64) (string, string, error) { + agent, err := verifiedConnectAgent(ctx, p) + if err != nil { + return "", "", err + } + policy, err := p.file.Policy(agent.personID) + if err != nil { + return "", "", err + } + reads := admission.NewSDKReads(&basecamp.Config{BaseURL: p.app.Config.BaseURL}, agent.tokens, agent.account, connectSDKOptions()...) + admitter, err := admission.NewAdmitter(policy, reads) + if err != nil { + return "", "", err + } + records := ledger.Admission() + ev, ok, err := records.LoadUndecided(ctx, id) + if err != nil { + return "", "", err + } + if !ok { + return "", "", errors.New("the record is no longer blocked; something else decided it") + } + v, err := admitter.Decide(ctx, ev) + if err != nil { + return "", "", err + } + v, err = admission.NewCommitter(records).Commit(ctx, v) + if errors.Is(err, admission.ErrAlreadyDecided) { + return "", "", errors.New("the running connector decided it first") + } + if err != nil { + return "", "", err + } + return string(v.State), string(v.Reason), nil +} + +// connectAgent is the agent a profile's credential proved to be, checked +// against connect.json. +type connectAgent struct { + account string + personID int64 + tokens basecamp.TokenProvider + client *basecamp.Client + reader setup.SDKReader + kind string +} + +func verifiedConnectAgent(ctx context.Context, p connectProfile) (connectAgent, error) { + app := p.app + if os.Getenv("BASECAMP_TOKEN") != "" { + return connectAgent{}, errEnvTokenShadows("the connector acts only as the agent its profile holds, and BASECAMP_TOKEN would override it") + } + account, err := connectAccount(app, p.name) + if err != nil { + return connectAgent{}, err + } + if !accountIDsEqual(account, p.file.AccountID) { + return connectAgent{}, output.ErrUsage(fmt.Sprintf("connect.json was set up in account %s, and profile %q is bound to account %s", p.file.AccountID, p.name, account)) + } + kind, err := connectCredentialKind(ctx, app) + if err != nil { + return connectAgent{}, err + } + if kind == "" { + return connectAgent{}, output.ErrAuth(fmt.Sprintf("Profile %q holds no credential", p.name)) + } + creds, err := app.Auth.GetStore().LoadContext(ctx, app.Auth.CredentialKey()) + if err != nil { + return connectAgent{}, output.ErrAuth("The stored credential could not be read: " + setup.ErrorText(err)) + } + tokens := &managerTokens{mgr: app.Auth} + client := connectSDKClient(app, tokens) + reader := setup.SDKReader{Client: client.ForAccount(account)} + me, err := reader.Me(ctx) + if err != nil { + return connectAgent{}, output.ErrAuth(fmt.Sprintf("Could not read who profile %q is: %s", p.name, setup.ErrorText(err))) + } + if _, err := checkConnectIdentity(ctx, app, client, kind, creds.OAuthType, me, p.file.Agent.IdentityID); err != nil { + return connectAgent{}, err + } + if err := p.file.VerifyAgent(kind, me.ID, p.file.Agent.IdentityID); err != nil { + return connectAgent{}, output.ErrAuth(err.Error()) + } + return connectAgent{account: account, personID: me.ID, tokens: tokens, client: client, reader: reader, kind: kind}, nil +} + +// --- discard -------------------------------------------------------------- + +func newConnectDiscardCmd() *cobra.Command { + return &cobra.Command{ + Use: "discard <event_id>", + Short: "Close a held, blocked or unknown record without running it", + Long: `Close a record without running it, as discarded(by_operator), and record who +decided. Accepted for a held record, a blocked one, and a completed one whose +outcome is unknown. A lifecycle message still pending for it is not sent.`, + Example: ` basecamp connect discard -P agent 9876543210`, + Args: cobra.ExactArgs(1), + RunE: func(cmd *cobra.Command, args []string) error { + id, err := parseEventIDArg(args[0]) + if err != nil { + return err + } + p, err := loadConnectProfile(cmd) + if err != nil { + return err + } + ledger, done, err := openConnectLedger(cmd.Context(), p, false) + if err != nil { + return err + } + defer done() + res, err := ledger.Discard(cmd.Context(), id, operatorName()) + if err != nil { + return decisionError(err) + } + summary := fmt.Sprintf("Event %d discarded", id) + if res.Already { + summary = fmt.Sprintf("Event %d was already discarded by a person", id) + } + return p.app.OK(res, output.WithSummary(summary)) + }, + } +} + +// --- release -------------------------------------------------------------- + +func newConnectReleaseCmd() *cobra.Command { + return &cobra.Command{ + Use: "release", + Short: "Clear the hold: dispatch and posting resume", + Long: `Clear the durable hold that basecamp connect --hold or shadow promote set. +Records a person authorized, and records that arrived after the hold, dispatch; +held records stay held until each is redispatched or discarded.`, + Example: ` basecamp connect release -P agent`, + Args: cobra.NoArgs, + RunE: func(cmd *cobra.Command, _ []string) error { + p, err := loadConnectProfile(cmd) + if err != nil { + return err + } + ledger, done, err := openConnectLedger(cmd.Context(), p, false) + if err != nil { + return err + } + defer done() + res, err := ledger.Release(cmd.Context(), operatorName()) + if err != nil { + return err + } + summary := "No hold stood" + if res.Released { + summary = fmt.Sprintf("Released; %d held records stay held", res.StillHeld) + } + return p.app.OK(res, output.WithSummary(summary)) + }, + } +} + +// --- shadow promote ------------------------------------------------------- + +func newConnectShadowCmd() *cobra.Command { + cmd := &cobra.Command{ + Use: "shadow", + Short: "Work with a shadow run's state", + } + cmd.AddCommand(&cobra.Command{ + Use: "promote", + Short: "Make the shadow ledger the connector's, held", + Long: `Turn the shadow run's ledger into the connector's under the hold. + +Both the shadow connector and the connector must be stopped: promote takes +both instance locks. In one transaction it sets the hold and tags every +non-terminal shadow record for review, then moves the ledger into the +connector's state directory. A crash at any point leaves either the untouched +shadow or a held ledger; run promote again to finish. + +Start the connector afterwards: intake continues from the promoted position, +nothing dispatches until basecamp connect release, and held records wait for +redispatch or discard.`, + Example: ` basecamp connect shadow promote -P agent`, + Args: cobra.NoArgs, + RunE: func(cmd *cobra.Command, _ []string) error { + p, err := loadConnectProfile(cmd) + if err != nil { + return err + } + shadowDir, err := connectStatePath(p.file, true) + if err != nil { + return err + } + stateHome, err := connectStateHome() + if err != nil { + return err + } + parent, err := ensurePrivateChain(stateHome, "basecamp", "connect") + if err != nil { + return output.ErrUsage("The connector's state directory cannot be used: " + err.Error()) + } + res, err := connector.PromoteShadow(cmd.Context(), connector.PromoteOptions{ + ShadowDir: shadowDir, + StateDir: filepath.Join(parent, connector.StateDirName(p.file.AccountID, p.file.Agent.PersonID)), + AccountID: p.file.AccountID, + AgentID: p.file.Agent.PersonID, + By: operatorName(), + }) + switch { + case errors.Is(err, connector.ErrAlreadyRunning): + return &output.Error{Code: output.CodeLockUnavailable, Message: err.Error(), + Hint: "Stop the shadow connector and the connector first; promote never stops a process itself."} + case errors.Is(err, connector.ErrNoShadowLedger), errors.Is(err, connector.ErrLedgerExists): + return output.ErrUsage(strings.TrimPrefix(err.Error(), "connector: ")) + case err != nil: + return err + } + summary := fmt.Sprintf("Promoted under the hold: %d records tagged for review, %d held", res.Tagged, res.Held) + if res.Already { + summary = "Already promoted; the ledger is held" + } + return p.app.OK(res, output.WithSummary(summary)) + }, + }) + return cmd +} + +// --- import --------------------------------------------------------------- + +// maxReconciliationBytes bounds a reconciliation file. +const maxReconciliationBytes = 16 << 20 + +func newConnectImportCmd() *cobra.Command { + return &cobra.Command{ + Use: "import <file>", + Short: "Apply a cutover reconciliation file to the ledger", + Long: `Apply a reconciliation file in one transaction: a tombstone for every entry +decided done, and the review tag on every other non-terminal record, each +keeping its state and blocking reason. A file with an entry that cannot be +applied changes nothing. The connector must be stopped. + +The file is JSON: + {"version": 1, "entries": [{"event_id": 123, "decision": "done"}, + {"event_id": 456, "decision": "held"}]}`, + Example: ` basecamp connect import -P agent reconciliation.json`, + Args: cobra.ExactArgs(1), + RunE: func(cmd *cobra.Command, args []string) error { + p, err := loadConnectProfile(cmd) + if err != nil { + return err + } + data, err := readReconciliation(args[0]) + if err != nil { + return err + } + r, err := connector.ParseReconciliation(data) + if err != nil { + return output.ErrUsage(strings.TrimPrefix(err.Error(), "connector: ")) + } + dir, err := connectStatePath(p.file, false) + if err != nil { + return err + } + if _, err := os.Lstat(filepath.Join(dir, connector.LedgerFile)); errors.Is(err, os.ErrNotExist) { + return output.ErrUsageHint(fmt.Sprintf("Profile %q's connector has no ledger yet", p.name), "Promote the shadow first: basecamp connect shadow promote -P "+shellQuote(p.name)) + } + // The connector must be stopped: the open takes the instance lock + // and holds it for the import. + ledger, done, err := openConnectLedger(cmd.Context(), p, true) + if err != nil { + return err + } + defer done() + res, err := ledger.Import(cmd.Context(), r, operatorName()) + if err != nil { + return decisionError(err) + } + return p.app.OK(res, output.WithSummary(fmt.Sprintf("Imported %d entries: %d tombstoned, %d tombstones added, %d records tagged for review", + len(r.Entries), res.Tombstoned, res.Inserted, res.Tagged))) + }, + } +} + +func readReconciliation(path string) ([]byte, error) { + f, err := os.Open(path) + if err != nil { + return nil, output.ErrUsage(fmt.Sprintf("Cannot read %s: %v", richtext.SanitizeSingleLine(path), err)) + } + defer f.Close() + data, err := io.ReadAll(io.LimitReader(f, maxReconciliationBytes+1)) + if err != nil { + return nil, err + } + if len(data) > maxReconciliationBytes { + return nil, output.ErrUsage("The reconciliation file is larger than 16 MB") + } + return data, nil +} diff --git a/internal/commands/connect_operator_test.go b/internal/commands/connect_operator_test.go new file mode 100644 index 000000000..81dcb4198 --- /dev/null +++ b/internal/commands/connect_operator_test.go @@ -0,0 +1,459 @@ +//go:build unix + +package commands + +import ( + "bytes" + "context" + "database/sql" + "encoding/json" + "errors" + "flag" + "os" + "os/exec" + "path/filepath" + "strconv" + "strings" + "testing" + "time" + + "github.com/modelcontextprotocol/go-sdk/mcp" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + + _ "modernc.org/sqlite" + + "github.com/basecamp/basecamp-sdk/go/pkg/basecamp/eventfeed" + + "github.com/basecamp/basecamp-cli/internal/appctx" + "github.com/basecamp/basecamp-cli/internal/connector" + "github.com/basecamp/basecamp-cli/internal/connector/admission" + "github.com/basecamp/basecamp-cli/internal/connector/setup" + "github.com/basecamp/basecamp-cli/internal/output" +) + +const operatorSecretContent = "please-look-secret-instruction" + +// operatorFixture is a set-up "agent" profile with its state under a temp +// XDG_STATE_HOME. +type operatorFixture struct { + s *connectSetupServer + file setup.File +} + +func newOperatorFixture(t *testing.T) operatorFixture { + t.Helper() + s := startConnectSetupServer(t) + firstSetup(t, s) + state := t.TempDir() + require.NoError(t, os.Chmod(state, 0o700)) + t.Setenv("XDG_STATE_HOME", state) + file, err := setup.Load(connectSetupPath(t, "agent")) + require.NoError(t, err) + return operatorFixture{s: s, file: file} +} + +// ledger creates the connector's (or the shadow's) ledger with an admitted +// record 1 and a blocked record 2, and returns it open. +func (f operatorFixture) ledger(t *testing.T, shadow bool) *connector.Ledger { + t.Helper() + dir, err := connectStateDir(f.file, shadow) + require.NoError(t, err) + l, err := connector.OpenLedger(filepath.Join(dir, connector.LedgerFile)) + require.NoError(t, err) + ctx := context.Background() + for _, id := range []int64{1, 2} { + _, err := l.RecordSeen(ctx, eventfeed.Event{ID: id, Kind: "comment_created", EventType: "comment.created", Action: "created", + CreatedAt: time.Now(), BucketID: setupProject, CreatorID: setupOperatorPerson, RecordingID: 77}, connector.LanePoll) + require.NoError(t, err) + } + _, err = l.Admission().Commit(ctx, admission.Verdict{ + EventID: 1, EventType: "comment.created", BucketID: setupProject, RecordingID: 77, RequesterID: setupOperatorPerson, + State: admission.StateAdmitted, Trigger: admission.TriggerMentioned, Acknowledge: true, ConversationKey: "recording:70", + Reply: &admission.ReplyDestination{Kind: admission.ReplyComment, RecordingID: 70}, Routed: true, Route: "/work/app", + RecordingURL: "https://app.basecamp.com/999/buckets/1/recordings/77", + Snapshot: &admission.Snapshot{Type: "Comment", Content: operatorSecretContent, UpdatedAt: time.Now()}, + }) + require.NoError(t, err) + _, err = l.Admission().Commit(ctx, admission.Verdict{ + EventID: 2, EventType: "comment.created", BucketID: setupProject, RecordingID: 77, RequesterID: setupOperatorPerson, + State: admission.StateBlocked, Reason: admission.ReasonUnroutable, + }) + require.NoError(t, err) + return l +} + +func (f operatorFixture) run(t *testing.T, format output.Format, args ...string) (string, error) { + t.Helper() + app := newConnectSetupApp(t, f.s, "agent") + var buf bytes.Buffer + app.Output = output.New(output.Options{Format: format, Writer: &buf}) + cmd := NewConnectCmd() + cmd.SetArgs(args) + cmd.SetContext(appctx.WithApp(context.Background(), app)) + cmd.SetOut(&buf) + cmd.SetErr(&buf) + cmd.SilenceErrors, cmd.SilenceUsage = true, true + err := cmd.Execute() + return buf.String(), err +} + +func usageError(t *testing.T, err error) *output.Error { + t.Helper() + var e *output.Error + require.True(t, errors.As(err, &e), "an output error, got %v", err) + return e +} + +func TestConnectStatusReadsWithoutWritingAndShowsNoContent(t *testing.T) { + f := newOperatorFixture(t) + + _, err := f.run(t, output.FormatJSON, "status") + require.Error(t, err) + assert.Equal(t, output.CodeUsage, usageError(t, err).Code) + state, _ := connectStateHome() + _, statErr := os.Lstat(filepath.Join(state, "basecamp")) + assert.ErrorIs(t, statErr, os.ErrNotExist, "status on no ledger creates nothing") + + l := f.ledger(t, false) + _, err = l.SetHold(context.Background(), "local:tester", connector.HoldByOperator) + require.NoError(t, err) + require.NoError(t, l.Close()) + + out, err := f.run(t, output.FormatJSON, "status") + require.NoError(t, err, out) + assert.NotContains(t, out, operatorSecretContent) + var envelope struct { + Data connectStatusReport `json:"data"` + } + require.NoError(t, json.Unmarshal([]byte(out), &envelope), out) + require.NotNil(t, envelope.Data.Status.Hold) + require.Len(t, envelope.Data.Status.Held, 1) + assert.Equal(t, int64(1), envelope.Data.Status.Held[0].EventID) + + styled, err := f.run(t, output.FormatStyled, "status") + require.NoError(t, err) + assert.Contains(t, styled, "Held records 1") + assert.NotContains(t, styled, operatorSecretContent) +} + +func TestConnectRedispatchDiscardAndRelease(t *testing.T) { + f := newOperatorFixture(t) + l := f.ledger(t, false) + ctx := context.Background() + _, err := l.SetHold(ctx, "local:tester", connector.HoldByOperator) + require.NoError(t, err) + require.NoError(t, l.Close()) + + out, err := f.run(t, output.FormatJSON, "redispatch", "1") + require.NoError(t, err, out) + assert.Contains(t, out, "admitted") + assert.Contains(t, out, "nothing launches until release") + + out, err = f.run(t, output.FormatJSON, "redispatch", "1") + require.Error(t, err, out) + assert.Equal(t, output.CodeUsage, usageError(t, err).Code, "an admitted record is live") + + out, err = f.run(t, output.FormatJSON, "discard", "2") + require.NoError(t, err, out) + out, err = f.run(t, output.FormatJSON, "redispatch", "2") + require.Error(t, err, out) + + _, err = f.run(t, output.FormatJSON, "redispatch", "nope") + require.Error(t, err) + + out, err = f.run(t, output.FormatJSON, "release") + require.NoError(t, err, out) + assert.Contains(t, out, "Released") + + dir, err := connectStatePath(f.file, false) + require.NoError(t, err) + l, err = connector.OpenLedgerReadOnly(context.Background(), filepath.Join(dir, connector.LedgerFile)) + require.NoError(t, err) + defer func() { _ = l.Close() }() + held, err := l.Held(ctx) + require.NoError(t, err) + assert.False(t, held) + one, _, err := l.Get(ctx, 1) + require.NoError(t, err) + assert.Equal(t, connector.StateAdmitted, one.State) + two, _, err := l.Get(ctx, 2) + require.NoError(t, err) + assert.Equal(t, connector.StateDiscarded, two.State) + assert.Equal(t, connector.ReasonByOperator, two.Reason) +} + +func TestConnectShadowPromoteAndImport(t *testing.T) { + f := newOperatorFixture(t) + require.NoError(t, f.ledger(t, true).Close()) + + out, err := f.run(t, output.FormatJSON, "import", filepath.Join(t.TempDir(), "missing.json")) + require.Error(t, err, out) + + out, err = f.run(t, output.FormatJSON, "shadow", "promote") + require.NoError(t, err, out) + assert.Contains(t, out, "Promoted under the hold") + out, err = f.run(t, output.FormatJSON, "shadow", "promote") + require.NoError(t, err, out) + assert.Contains(t, out, "Already promoted") + + bad := filepath.Join(t.TempDir(), "bad.json") + require.NoError(t, os.WriteFile(bad, []byte(`{"version":1,"entries":[{"event_id":2,"decision":"maybe"}]}`), 0o600)) + _, err = f.run(t, output.FormatJSON, "import", bad) + require.Error(t, err) + assert.Equal(t, output.CodeUsage, usageError(t, err).Code) + + dir, err := connectStatePath(f.file, false) + require.NoError(t, err) + lock, err := connector.AcquireInstanceLock(dir, f.file.AccountID, f.file.Agent.PersonID, time.Now()) + require.NoError(t, err) + good := filepath.Join(t.TempDir(), "good.json") + require.NoError(t, os.WriteFile(good, []byte(`{"version":1,"entries":[{"event_id":2,"decision":"done"}]}`), 0o600)) + _, err = f.run(t, output.FormatJSON, "import", good) + require.Error(t, err, "a running connector refuses the import") + assert.Equal(t, output.CodeLockUnavailable, usageError(t, err).Code) + require.NoError(t, lock.Release()) + + out, err = f.run(t, output.FormatJSON, "import", good) + require.NoError(t, err, out) + l, err := connector.OpenLedgerReadOnly(context.Background(), filepath.Join(dir, connector.LedgerFile)) + require.NoError(t, err) + defer func() { _ = l.Close() }() + two, _, err := l.Get(context.Background(), 2) + require.NoError(t, err) + assert.Equal(t, connector.StateDiscarded, two.State) + one, _, err := l.Get(context.Background(), 1) + require.NoError(t, err) + assert.Equal(t, connector.StateHeld, one.State) +} + +func TestConnectHoldFlagIsOnTheRunCommand(t *testing.T) { + cmd := NewConnectCmd() + require.NoError(t, cmd.Flags().Parse([]string{"--hold"})) + v, err := cmd.Flags().GetBool("hold") + require.NoError(t, err) + assert.True(t, v) +} + +func TestConnectDoctorWorkerBinaries(t *testing.T) { + file := setup.New("agent") + assert.Equal(t, []string{"claude"}, workerBinaries(file)) + assert.Empty(t, driverChecks(connectProfile{name: "agent", file: file})) + file.Driver = setup.DriverACP + assert.Equal(t, []string{"claude-agent-acp"}, workerBinaries(file)) + checks := driverChecks(connectProfile{name: "agent", file: file}) + require.Len(t, checks, 1) + assert.Equal(t, setup.StatusFail, checks[0].Status, "a driver the run command refuses is not ready") + + // Worktrees are the run command's other refusal. + worktrees := setup.New("agent") + worktrees.Worktrees = true + checks = driverChecks(connectProfile{name: "agent", file: worktrees}) + require.Len(t, checks, 1) + assert.Equal(t, "Worktrees", checks[0].Name) + assert.Equal(t, setup.StatusFail, checks[0].Status, "what the connector refuses to start with is not ready") +} + +func TestConnectDoctorReportsLedgerGapsAndTheHold(t *testing.T) { + f := newOperatorFixture(t) + l := f.ledger(t, false) + epoch := int64(500) + _, err := l.RecordGap(context.Background(), connector.Gap{DetectedAt: time.Now(), Class: connector.GapEpoch, EpochAfterID: &epoch, EntryClass: connector.EntryPresent}) + require.NoError(t, err) + _, err = l.SetHold(context.Background(), "local:tester", connector.HoldByOperator) + require.NoError(t, err) + require.NoError(t, l.Close()) + + checks := ledgerChecks(context.Background(), connectProfile{name: "agent", file: f.file}) + byName := map[string]setup.Check{} + for _, c := range checks { + byName[c.Name] = c + } + assert.Equal(t, setup.StatusPass, byName["Ledger"].Status) + assert.Contains(t, byName["Gap 1"].Message, "500") + assert.Equal(t, setup.StatusWarn, byName["Hold"].Status) +} + +// fakeMCPServerArg marks a test binary run as the doctor's MCP server. +const fakeMCPServerArg = "fake-basecamp-mcp" + +// TestFakeMCPServer is not a test: doctor's handshake starts it. It lists one +// tool when its environment is the allowlist, and a second when a variable +// the allowlist excludes reached it. +func TestFakeMCPServer(t *testing.T) { + if !strings.Contains(strings.Join(flag.Args(), " "), fakeMCPServerArg) { + t.Skip("started by the doctor's handshake test") + } + for _, arg := range flag.Args() { + if pidFile, ok := strings.CutPrefix(arg, "spawn-child="); ok { + // A server that starts a descendant in its group and then hangs + // without ever answering the handshake. + child := exec.CommandContext(context.Background(), "/bin/sleep", "300") + if err := child.Start(); err != nil { + os.Exit(2) + } + _ = os.WriteFile(pidFile, []byte(strconv.Itoa(child.Process.Pid)), 0o600) + select {} + } + } + server := mcp.NewServer(&mcp.Implementation{Name: "fake", Version: "0"}, nil) + type none struct{} + handler := func(context.Context, *mcp.CallToolRequest, none) (*mcp.CallToolResult, none, error) { + return &mcp.CallToolResult{}, none{}, nil + } + mcp.AddTool(server, &mcp.Tool{Name: "ok"}, handler) + if os.Getenv("CONNECT_DOCTOR_LEAK_CHECK") != "" { + mcp.AddTool(server, &mcp.Tool{Name: "leaked"}, handler) + } + _ = server.Run(context.Background(), &mcp.StdioTransport{}) + os.Exit(0) +} + +func TestConnectDoctorMCPHandshakeRunsTheServerWithAnAllowlistedEnvironment(t *testing.T) { + t.Setenv("CONNECT_DOCTOR_LEAK_CHECK", "not-a-real-secret") + orig := mcpServerCommand + mcpServerCommand = func(string) (string, []string, error) { + return os.Args[0], []string{"-test.run=^TestFakeMCPServer$", "--", fakeMCPServerArg}, nil + } + t.Cleanup(func() { mcpServerCommand = orig }) + + c := mcpHandshakeCheck(context.Background(), "agent") + assert.Equal(t, setup.StatusPass, c.Status, c.Message) + assert.Contains(t, c.Message, "1 tools", "only the allowlisted environment reached the server") +} + +func TestOperatorCommandsDoNotMigrateUnderARunningConnector(t *testing.T) { + f := newOperatorFixture(t) + require.NoError(t, f.ledger(t, false).Close()) + dir, err := connectStatePath(f.file, false) + require.NoError(t, err) + + // A ledger an older binary wrote: its last migration is not recorded. + db, err := sql.Open("sqlite", filepath.Join(dir, connector.LedgerFile)) + require.NoError(t, err) + _, err = db.ExecContext(context.Background(), `DELETE FROM schema_migrations WHERE version = (SELECT MAX(version) FROM schema_migrations)`) + require.NoError(t, err) + require.NoError(t, db.Close()) + + lock, err := connector.AcquireInstanceLock(dir, f.file.AccountID, f.file.Agent.PersonID, time.Now()) + require.NoError(t, err) + defer func() { _ = lock.Release() }() + + _, err = f.run(t, output.FormatJSON, "release") + require.Error(t, err) + assert.Contains(t, usageError(t, err).Message, "older than this build") +} + +// The migration guard is the lock itself, not the metadata beside it: a +// connector whose lock file carries nothing still stops the migration. +func TestTheMigrationGuardIsTheLockNotItsMetadata(t *testing.T) { + f := newOperatorFixture(t) + require.NoError(t, f.ledger(t, false).Close()) + dir, err := connectStatePath(f.file, false) + require.NoError(t, err) + db, err := sql.Open("sqlite", filepath.Join(dir, connector.LedgerFile)) + require.NoError(t, err) + _, err = db.ExecContext(context.Background(), `DELETE FROM schema_migrations WHERE version = (SELECT MAX(version) FROM schema_migrations)`) + require.NoError(t, err) + require.NoError(t, db.Close()) + + lock, err := connector.AcquireInstanceLock(dir, f.file.AccountID, f.file.Agent.PersonID, time.Now()) + require.NoError(t, err) + defer func() { _ = lock.Release() }() + require.NoError(t, os.Remove(lock.Path()+".json"), "the holder's metadata is best-effort and may be missing") + + _, err = f.run(t, output.FormatJSON, "release") + require.Error(t, err) + assert.Contains(t, usageError(t, err).Message, "older than this build") +} + +// Import takes the instance lock itself, so it does not refuse its own hold on +// a ledger older than this build — the cutover's whole reason to run. +func TestImportRunsOnALedgerOlderThanTheBuild(t *testing.T) { + f := newOperatorFixture(t) + require.NoError(t, f.ledger(t, false).Close()) + dir, err := connectStatePath(f.file, false) + require.NoError(t, err) + db, err := sql.Open("sqlite", filepath.Join(dir, connector.LedgerFile)) + require.NoError(t, err) + _, err = db.ExecContext(context.Background(), `DELETE FROM schema_migrations WHERE version = (SELECT MAX(version) FROM schema_migrations)`) + require.NoError(t, err) + require.NoError(t, db.Close()) + + file := filepath.Join(t.TempDir(), "reconciliation.json") + require.NoError(t, os.WriteFile(file, []byte(`{"version":1,"entries":[{"event_id":2,"decision":"done"}]}`), 0o600)) + // The fabricated ledger cannot actually migrate (its tables are already + // there), so the migration's own error is the end of this run. What + // matters is what it is not: import must never refuse itself over the + // lock it holds. + _, err = f.run(t, output.FormatJSON, "import", file) + require.Error(t, err) + assert.NotContains(t, err.Error(), "already holds this account") + assert.NotContains(t, err.Error(), "Stop the connector") +} + +func TestConnectStatusOnAMissingShadowLedgerPointsAtTheShadowRun(t *testing.T) { + f := newOperatorFixture(t) + _, err := f.run(t, output.FormatJSON, "status", "--shadow") + require.Error(t, err) + assert.Contains(t, usageError(t, err).Hint, "--shadow") +} + +// A token in the environment would decide a record's prerequisite as somebody +// other than the agent, so redispatch and doctor refuse before the ledger is +// touched. +func TestRedispatchAndDoctorRefuseAShadowingToken(t *testing.T) { + f := newOperatorFixture(t) + l := f.ledger(t, false) + require.NoError(t, l.Close()) + t.Setenv("BASECAMP_TOKEN", "not-a-real-token") + + for _, args := range [][]string{{"redispatch", "2"}, {"doctor"}} { + _, err := f.run(t, output.FormatJSON, args...) + require.Error(t, err, args[0]) + assert.Contains(t, err.Error(), "BASECAMP_TOKEN", args[0]) + } + dir, err := connectStatePath(f.file, false) + require.NoError(t, err) + db, err := sql.Open("sqlite", filepath.Join(dir, connector.LedgerFile)) + require.NoError(t, err) + defer func() { _ = db.Close() }() + var decisions int + require.NoError(t, db.QueryRowContext(context.Background(), `SELECT COUNT(*) FROM decisions`).Scan(&decisions)) + assert.Zero(t, decisions, "nothing was decided") +} + +// The decision commands' JSON is the CLI's snake_case, as status's is. +func TestTheDecisionCommandsSpeakSnakeCase(t *testing.T) { + f := newOperatorFixture(t) + l := f.ledger(t, false) + _, err := l.SetHold(context.Background(), "local:tester", connector.HoldByOperator) + require.NoError(t, err) + require.NoError(t, l.Close()) + + out, err := f.run(t, output.FormatJSON, "redispatch", "1") + require.NoError(t, err, out) + assert.Contains(t, out, `"event_id"`) + assert.NotContains(t, out, `"EventID"`) + + out, err = f.run(t, output.FormatJSON, "release") + require.NoError(t, err, out) + assert.Contains(t, out, `"still_held"`) + assert.NotContains(t, out, `"StillHeld"`) +} + +// Until the worktree driver lands, status says the retained worktrees are +// unavailable — never that there are none. +func TestStatusSaysWorktreesAreUnavailableNotNone(t *testing.T) { + f := newOperatorFixture(t) + require.NoError(t, f.ledger(t, false).Close()) + + styled, err := f.run(t, output.FormatStyled, "status") + require.NoError(t, err, styled) + assert.Contains(t, styled, "Worktrees unavailable") + assert.NotContains(t, styled, "0 retained") + + out, err := f.run(t, output.FormatJSON, "status") + require.NoError(t, err, out) + assert.Contains(t, out, `"worktrees_known": false`) +} diff --git a/internal/commands/connect_process_other.go b/internal/commands/connect_process_other.go new file mode 100644 index 000000000..e841797c9 --- /dev/null +++ b/internal/commands/connect_process_other.go @@ -0,0 +1,14 @@ +//go:build !unix + +package commands + +// Process presence, as much as a reader can say without taking a lock. +const ( + pidPresent = "present" + pidAbsent = "absent" + pidUnknown = "unknown" +) + +// processPresence cannot be answered here — the connector runs on macOS and +// Linux — so it says so rather than calling a pid absent. +func processPresence(int) string { return pidUnknown } diff --git a/internal/commands/connect_process_unix.go b/internal/commands/connect_process_unix.go new file mode 100644 index 000000000..3078e3879 --- /dev/null +++ b/internal/commands/connect_process_unix.go @@ -0,0 +1,32 @@ +//go:build unix + +package commands + +import ( + "errors" + "syscall" +) + +// Process presence, as much as a reader can say without taking a lock. +const ( + pidPresent = "present" + pidAbsent = "absent" + pidUnknown = "unknown" +) + +// processPresence reports whether a process with pid exists. It signals +// nothing: signal 0 only asks. A pid that exists is not proof it is the same +// process that wrote the pid down. +func processPresence(pid int) string { + if pid <= 1 { + return pidUnknown + } + switch err := syscall.Kill(pid, 0); { + case err == nil, errors.Is(err, syscall.EPERM): + return pidPresent + case errors.Is(err, syscall.ESRCH): + return pidAbsent + default: + return pidUnknown + } +} diff --git a/internal/commands/connect_run.go b/internal/commands/connect_run.go index bfd2d12c8..c76ba7a87 100644 --- a/internal/commands/connect_run.go +++ b/internal/commands/connect_run.go @@ -38,6 +38,7 @@ type connectRunFlags struct { shadow bool since int64 driver string + hold bool } func addConnectRunFlags(cmd *cobra.Command, f *connectRunFlags) { @@ -48,6 +49,7 @@ func addConnectRunFlags(cmd *cobra.Command, f *connectRunFlags) { fl.BoolVar(&f.shadow, "shadow", false, "Admit and log in an isolated state directory; dispatch and post nothing") fl.Int64Var(&f.since, "since", 0, "Enter the feed just after this event id, whatever the ledger holds") fl.StringVar(&f.driver, "driver", "", "Override connect.json's driver (spawn)") + fl.BoolVar(&f.hold, "hold", false, "Set the durable hold: intake and admission run, nothing is dispatched or posted until the hold is released, and earlier records wait for review") } // connectStateHome is the directory holding the connector's state root, from @@ -88,13 +90,28 @@ func connectStateDir(file setup.File, shadow bool) (string, error) { if err != nil { return "", err } + return ensurePrivateChain(stateHome, connectStateParts(file, shadow)...) +} + +// connectStatePath is connectStateDir's path, created nothing: for commands +// that only read the connector's state, and must not make a directory to do +// it. +func connectStatePath(file setup.File, shadow bool) (string, error) { + stateHome, err := connectStateHome() + if err != nil { + return "", err + } + return filepath.Join(append([]string{stateHome}, connectStateParts(file, shadow)...)...), nil +} + +func connectStateParts(file setup.File, shadow bool) []string { group := "connect" if shadow { // An isolated ledger, lock and checkpoint: a shadow never shares a // position or a record with the connector it watches beside. group = "connect-shadow" } - return ensurePrivateChain(stateHome, "basecamp", group, connector.StateDirName(file.AccountID, file.Agent.PersonID)) + return []string{"basecamp", group, connector.StateDirName(file.AccountID, file.Agent.PersonID)} } // connectSessionsDir is where a session's short-lived files go — the MCP @@ -237,6 +254,21 @@ func runConnect(cmd *cobra.Command, f *connectRunFlags) error { defer func() { _ = ledger.Close() }() logger := slog.New(slog.NewTextHandler(cmd.ErrOrStderr(), nil)) + if f.hold { + // Before intake starts: nothing this run admits may dispatch ahead of + // the marker. + held, err := ledger.SetHold(ctx, operatorName(), connector.HoldByOperator) + if err != nil { + return err + } + logger.Info("connector: held", "generation", held.Hold.Generation, "tagged_for_review", held.Tagged, "held", held.Held) + } + if hold, ok, err := ledger.HoldMarker(ctx); err != nil { + return err + } else if ok { + logger.Warn("connector: the hold stands; nothing is dispatched or posted until `basecamp connect release`", + "since", hold.HeldAt, "by", richtext.SanitizeSingleLine(hold.HeldBy)) + } lines := ndjson.NewWriter(cmd.OutOrStdout()) queue, err := connector.NewQueue(connector.DefaultBacklogWarn, connector.DefaultBacklogPause) @@ -282,7 +314,7 @@ func runConnect(cmd *cobra.Command, f *connectRunFlags) error { if err != nil { return err } - outbox, err = connector.NewOutbox(connector.OutboxOptions{Ledger: ledger, Poster: poster, Lines: lines, Logger: logger}) + outbox, err = connector.NewOutbox(connector.OutboxOptions{Ledger: ledger, Poster: poster, Paused: ledger.Held, Lines: lines, Logger: logger}) if err != nil { return err } @@ -343,6 +375,10 @@ func runConnect(cmd *cobra.Command, f *connectRunFlags) error { os.Exit(connector.ExitCodeForSignal(sig)) }() + defer func() { + // Whatever ended the run, status says it is not running any more. + _ = ledger.NoteConnection(context.WithoutCancel(ctx), connector.ConnectionStopped, "") + }() logger.Info("connector: running", "profile", richtext.SanitizeSingleLine(name), "account", account, "agent_person_id", agentID, "shadow", f.shadow, "projects", len(buckets), "state", richtext.SanitizeSingleLine(stateDir)) @@ -385,6 +421,9 @@ func runConnect(cmd *cobra.Command, f *connectRunFlags) error { return err } } + if err := ledger.NoteConnection(ctx, connector.ConnectionRunning, ""); err != nil { + logger.Warn("connector: could not record that it runs, for status", "error", err) + } runPart("intake", intake.Run) runPart("admission", func(ctx context.Context) error { return connector.RunAdmission(ctx, connector.AdmissionOptions{Ledger: ledger, Queue: queue, Admitter: admitter, Lines: lines, Logger: logger}) diff --git a/internal/commands/connect_worker.go b/internal/commands/connect_worker.go new file mode 100644 index 000000000..ec951fe23 --- /dev/null +++ b/internal/commands/connect_worker.go @@ -0,0 +1,113 @@ +//go:build unix + +package commands + +import ( + "errors" + "time" + + "github.com/basecamp/basecamp-cli/internal/connector" + "github.com/basecamp/basecamp-cli/internal/connector/driver" + "github.com/basecamp/basecamp-cli/internal/richtext" +) + +// The operator commands act on a recorded worker only through the driver's +// one-owner rule (driver/worker.go): a pid is not an identity, so every +// question about a recorded worker is driver.OwnsWorker's, and nothing here +// tests a pid of its own. + +// Worker states the operator commands report. +const ( + workerRunning = "running" + workerStopped = "stopped" + workerGone = "gone" + workerHeld = "held" + workerUnverified = "unverified" + workerNotRecorded = "not_recorded" +) + +// workerOps are the driver's one-owner functions stopReplacedWorker uses. A +// test seam, so the branches that must not signal can be exercised without a +// real process group whose id nothing reserves. Production only reads it; a +// test that replaces it must not run in parallel. +var workerOps = struct { + owns func(driver.Process) (bool, error) + terminate func(driver.Process, time.Duration) (bool, error) + confirm func(driver.Process, time.Duration) error +}{driver.OwnsWorker, driver.TerminateRecorded, driver.ConfirmGroupGone} + +// workerStop is what stopping a replaced worker did. +type workerStop struct { + signaled bool + state string + note string +} + +// stopReplacedWorker ends the worker a redispatch replaced, first, as the +// spec asks: only while OwnsWorker says the recorded process is still that +// worker, and then confirms its group is gone. A group that outlived its +// leader, or an identity that cannot be established, is left alone and said +// so: the task's end — which admits the redispatched record — waits for the +// owner to confirm the group gone, so nothing runs twice meanwhile. +func stopReplacedWorker(p driver.Process, grace time.Duration) workerStop { + if p.PID <= 0 || p.PGID <= 0 || p.StartedAt.IsZero() { + // A worker still launching has no recorded process yet: there is + // nothing this command can prove is it, so nothing is signaled. + return workerStop{state: workerNotRecorded, + note: "the replaced attempt had not recorded its worker process yet, so nothing was signaled; its token is retired, and the redispatch waits until that task ends"} + } + switch owns, err := workerOps.owns(p); { + case errors.Is(err, driver.ErrGroupOutlivedLeader): + return workerStop{state: workerHeld, + note: "its leader is gone but its process group still runs, so it was not signaled; its token is retired, and the redispatch waits until that group is gone"} + case err != nil: + return workerStop{state: workerUnverified, + note: "the recorded worker's identity could not be established, so nothing was signaled; its token is retired: " + richtext.SanitizeSingleLine(err.Error())} + case !owns: + return workerStop{state: workerGone, note: "the recorded worker had already gone; nothing was signaled, and its token is retired"} + } + signaled, err := workerOps.terminate(p, grace) + if err != nil { + return workerStop{state: workerUnverified, + note: "the recorded worker could not be signaled; its token is retired: " + richtext.SanitizeSingleLine(err.Error())} + } + if err := workerOps.confirm(p, grace); err != nil { + return workerStop{signaled: signaled, state: workerHeld, + note: "the worker was signaled but its process group did not go; the redispatch waits until it has"} + } + // The group is gone, but "stopped" is only said of the worker itself. + if owns, err := workerOps.owns(p); owns || err != nil { + return workerStop{signaled: signaled, state: workerUnverified, + note: "the recorded worker is still running outside its recorded process group, so it was not stopped; its token is retired, and the redispatch waits until that task ends"} + } + return workerStop{signaled: signaled, state: workerStopped} +} + +// recordedWorkerState is status's answer for a live attempt's worker. It +// signals nothing. +func recordedWorkerState(t connector.TaskStatus) string { + return recordedProcessState(t.PID, t.PGID, t.ProcessStartedAt) +} + +// recordedTakerState is the same answer for the process the task token went +// to — a worker's MCP server, which lives in a group of its own, so it can +// outlive the worker that started it and still hold the task's token. +func recordedTakerState(t connector.TaskStatus) string { + return recordedProcessState(t.TakerPID, t.TakerPGID, t.TakerStartedAt) +} + +func recordedProcessState(pid, pgid int, started *time.Time) string { + if pid <= 0 || pgid <= 0 || started == nil { + return workerNotRecorded + } + switch owns, err := driver.OwnsWorker(driver.Process{PID: pid, PGID: pgid, StartedAt: *started}); { + case errors.Is(err, driver.ErrGroupOutlivedLeader): + return workerHeld + case err != nil: + return workerUnverified + case owns: + return workerRunning + default: + return workerGone + } +} diff --git a/internal/commands/connect_worker_other.go b/internal/commands/connect_worker_other.go new file mode 100644 index 000000000..86e8c4d9a --- /dev/null +++ b/internal/commands/connect_worker_other.go @@ -0,0 +1,37 @@ +//go:build !unix + +package commands + +import ( + "time" + + "github.com/basecamp/basecamp-cli/internal/connector" + "github.com/basecamp/basecamp-cli/internal/connector/driver" +) + +// The one-owner rule is Unix's: process groups, and a start time that makes a +// pid an identity, are what it rests on. Elsewhere the connector does not run +// (the run command refuses), and nothing here can say whether a recorded +// worker is still itself — so nothing is signaled and nothing is claimed. + +const ( + workerStopped = "stopped" + workerHeld = "held" + workerUnverified = "unverified" + workerNotRecorded = "not_recorded" +) + +type workerStop struct { + signaled bool + state string + note string +} + +func stopReplacedWorker(driver.Process, time.Duration) workerStop { + return workerStop{state: workerUnverified, + note: "this platform cannot establish a recorded worker's identity, so nothing was signaled; its token is retired"} +} + +func recordedWorkerState(connector.TaskStatus) string { return workerUnverified } + +func recordedTakerState(connector.TaskStatus) string { return workerUnverified } diff --git a/internal/commands/connect_worker_unix_test.go b/internal/commands/connect_worker_unix_test.go new file mode 100644 index 000000000..d954d6c2e --- /dev/null +++ b/internal/commands/connect_worker_unix_test.go @@ -0,0 +1,154 @@ +//go:build unix + +package commands + +import ( + "context" + "os" + "path/filepath" + "strconv" + "strings" + "syscall" + "testing" + "time" + + "github.com/stretchr/testify/assert" + + "github.com/basecamp/basecamp-cli/internal/connector" + "github.com/basecamp/basecamp-cli/internal/connector/driver" + "github.com/basecamp/basecamp-cli/internal/connector/driver/drivertest" +) + +func taskOf(p driver.Process) connector.TaskStatus { + started := p.StartedAt + return connector.TaskStatus{PID: p.PID, PGID: p.PGID, ProcessStartedAt: &started} +} + +// runningTree starts a worker whose leader keeps running beside a child in +// its group, and returns it and the child's pid. +func runningTree(t *testing.T) (*driver.Worker, int) { + t.Helper() + pidFile := filepath.Join(t.TempDir(), "child") + worker, err := driver.StartWorker(context.Background(), nil, driver.Scope{WorkDir: t.TempDir()}, + driver.Command{Path: "/bin/sh", Args: []string{"-c", "sleep 300 & echo $! > " + pidFile + "; wait"}, Env: []string{"PATH=/bin:/usr/bin"}}) + if err != nil { + t.Fatalf("start a worker: %v", err) + } + t.Cleanup(func() { worker.Terminate(time.Second) }) + var child int + deadline := time.Now().Add(5 * time.Second) + for child == 0 { + if data, err := os.ReadFile(pidFile); err == nil { + child, _ = strconv.Atoi(strings.TrimSpace(string(data))) + } + if time.Now().After(deadline) { + t.Fatal("the worker's child never started") + } + time.Sleep(10 * time.Millisecond) + } + t.Cleanup(func() { _ = syscall.Kill(child, syscall.SIGKILL) }) + return worker, child +} + +// A redispatch stops the worker it replaces, its whole tree, and says so. +func TestRedispatchStopsTheReplacedWorkersTree(t *testing.T) { + worker, grandchild := runningTree(t) + p := worker.Process() + assert.Equal(t, workerRunning, recordedWorkerState(taskOf(p))) + + got := stopReplacedWorker(p, 2*time.Second) + assert.Equal(t, workerStopped, got.state, got.note) + assert.True(t, got.signaled) + assert.Eventually(t, func() bool { return !drivertest.Alive(grandchild) }, 5*time.Second, 20*time.Millisecond, "the grandchild went with its group") + assert.Equal(t, workerGone, recordedWorkerState(taskOf(p))) +} + +// A tree that outlived its leader is not proven this task's to signal: it is +// held, left running, and reported. +func TestRedispatchLeavesATreeThatOutlivedItsLeaderHeld(t *testing.T) { + p, grandchild := drivertest.SurvivingWorker(t, t.TempDir()) + assert.Equal(t, workerHeld, recordedWorkerState(taskOf(p))) + + got := stopReplacedWorker(p, time.Second) + assert.Equal(t, workerHeld, got.state) + assert.False(t, got.signaled) + assert.True(t, drivertest.Alive(grandchild), "nothing was signaled") + drivertest.RequireGroupHeld(t, p) +} + +// A recorded start time that is not the process's own is not this worker, +// whatever the pid says. +func TestAPidAloneIsNotTheWorker(t *testing.T) { + worker, grandchild := runningTree(t) + p := worker.Process() + p.StartedAt = p.StartedAt.Add(-time.Hour) + + assert.NotEqual(t, workerRunning, recordedWorkerState(taskOf(p))) + got := stopReplacedWorker(p, time.Second) + assert.False(t, got.signaled) + assert.True(t, drivertest.Alive(grandchild)) +} + +// A worker still launching has recorded no process: nothing is signaled, and +// it is not called gone. +func TestRedispatchDoesNotCallAnUnrecordedWorkerGone(t *testing.T) { + got := stopReplacedWorker(driver.Process{}, time.Second) + assert.Equal(t, workerNotRecorded, got.state) + assert.False(t, got.signaled) +} + +// A worker whose recorded group holds nothing is not called stopped while it +// still runs. Faked: a real member-less group id is not one a test can hold +// reserved, and signaling a freed id could reach someone else's group. +func TestRedispatchDoesNotCallAWorkerOutsideItsGroupStopped(t *testing.T) { + orig := workerOps + t.Cleanup(func() { workerOps = orig }) + var signaled bool + workerOps.owns = func(driver.Process) (bool, error) { return true, nil } // the leader runs on + workerOps.terminate = func(driver.Process, time.Duration) (bool, error) { signaled = true; return false, nil } + workerOps.confirm = func(driver.Process, time.Duration) error { return nil } // its group is empty + + got := stopReplacedWorker(driver.Process{PID: 4242, PGID: 4243, StartedAt: time.Now()}, time.Second) + assert.True(t, signaled) + assert.Equal(t, workerUnverified, got.state, got.note) +} + +// A handshake that never completes ends the server's whole group, a +// descendant it started included, before doctor returns. +func TestDoctorsFailedHandshakeLeavesNoDescendant(t *testing.T) { + pidFile := filepath.Join(t.TempDir(), "child") + orig, origTimeout := mcpServerCommand, mcpHandshakeTimeout + mcpServerCommand = func(string) (string, []string, error) { + return os.Args[0], []string{"-test.run=^TestFakeMCPServer$", "--", fakeMCPServerArg, "spawn-child=" + pidFile}, nil + } + mcpHandshakeTimeout = 2 * time.Second + t.Cleanup(func() { mcpServerCommand, mcpHandshakeTimeout = orig, origTimeout }) + + c := mcpHandshakeCheck(context.Background(), "agent") + assert.Equal(t, "fail", c.Status) + data, err := os.ReadFile(pidFile) + if err != nil { + t.Fatalf("the fake server never started its child: %v", err) + } + child, _ := strconv.Atoi(strings.TrimSpace(string(data))) + t.Cleanup(func() { _ = syscall.Kill(child, syscall.SIGKILL) }) + assert.Eventually(t, func() bool { return !drivertest.Alive(child) }, 3*time.Second, 20*time.Millisecond, "the descendant went with its group") +} + +// Status reports the process the task token went to as it reports the worker: +// a taker that outlived its worker is the same "one owner" story, seen from +// the operator's side. +func TestStatusReportsATakerThatOutlivedItsWorker(t *testing.T) { + worker, _ := runningTree(t) + live := worker.Process() + taker, _ := drivertest.SurvivingWorker(t, t.TempDir()) + started, takerStarted := live.StartedAt, taker.StartedAt + task := connector.TaskStatus{ + PID: live.PID, PGID: live.PGID, ProcessStartedAt: &started, + TakerPID: taker.PID, TakerPGID: taker.PGID, TakerStartedAt: &takerStarted, + } + + assert.Equal(t, workerRunning, recordedWorkerState(task)) + assert.Equal(t, workerHeld, recordedTakerState(task), "its leader is gone and its group still runs") + assert.Equal(t, workerNotRecorded, recordedTakerState(connector.TaskStatus{PID: live.PID, PGID: live.PGID, ProcessStartedAt: &started})) +} diff --git a/internal/connector/admission/commit.go b/internal/connector/admission/commit.go index 13a3cbce0..b1079a8c5 100644 --- a/internal/connector/admission/commit.go +++ b/internal/connector/admission/commit.go @@ -68,7 +68,7 @@ func (c *Committer) Commit(ctx context.Context, v Verdict) (Verdict, error) { } switch { case written == v.State: - case v.State == StateAdmitted && written == StateQueued: + case v.State == StateAdmitted && (written == StateQueued || written == StateHeld): v.State = written default: return v, fmt.Errorf("admission: ledger wrote %s for a %s verdict on event %d", written, v.State, v.EventID) diff --git a/internal/connector/admission/commit_test.go b/internal/connector/admission/commit_test.go index 919cdca0d..4b0f5d8a1 100644 --- a/internal/connector/admission/commit_test.go +++ b/internal/connector/admission/commit_test.go @@ -170,7 +170,7 @@ func TestCommitsAreSerialisedPerConversation(t *testing.T) { admitted++ case StateQueued: queued++ - case StateBlocked, StateDiscarded: + case StateBlocked, StateDiscarded, StateHeld: t.Errorf("unexpected %s commit", v.State) } } diff --git a/internal/connector/admission/matrix.go b/internal/connector/admission/matrix.go index 4869d96db..2697dad70 100644 --- a/internal/connector/admission/matrix.go +++ b/internal/connector/admission/matrix.go @@ -72,6 +72,10 @@ const ( StateQueued State = "queued" StateBlocked State = "blocked" StateDiscarded State = "discarded" + // StateHeld is never a verdict. It is what the ledger writes instead of + // admitted or queued for a record a hold tagged for review, which waits + // for a person. + StateHeld State = "held" ) // Reason explains a blocked or discarded verdict. diff --git a/internal/connector/dispatch_lifecycle_test.go b/internal/connector/dispatch_lifecycle_test.go index 5de670d71..b3e88e314 100644 --- a/internal/connector/dispatch_lifecycle_test.go +++ b/internal/connector/dispatch_lifecycle_test.go @@ -157,6 +157,10 @@ func reachRecord(t *testing.T, ledger *Ledger, state RecordState, held bool) { if state == StateCompleted { require.NoError(t, ledger.SetState(ctx, 1, StateCompleted, "")) } + case StateHeld: + // Held is written by a hold's review tag (ledger_hold.go), never by + // a transition these tests drive. + t.Fatalf("reachRecord does not build a %s record", state) } require.Equal(t, state, getRecord(t, ledger, 1).State) } diff --git a/internal/connector/dispatcher.go b/internal/connector/dispatcher.go index a9ae9d637..cb512bc81 100644 --- a/internal/connector/dispatcher.go +++ b/internal/connector/dispatcher.go @@ -1150,6 +1150,13 @@ func (r *taskRun) nextFollowUp(ctx context.Context) (int64, bool, error) { return 0, false, err } exposed, err := r.d.ledger.ExposeEvent(ctx, r.launch.AttemptID, ids[0]) + if errors.Is(err, ErrHeld) { + // A hold: nothing more is handed to this worker, and the task + // finishes rather than failing. Its unexposed events wait for a + // person (ledger_hold.go). + r.log.Info("connector: the connector is held; no more instructions are handed to this worker", "task_id", r.launch.TaskID) + return 0, false, nil + } if err != nil { return 0, false, err } diff --git a/internal/connector/ledger.go b/internal/connector/ledger.go index bfa55727f..87fea0f9c 100644 --- a/internal/connector/ledger.go +++ b/internal/connector/ledger.go @@ -49,6 +49,10 @@ const ( StateCompleted RecordState = "completed" // StateDiscarded is terminal with a verified verdict. StateDiscarded RecordState = "discarded" + // StateHeld waits for a person. A record tagged for review by a hold + // becomes held where it would have waited for a worker, and only a + // person's redispatch or discard moves it on. It keeps its snapshot. + StateHeld RecordState = "held" ) // Lane names which lane first served an event. It is diagnostic: dedupe is by @@ -832,6 +836,16 @@ END; // this to 8. The numbers move only because nothing has shipped them yet; // once a ledger has applied one, its number is fixed. migrationOutbox, + // Migration 9. The hold marker, intake generations, the review tag and + // people's decisions on records. See ledger_hold.go for the invariants + // they hold. + // + // This was migration 8 while it sat on card 20's head, behind the tasks + // and attempts at 6 and the outbox at 7. Main took 6 for the + // acknowledgement trigger, which pushed those two to 7 and 8 and this to + // 9. The numbers move only because nothing has shipped them yet; once a + // ledger has applied one, its number is fixed. + migrationOperator, } func (l *Ledger) migrate(ctx context.Context) error { @@ -841,6 +855,17 @@ func (l *Ledger) migrate(ctx context.Context) error { )`); err != nil { return fmt.Errorf("connector: create migration table: %w", err) } + // A ledger a newer basecamp wrote is refused, not opened as if it were + // current: its triggers and states (a held record, say) are rules this + // binary does not know, and running over them could break them — the + // rollback case. + var newest int + if err := l.db.QueryRowContext(ctx, `SELECT COALESCE(MAX(version), 0) FROM schema_migrations`).Scan(&newest); err != nil { + return fmt.Errorf("connector: read schema version: %w", err) + } + if newest > len(migrations) { + return fmt.Errorf("connector: ledger at schema %d, this basecamp writes %d: %w", newest, len(migrations), ErrLedgerSchema) + } for i := range migrations { version := i + 1 diff --git a/internal/connector/ledger_admission.go b/internal/connector/ledger_admission.go index 215af3231..f27d43b97 100644 --- a/internal/connector/ledger_admission.go +++ b/internal/connector/ledger_admission.go @@ -160,6 +160,16 @@ func (a Admission) commit(ctx context.Context, v admission.Verdict, state Record if !moved { return "", explainVerdictRefusal(ctx, tx, v) } + if state == StateAdmitted || state == StateQueued { + // A record a hold tagged for review is written held by the database + // instead (ledger_hold.go). The verdict reports what was written, so + // neither the hooks nor the stdout line call it admitted. + var written string + if err := tx.QueryRowContext(ctx, `SELECT state FROM events WHERE id = ?`, v.EventID).Scan(&written); err != nil { + return "", fmt.Errorf("connector: read verdict on %d back: %w", v.EventID, err) + } + state = RecordState(written) + } if l.hooks.VerdictCommitted != nil { committed := CommittedVerdict{ EventID: v.EventID, diff --git a/internal/connector/ledger_decisions.go b/internal/connector/ledger_decisions.go new file mode 100644 index 000000000..0aff8c2ed --- /dev/null +++ b/internal/connector/ledger_decisions.go @@ -0,0 +1,480 @@ +package connector + +import ( + "context" + "database/sql" + "errors" + "fmt" + "strings" + "time" +) + +// ErrDecisionRefused is a redispatch or discard the record's state does not +// accept. The message says why. +var ErrDecisionRefused = errors.New("refused") + +// eventTask is the latest task an event was on, as a decision reads it. +type eventTask struct { + found bool + taskID int64 + delivery Delivery + outcome Outcome + superseded bool + ended bool + // completedAt is when the event's outcome settled, as stored. + completedAt string + // live is the task's attempt that has not ended, if any, with its + // recorded process. + liveAttempt string + process AttemptProcess +} + +func loadEventTask(ctx context.Context, tx *sql.Tx, eventID int64) (eventTask, error) { + var ( + et eventTask + delivery, outcome string + superseded, ended sql.NullString + completed sql.NullString + attempt, startedText sql.NullString + pid, pgid sql.NullInt64 + ) + err := tx.QueryRowContext(ctx, ` +SELECT te.task_id, te.delivery, te.outcome, te.completed_at, t.superseded_at, t.ended_at, + a.id, a.pid, a.pgid, a.process_started +FROM task_events te +JOIN tasks t ON t.id = te.task_id +LEFT JOIN attempts a ON a.task_id = t.id AND a.state <> 'ended' +WHERE te.event_id = ? AND te.withdrawn_at IS NULL +ORDER BY te.task_id DESC LIMIT 1`, eventID).Scan(&et.taskID, &delivery, &outcome, &completed, &superseded, &ended, + &attempt, &pid, &pgid, &startedText) + switch { + case errors.Is(err, sql.ErrNoRows): + return eventTask{}, nil + case err != nil: + return eventTask{}, fmt.Errorf("connector: read the task of event %d: %w", eventID, err) + } + et.found = true + et.delivery, et.outcome = Delivery(delivery), Outcome(outcome) + et.superseded, et.ended, et.completedAt = superseded.Valid, ended.Valid, completed.String + if attempt.Valid { + et.liveAttempt = attempt.String + et.process = AttemptProcess{PID: int(pid.Int64), PGID: int(pgid.Int64)} + if startedText.Valid { + if et.process.StartedAt, err = parseStamp(startedText.String); err != nil { + return eventTask{}, err + } + } + } + return et, nil +} + +// operatorRecord is a record with the columns a decision reads. +type operatorRecord struct { + Record + review bool + authorizedAt sql.NullString + // redispatchDecision is the redispatch waiting for the record's task to + // end; zero when none is. + redispatchDecision int64 +} + +func loadOperatorRecord(ctx context.Context, tx *sql.Tx, eventID int64) (operatorRecord, error) { + record, err := loadRecord(ctx, tx, eventID) + if err != nil { + return operatorRecord{}, err + } + out := operatorRecord{Record: record} + var decision sql.NullInt64 + if err := tx.QueryRowContext(ctx, `SELECT review, authorized_at, redispatch_decision FROM events WHERE id = ?`, eventID). + Scan(&out.review, &out.authorizedAt, &decision); err != nil { + return operatorRecord{}, fmt.Errorf("connector: read event %d: %w", eventID, err) + } + out.redispatchDecision = decision.Int64 + return out, nil +} + +// RedispatchResult is what a redispatch did. +type RedispatchResult struct { + EventID int64 `json:"event_id"` + FromState RecordState `json:"from_state"` + FromReason string `json:"from_reason,omitempty"` + FromOutcome Outcome `json:"from_outcome,omitempty"` + // State is the record's state after the authorization. + State RecordState `json:"state"` + // Admitted says the record waits for a worker now. + Admitted bool `json:"admitted"` + // Pending says the record's task is still live: it is admitted in the + // transaction that ends that task. + Pending bool `json:"pending,omitempty"` + // Rerun says the record was authorized as blocked: the caller runs its + // prerequisite again (admission), which admits it when it succeeds. + Rerun bool `json:"rerun,omitempty"` + // SupersededTaskID is the task whose token this redispatch retired; zero + // when it was already retired. + SupersededTaskID int64 `json:"superseded_task_id,omitempty"` + // Worker is the replaced attempt's recorded process, still live in the + // ledger: the caller terminates it (driver.TerminateRecorded). + Worker *LiveWorker `json:"worker,omitempty"` + // Held says the hold marker stands: authorized, and nothing launches + // until release. + Held bool `json:"held,omitempty"` +} + +// LiveWorker is an attempt's recorded worker process. +type LiveWorker struct { + AttemptID string `json:"attempt_id"` + TaskID int64 `json:"task_id"` + // PID, PGID and StartedAt are the recorded process: with the start time, + // the pid is an identity (driver.OwnsWorker). + PID int `json:"pid"` + PGID int `json:"pgid"` + StartedAt time.Time `json:"started_at"` +} + +// Redispatch authorizes a record to run again, or for the first time, and +// records who authorized it (invariants 4 to 6). +// +// - completed with outcome unknown or failed: the task's token is +// superseded; admitted at once when the task has ended, otherwise when it +// ends. Refused without a snapshot or a route. +// - held with its snapshot and route and no blocking reason: admitted. +// - blocked, or held over a blocking reason: authorized as blocked, and +// Rerun asks the caller to run what blocked it. +// - succeeded, discarded, and anything live (seen, admitted, queued, +// dispatched) are refused with ErrDecisionRefused. +func (l *Ledger) Redispatch(ctx context.Context, eventID int64, by string) (RedispatchResult, error) { + if strings.TrimSpace(by) == "" { + return RedispatchResult{}, errors.New("connector: a redispatch records who authorized it") + } + var out RedispatchResult + err := retryBusy(func() error { + var err error + out, err = l.redispatch(ctx, eventID, by) + return err + }) + return out, err +} + +func (l *Ledger) redispatch(ctx context.Context, eventID int64, by string) (RedispatchResult, error) { + tx, err := l.db.BeginTx(ctx, nil) + if err != nil { + return RedispatchResult{}, fmt.Errorf("connector: begin redispatch: %w", err) + } + defer func() { _ = tx.Rollback() }() + + record, err := loadOperatorRecord(ctx, tx, eventID) + if err != nil { + return RedispatchResult{}, err + } + task, err := loadEventTask(ctx, tx, eventID) + if err != nil { + return RedispatchResult{}, err + } + out := RedispatchResult{EventID: eventID, FromState: record.State, FromReason: record.Reason, FromOutcome: task.outcome} + refuse := func(why string) error { + return fmt.Errorf("connector: redispatch of event %d %s: %w", eventID, why, ErrDecisionRefused) + } + dispatchable := !record.ContentDropped && len(record.Decision.Snapshot) > 0 && record.Decision.Routed && record.Decision.ConversationKey != "" + now := l.timestamp() + authorize := []assignment{{column: "authorized_at", value: now}, {column: "authorized_by", value: by}} + recorded := false + + switch record.State { + case StateSeen, StateAdmitted, StateQueued, StateDispatched: + return RedispatchResult{}, refuse(fmt.Sprintf("is %s: it is live, and runs without one", record.State)) + case StateDiscarded: + return RedispatchResult{}, refuse(fmt.Sprintf("is discarded (%s)", record.Reason)) + + case StateCompleted: + switch { + case !task.found || task.delivery != DeliveryCompleted: + return RedispatchResult{}, refuse("has no settled outcome to redispatch") + case task.outcome == OutcomeSucceeded: + return RedispatchResult{}, refuse("succeeded; a success is not run again") + case task.outcome != OutcomeUnknown && task.outcome != OutcomeFailed: + return RedispatchResult{}, refuse(fmt.Sprintf("has outcome %q", task.outcome)) + case record.redispatchDecision != 0: + return RedispatchResult{}, refuse("already has a redispatch waiting for its task to end") + case !dispatchable: + return RedispatchResult{}, refuse("no longer has the snapshot and route a dispatch needs (retention dropped them, or the verdict carried none)") + } + if !task.superseded { + // The replaced worker is refused by basecamp_connect from here on + // (invariant 5). Through supersedeTask and not a bare write to + // superseded_at: the supersession retires the task's rows in the + // same statement (tasks_supersession_retires_its_events), so an + // event this task never exposed has to be returned to admitted + // here or it is never returned at all — the settlement at the + // attempt's end reads only rows that are still live, and finds + // none. A returned event is not startable while the task it left + // has not ended, so nothing runs beside the worker being stopped. + if err := l.supersedeTask(ctx, tx, task.taskID); err != nil { + return RedispatchResult{}, err + } + out.SupersededTaskID = task.taskID + } + if task.liveAttempt != "" { + out.Worker = &LiveWorker{AttemptID: task.liveAttempt, TaskID: task.taskID, + PID: task.process.PID, PGID: task.process.PGID, StartedAt: task.process.StartedAt} + } + to := StateCompleted + if task.ended { + to = StateAdmitted + } + // The decision is the authorization the database checks: the record + // names it, and only a decision made after the outcome settled lets a + // completed record move (invariant 4). + decisionID, err := insertDecision(ctx, tx, decision{action: "redispatch", eventID: eventID, by: by, at: notBefore(now, task.completedAt), + fromState: record.State, fromReason: record.Reason, fromOutcome: task.outcome, toState: to, + supersededTask: out.SupersededTaskID, note: pendingNote(task)}) + if err != nil { + return RedispatchResult{}, err + } + recorded = true + if _, err := tx.ExecContext(ctx, `UPDATE events SET authorized_at = ?, authorized_by = ?, redispatch_decision = ? WHERE id = ?`, now, by, decisionID, eventID); err != nil { + return RedispatchResult{}, fmt.Errorf("connector: authorize event %d: %w", eventID, err) + } + if task.ended { + moved, err := l.move(ctx, tx, transition{id: eventID, state: StateAdmitted, from: []RecordState{StateCompleted}, byOperator: true, + set: []assignment{{column: "redispatch_decision", value: nil}}}) + if err != nil { + return RedispatchResult{}, err + } + if !moved { + return RedispatchResult{}, fmt.Errorf("connector: admit event %d: %w", eventID, ErrNotATransition) + } + out.Admitted = true + } else { + out.Pending = true + } + + case StateHeld: + if record.Reason == "" && dispatchable { + // Queued behind a live conversation, as admission would write it. + target := StateAdmitted + var live bool + if err := tx.QueryRowContext(ctx, `SELECT EXISTS (SELECT 1 FROM events WHERE conversation_key = ? AND id <> ? AND state IN ('admitted', 'dispatched'))`, + record.Decision.ConversationKey, eventID).Scan(&live); err != nil { + return RedispatchResult{}, fmt.Errorf("connector: read conversation of %d: %w", eventID, err) + } + if live { + target = StateQueued + } + moved, err := l.move(ctx, tx, transition{id: eventID, state: target, from: []RecordState{StateHeld}, byOperator: true, set: authorize}) + if err != nil { + return RedispatchResult{}, err + } + if !moved { + return RedispatchResult{}, fmt.Errorf("connector: admit event %d: %w", eventID, ErrNotATransition) + } + out.Admitted = target == StateAdmitted + break + } + // A held record carries no reason today (events_review_is_held clears + // it), but the spec's "held over a blocking reason" is a record a + // migration may yet write, and it re-runs what blocked it. + reason := record.Reason + if reason == "" { + reason = "held_incomplete" + } + moved, err := l.move(ctx, tx, transition{id: eventID, state: StateBlocked, reason: reason, from: []RecordState{StateHeld}, byOperator: true}) + if err != nil { + return RedispatchResult{}, err + } + if !moved { + return RedispatchResult{}, fmt.Errorf("connector: authorize event %d: %w", eventID, ErrNotATransition) + } + if err := authorizeBlocked(ctx, tx, eventID, now, by); err != nil { + return RedispatchResult{}, err + } + out.Rerun = true + + case StateBlocked: + // The record keeps its state; what blocked it runs again. Writing + // the authorization is not a state change and leaves the revision + // the re-run loads at. + if err := authorizeBlocked(ctx, tx, eventID, now, by); err != nil { + return RedispatchResult{}, err + } + out.Rerun = true + + default: + return RedispatchResult{}, refuse(fmt.Sprintf("is in a state %q this build does not know", record.State)) + } + + if err := tx.QueryRowContext(ctx, `SELECT state FROM events WHERE id = ?`, eventID).Scan(&out.State); err != nil { + return RedispatchResult{}, fmt.Errorf("connector: read event %d back: %w", eventID, err) + } + if _, out.Held, err = readHold(ctx, tx); err != nil { + return RedispatchResult{}, err + } + if !recorded { + note := "" + if out.Rerun { + note = "prerequisite runs again" + } + if err := recordDecision(ctx, tx, decision{action: "redispatch", eventID: eventID, by: by, at: now, + fromState: record.State, fromReason: record.Reason, fromOutcome: task.outcome, toState: out.State, + supersededTask: out.SupersededTaskID, note: note}); err != nil { + return RedispatchResult{}, err + } + } + if err := tx.Commit(); err != nil { + return RedispatchResult{}, fmt.Errorf("connector: commit redispatch of %d: %w", eventID, err) + } + return out, nil +} + +// DiscardResult is what a discard did. +type DiscardResult struct { + EventID int64 `json:"event_id"` + FromState RecordState `json:"from_state"` + FromReason string `json:"from_reason,omitempty"` + FromOutcome Outcome `json:"from_outcome,omitempty"` + // Already says the record was discarded by a person before; nothing + // changed. + Already bool `json:"already_discarded,omitempty"` + // Canceled counts lifecycle messages still pending for the event that + // will not be sent. + Canceled int `json:"canceled_messages"` +} + +// Discard closes a held, blocked or unknown record without running it, as +// discarded(by_operator), and records who decided. Anything else is refused +// with ErrDecisionRefused. +func (l *Ledger) Discard(ctx context.Context, eventID int64, by string) (DiscardResult, error) { + if strings.TrimSpace(by) == "" { + return DiscardResult{}, errors.New("connector: a discard records who decided") + } + var out DiscardResult + err := retryBusy(func() error { + var err error + out, err = l.discard(ctx, eventID, by) + return err + }) + return out, err +} + +func (l *Ledger) discard(ctx context.Context, eventID int64, by string) (DiscardResult, error) { + tx, err := l.db.BeginTx(ctx, nil) + if err != nil { + return DiscardResult{}, fmt.Errorf("connector: begin discard: %w", err) + } + defer func() { _ = tx.Rollback() }() + + record, err := loadOperatorRecord(ctx, tx, eventID) + if err != nil { + return DiscardResult{}, err + } + task, err := loadEventTask(ctx, tx, eventID) + if err != nil { + return DiscardResult{}, err + } + out := DiscardResult{EventID: eventID, FromState: record.State, FromReason: record.Reason, FromOutcome: task.outcome} + refuse := func(why string) error { + return fmt.Errorf("connector: discard of event %d %s: %w", eventID, why, ErrDecisionRefused) + } + switch record.State { + case StateDiscarded: + if record.Reason == ReasonByOperator { + out.Already = true + return out, nil + } + return DiscardResult{}, refuse(fmt.Sprintf("is already discarded (%s)", record.Reason)) + case StateCompleted: + if !task.found || task.outcome != OutcomeUnknown { + return DiscardResult{}, refuse(fmt.Sprintf("completed with outcome %q; only an unknown outcome is discarded", task.outcome)) + } + case StateHeld, StateBlocked: + default: + return DiscardResult{}, refuse(fmt.Sprintf("is %s: only a held, blocked or unknown record is discarded", record.State)) + } + + now := l.timestamp() + // Recorded before the move, which the database allows out of completed + // only against it (invariant 4). + if err := recordDecision(ctx, tx, decision{action: "discard", eventID: eventID, by: by, at: notBefore(now, task.completedAt), + fromState: record.State, fromReason: record.Reason, fromOutcome: task.outcome, toState: StateDiscarded}); err != nil { + return DiscardResult{}, err + } + moved, err := l.move(ctx, tx, transition{id: eventID, state: StateDiscarded, reason: ReasonByOperator, + from: []RecordState{StateHeld, StateBlocked, StateCompleted}, byOperator: true, + set: []assignment{{column: "redispatch_decision", value: nil}}}) + if err != nil { + return DiscardResult{}, err + } + if !moved { + return DiscardResult{}, fmt.Errorf("connector: discard event %d: %w", eventID, ErrNotATransition) + } + // What the connector would still have said about this event is not said: + // a guard acknowledgement or holding reply for a record a person closed. + res, err := tx.ExecContext(ctx, ` +UPDATE outbox SET state = 'canceled', finished_at = ?, note = 'discarded by a person' +WHERE event_id = ? AND state = 'pending' AND kind IN ('guard_ack', 'holding_reply')`, now, eventID) + if err != nil { + return DiscardResult{}, fmt.Errorf("connector: cancel lifecycle messages for %d: %w", eventID, err) + } + canceled, err := res.RowsAffected() + if err != nil { + return DiscardResult{}, err + } + out.Canceled = int(canceled) + if err := tx.Commit(); err != nil { + return DiscardResult{}, fmt.Errorf("connector: commit discard of %d: %w", eventID, err) + } + return out, nil +} + +// AuthorizedBlocked lists blocked records a person authorized, oldest first: +// authorized since the record entered its current run of blocked states, so +// an authorization that answered an earlier outcome does not count. +// The redispatch command runs the prerequisite itself; this is for the +// blocked-record recovery schedule to run it again when that did not settle +// it (the schedule is plan step 22's, and nothing calls this yet). +func (l *Ledger) AuthorizedBlocked(ctx context.Context, limit int) ([]int64, error) { + rows, err := l.db.QueryContext(ctx, `SELECT id FROM events WHERE state = 'blocked' AND authorized_at >= blocked_at ORDER BY id LIMIT ?`, limit) + if err != nil { + return nil, fmt.Errorf("connector: authorized blocked records: %w", err) + } + defer func() { _ = rows.Close() }() + var ids []int64 + for rows.Next() { + var id int64 + if err := rows.Scan(&id); err != nil { + return nil, err + } + ids = append(ids, id) + } + return ids, rows.Err() +} + +// notBefore is now, or the stored time an outcome settled when that is later: +// a decision is never recorded as made before the outcome it decides on, even +// with a clock that stepped back. +func notBefore(now, settled string) string { + if settled > now { + return settled + } + return now +} + +func pendingNote(task eventTask) string { + if task.ended { + return "" + } + return fmt.Sprintf("waits for task %d to end", task.taskID) +} + +// authorizeBlocked records a person's authorization on a blocked record, never +// dated before the record entered its current run of blocked states: an +// authorization counts for that block only when it is not older than it +// (AuthorizedBlocked), and neither a move's own later stamp nor a clock that +// stepped back may make a fresh one look stale. +func authorizeBlocked(ctx context.Context, tx *sql.Tx, eventID int64, now, by string) error { + if _, err := tx.ExecContext(ctx, ` +UPDATE events SET authorized_at = MAX(?, COALESCE(blocked_at, '')), authorized_by = ? +WHERE id = ? AND state = 'blocked'`, now, by, eventID); err != nil { + return fmt.Errorf("connector: authorize event %d: %w", eventID, err) + } + return nil +} diff --git a/internal/connector/ledger_dispatch.go b/internal/connector/ledger_dispatch.go index 59c8dbfbb..c76789fed 100644 --- a/internal/connector/ledger_dispatch.go +++ b/internal/connector/ledger_dispatch.go @@ -712,6 +712,11 @@ ORDER BY te.event_id LIMIT 1`, taskID).Scan(&eventID) // instruction, and the exposure can no longer be withdrawn as a // spawn that failed before any worker existed. if _, err := tx.ExecContext(ctx, `UPDATE task_events SET pulled_at = ? WHERE task_id = ? AND event_id = ? AND pulled_at IS NULL`, now, taskID, eventID); err != nil { + // A hold refuses a first pull (ledger_hold.go): the worker is + // told the connector is held, not given the instruction. + if held, holdErr := isHeld(ctx, tx); holdErr == nil && held { + return Instruction{}, false, fmt.Errorf("connector: event %d: %w", eventID, ErrHeld) + } return Instruction{}, false, fmt.Errorf("connector: record the pull of %d: %w", eventID, err) } wrote = true diff --git a/internal/connector/ledger_events.go b/internal/connector/ledger_events.go index 4e278c040..4b33fc8f8 100644 --- a/internal/connector/ledger_events.go +++ b/internal/connector/ledger_events.go @@ -291,6 +291,11 @@ type transition struct { retryAt time.Time // set is further columns written in the same statement. set []assignment + // byOperator adds the edges only a person's decision has (operatorEdges): + // out of held, and out of completed by a redispatch or a discard. The + // database refuses them to anything that does not also write the + // decision (ledger_hold.go). + byOperator bool } // assignment is one further column a transition writes. column is this @@ -314,6 +319,8 @@ func (l *Ledger) move(ctx context.Context, db dbtx, t transition) (bool, error) if t.reason == "" { return false, fmt.Errorf("connector: set state of %d: a %s record needs a reason", t.id, t.state) } + case StateHeld: + // A held record may keep the reason it was blocked on, or none. case StateSeen, StateAdmitted, StateQueued, StateDispatched, StateCompleted: if t.reason != "" { return false, fmt.Errorf("connector: set state of %d: a %s record takes no reason", t.id, t.state) @@ -326,6 +333,9 @@ func (l *Ledger) move(ctx context.Context, db dbtx, t transition) (bool, error) return false, fmt.Errorf("connector: set state of %d: only a blocked record has a retry deadline", t.id) } froms := enterableFrom(t.state) + if t.byOperator { + froms = append(froms, operatorEdgesInto(t.state)...) + } if len(t.from) > 0 { froms = slices.DeleteFunc(froms, func(from string) bool { return !slices.Contains(t.from, RecordState(from)) @@ -467,6 +477,8 @@ var ErrNoSuchRecord = errors.New("no such event record") // The tombstone is what makes an explicit replay safe forever, so it is never // deleted — only the payload goes. Non-terminal records are never touched: // their payload is the only copy of what intake was told. +// Nor is a completed record a person redispatched while its task was live: +// that task's end admits it, and admitted needs its snapshot. func (l *Ledger) DropContent(ctx context.Context, discardedBefore, completedBefore time.Time) (int, error) { res, err := l.db.ExecContext(ctx, ` UPDATE events @@ -476,7 +488,7 @@ SET details = NULL, event_type = '', kind = '', action = '', bucket_id = 0, snapshot = NULL, trigger_name = '', acknowledge = 0, conversation_key = '', reply_kind = '', reply_recording_id = 0, routed = 0, route = '', class = '', recording_url = '', requester_id = 0 -WHERE content_dropped = 0 +WHERE content_dropped = 0 AND redispatch_decision IS NULL AND ((state = ? AND updated_at < ?) OR (state = ? AND updated_at < ?))`, string(StateDiscarded), stamp(discardedBefore), string(StateCompleted), stamp(completedBefore)) diff --git a/internal/connector/ledger_hold.go b/internal/connector/ledger_hold.go new file mode 100644 index 000000000..05910d1a4 --- /dev/null +++ b/internal/connector/ledger_hold.go @@ -0,0 +1,527 @@ +package connector + +import ( + "context" + "database/sql" + "errors" + "fmt" + "os" + "strings" + "time" +) + +// The hold marker, intake generations, the review tag, and people's decisions +// on records: the ledger half of `basecamp connect --hold`, `release`, +// `redispatch`, `discard`, `shadow promote` and `import`. +// +// # Invariants +// +// Each is held by the database where SQL can say it, and by a test that fails +// without it (operator_invariants_test.go). +// +// 1. Nothing a hold tagged for review reaches a worker without a person. A +// tagged, unauthorized record written admitted or queued — by admission, +// by a task's end returning it, by anything — is written held instead, by +// a trigger, in the same statement. A held record is not startable. +// 2. The hold marker stops dispatch and posting at the database. While it +// stands no attempt row can be written, no task takes a follow-up, no +// event is handed to a worker for the first time — neither a first +// exposure nor a first pull of an event the launch exposed, so a worker a +// crashed connector left running is told nothing new — and no outbox +// intent can move to sending. It lives in the ledger, so every +// start respects it, and only Release clears it. What it does not stop is +// what such a worker already holds: an instruction it was handed before +// the hold, and its own Basecamp credential. Ending it is the one-owner +// rule's (driver/worker.go), and a person can hurry it with redispatch. +// 3. A hold is one transaction: the marker, a new intake generation, the +// review tag on every non-terminal record of the generations before it +// (clearing any earlier authorization, a redispatch still waiting for its +// task included), and admitted or queued records moved to held. +// 4. A person's decision is one transaction with the state change it makes, +// and it records who decided. A terminal record leaves its state only +// against a decision row made after its outcome settled: completed to +// admitted by the redispatch the record names, which the move consumes; +// completed(unknown) to discarded(by_operator) by a discard, and +// completed(unknown or failed) to discarded(imported_done) by an import's +// done decision. Discarded never leaves. A trigger refuses every other +// edge. +// 5. A redispatch never runs two workers for one event. The replaced task's +// token is superseded in the authorization's transaction, and an event +// whose task is still live is not admitted until that task ends: the +// authorization waits on the record and a trigger applies it in the +// transaction that ends the task. One live task per conversation keeps +// the new task from starting before then. +// 6. Admitted means dispatchable. A redispatch admits only a record that +// still has its snapshot and route; anything else is decided again by +// admission, whose verdict stands. +// 7. Shadow promote and import are atomic under a crash: each is one ledger +// transaction, and promote exposes the shadow ledger at the normal path +// only after its hold committed, by one rename (promote.go). +// 8. Reading is not deciding. Status opens the ledger read-only, takes no +// lock, and says nothing of content, feed positions or tokens. +const migrationOperator = ` +CREATE TABLE generations ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + cause TEXT NOT NULL CHECK (cause IN ('hold', 'shadow_promote')), + opened_by TEXT NOT NULL CHECK (opened_by <> ''), + opened_at TEXT NOT NULL +); + +CREATE TABLE hold_marker ( + id INTEGER PRIMARY KEY CHECK (id = 1), + generation INTEGER NOT NULL REFERENCES generations (id), + cause TEXT NOT NULL CHECK (cause IN ('hold', 'shadow_promote')), + held_by TEXT NOT NULL CHECK (held_by <> ''), + held_at TEXT NOT NULL +); + +CREATE TABLE decisions ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + action TEXT NOT NULL CHECK (action IN ('hold', 'release', 'redispatch', 'discard', 'shadow_promote', 'import')), + event_id INTEGER, + decided_by TEXT NOT NULL CHECK (decided_by <> ''), + decided_at TEXT NOT NULL, + from_state TEXT NOT NULL DEFAULT '', + from_reason TEXT NOT NULL DEFAULT '', + from_outcome TEXT NOT NULL DEFAULT '', + to_state TEXT NOT NULL DEFAULT '', + superseded_task_id INTEGER, + note TEXT NOT NULL DEFAULT '' +); +CREATE INDEX decisions_event ON decisions (event_id, id); + +CREATE TABLE connection ( + id INTEGER PRIMARY KEY CHECK (id = 1), + state TEXT NOT NULL, + pid INTEGER NOT NULL, + changed_at TEXT NOT NULL, + detail TEXT NOT NULL DEFAULT '' +); + +ALTER TABLE events ADD COLUMN generation INTEGER NOT NULL DEFAULT 0; +ALTER TABLE events ADD COLUMN review INTEGER NOT NULL DEFAULT 0; +ALTER TABLE events ADD COLUMN authorized_at TEXT; +ALTER TABLE events ADD COLUMN authorized_by TEXT NOT NULL DEFAULT ''; +ALTER TABLE events ADD COLUMN redispatch_decision INTEGER REFERENCES decisions (id); +CREATE INDEX events_review ON events (review, state); + +CREATE TRIGGER events_generation +AFTER INSERT ON events +BEGIN + UPDATE events SET generation = (SELECT COALESCE(MAX(id), 0) FROM generations) WHERE id = NEW.id; +END; + +CREATE TRIGGER events_review_is_held +AFTER UPDATE OF state, review, authorized_at ON events +WHEN NEW.state IN ('admitted', 'queued') AND NEW.review = 1 AND NEW.authorized_at IS NULL +BEGIN + UPDATE events SET state = 'held', reason = '', revision = revision + 1 WHERE id = NEW.id; +END; + +-- A held record's acknowledgement guard is canceled, not merely delayed: the +-- record may wait days for a person, and "received" then is worse than +-- nothing. A redispatch does not write a new one — the worker's own +-- acknowledgement is the first thing its prompt asks for. +CREATE TRIGGER events_held_cancels_guard +AFTER UPDATE OF state ON events +WHEN NEW.state = 'held' AND OLD.state <> 'held' +BEGIN + UPDATE outbox SET state = 'canceled', note = 'held', + finished_at = strftime('%Y-%m-%dT%H:%M:%f000000Z', 'now') + WHERE intent_key = 'guard_ack:event:' || NEW.id AND state = 'pending'; +END; + +CREATE TRIGGER attempts_refused_under_hold +BEFORE INSERT ON attempts +WHEN EXISTS (SELECT 1 FROM hold_marker) +BEGIN + SELECT RAISE(ABORT, 'the connector is held: nothing is dispatched until basecamp connect release'); +END; + +CREATE TRIGGER task_events_exposure_refused_under_hold +BEFORE UPDATE OF delivery ON task_events +WHEN OLD.delivery = 'admitted' AND NEW.delivery = 'exposed' AND EXISTS (SELECT 1 FROM hold_marker) +BEGIN + SELECT RAISE(ABORT, 'the connector is held: no instruction is handed to a worker until basecamp connect release'); +END; + +-- The other first hand-off: an event the launch exposed carries only a +-- pointer until a worker pulls its instruction, so a first pull is new work +-- reaching that worker and the hold refuses it too. A repeat — a worker +-- asking again for what it already pulled — is answered. +CREATE TRIGGER task_events_pull_refused_under_hold +BEFORE UPDATE OF pulled_at ON task_events +WHEN OLD.pulled_at IS NULL AND NEW.pulled_at IS NOT NULL AND EXISTS (SELECT 1 FROM hold_marker) +BEGIN + SELECT RAISE(ABORT, 'the connector is held: no instruction is handed to a worker until basecamp connect release'); +END; + +CREATE TRIGGER outbox_refused_under_hold +BEFORE UPDATE OF state ON outbox +WHEN NEW.state = 'sending' AND OLD.state <> 'sending' AND EXISTS (SELECT 1 FROM hold_marker) +BEGIN + SELECT RAISE(ABORT, 'the connector is held: nothing is posted until basecamp connect release'); +END; + +DROP TRIGGER events_terminal_is_terminal; +CREATE TRIGGER events_terminal_is_terminal +BEFORE UPDATE OF state ON events +WHEN OLD.state IN ('completed', 'discarded') AND NEW.state <> OLD.state + AND NOT ( + OLD.state = 'completed' AND NEW.state = 'admitted' + AND OLD.redispatch_decision IS NOT NULL AND NEW.redispatch_decision IS NULL + AND OLD.content_dropped = 0 AND OLD.snapshot IS NOT NULL + AND (SELECT te.outcome FROM task_events te WHERE te.event_id = OLD.id AND te.withdrawn_at IS NULL + ORDER BY te.task_id DESC LIMIT 1) IN ('unknown', 'failed') + AND EXISTS ( + SELECT 1 FROM decisions d + WHERE d.id = OLD.redispatch_decision AND d.event_id = OLD.id AND d.action = 'redispatch' + AND d.decided_at >= (SELECT te.completed_at FROM task_events te WHERE te.event_id = OLD.id AND te.withdrawn_at IS NULL + ORDER BY te.task_id DESC LIMIT 1)) + ) + AND NOT ( + OLD.state = 'completed' AND NEW.state = 'discarded' AND NEW.reason = 'by_operator' + AND (SELECT te.outcome FROM task_events te WHERE te.event_id = OLD.id AND te.withdrawn_at IS NULL + ORDER BY te.task_id DESC LIMIT 1) = 'unknown' + AND EXISTS ( + SELECT 1 FROM decisions d + WHERE d.event_id = OLD.id AND d.action = 'discard' + AND d.decided_at >= (SELECT te.completed_at FROM task_events te WHERE te.event_id = OLD.id AND te.withdrawn_at IS NULL + ORDER BY te.task_id DESC LIMIT 1)) + ) + AND NOT ( + OLD.state = 'completed' AND NEW.state = 'discarded' AND NEW.reason = 'imported_done' + AND (SELECT te.outcome FROM task_events te WHERE te.event_id = OLD.id AND te.withdrawn_at IS NULL + ORDER BY te.task_id DESC LIMIT 1) IN ('unknown', 'failed') + AND EXISTS ( + SELECT 1 FROM decisions d + WHERE d.event_id = OLD.id AND d.action = 'import' + AND d.decided_at >= (SELECT te.completed_at FROM task_events te WHERE te.event_id = OLD.id AND te.withdrawn_at IS NULL + ORDER BY te.task_id DESC LIMIT 1)) + ) +BEGIN + SELECT RAISE(ABORT, 'a terminal record cannot change state'); +END; + +CREATE TRIGGER tasks_end_applies_redispatch +AFTER UPDATE OF ended_at ON tasks +WHEN OLD.ended_at IS NULL AND NEW.ended_at IS NOT NULL +BEGIN + UPDATE events + SET state = 'admitted', reason = '', redispatch_decision = NULL, revision = revision + 1, + updated_at = NEW.ended_at, blocked_at = NULL, retry_at = NULL + WHERE state = 'completed' AND redispatch_decision IS NOT NULL + AND content_dropped = 0 AND snapshot IS NOT NULL + AND id IN (SELECT event_id FROM task_events WHERE task_id = NEW.id); +END; +` + +// ErrHeld is the hold marker refusing to hand a worker something new. It is +// not a failure of the task: nothing more is handed over until release. +var ErrHeld = errors.New("the connector is held") + +// Reasons a person's decision writes. +const ( + // ReasonByOperator is a record a person closed without running it. + ReasonByOperator = "by_operator" + // ReasonImportedDone is a tombstone an import wrote for an entry a person + // confirmed was finished before the cutover. + ReasonImportedDone = "imported_done" +) + +// operatorEdges are the moves only a person's decision makes, by target: the +// states a record may leave for it. The lifecycle's own edges (ledger_events.go) +// are what the connector does by itself; these are never taken automatically. +var operatorEdges = map[RecordState][]RecordState{ + // A redispatch admits a completed record, or a held one with its snapshot + // (queued when its conversation is live). + StateAdmitted: {StateCompleted, StateHeld}, + StateQueued: {StateHeld}, + // A hold holds what was waiting for a worker. + StateHeld: {StateAdmitted, StateQueued}, + // A redispatch of a record held over a blocking reason runs it again as + // blocked. + StateBlocked: {StateHeld}, + // A discard closes a held record or an unknown outcome. + StateDiscarded: {StateHeld, StateCompleted}, +} + +func operatorEdgesInto(target RecordState) []string { + out := make([]string, 0, len(operatorEdges[target])) + for _, from := range operatorEdges[target] { + out = append(out, string(from)) + } + return out +} + +// HoldCause is what set a hold. +type HoldCause string + +const ( + // HoldByOperator is `basecamp connect --hold`. + HoldByOperator HoldCause = "hold" + // HoldByPromote is `basecamp connect shadow promote`. + HoldByPromote HoldCause = "shadow_promote" +) + +// Hold is the standing hold marker. +type Hold struct { + // Generation is the intake generation the latest hold opened. Records of + // earlier generations were tagged for review. + Generation int64 `json:"generation"` + Cause HoldCause `json:"cause"` + HeldBy string `json:"held_by"` + HeldAt time.Time `json:"held_at"` +} + +// HoldResult is what setting a hold did. +type HoldResult struct { + Hold Hold `json:"hold"` + // Tagged is how many non-terminal records were tagged for review. + Tagged int `json:"tagged_for_review"` + // Held is how many of them were waiting for a worker and are now held. + Held int `json:"held"` +} + +// SetHold sets the durable hold marker, opens a new intake generation, and +// tags every non-terminal record of the generations before it for review, in +// one transaction (invariant 3). A hold already standing keeps its first +// setter and time; the new generation and tags are written again. +func (l *Ledger) SetHold(ctx context.Context, by string, cause HoldCause) (HoldResult, error) { + if strings.TrimSpace(by) == "" { + return HoldResult{}, errors.New("connector: a hold records who set it") + } + if cause != HoldByOperator && cause != HoldByPromote { + return HoldResult{}, fmt.Errorf("connector: %q is not a hold cause", cause) + } + var out HoldResult + err := retryBusy(func() error { + tx, err := l.db.BeginTx(ctx, nil) + if err != nil { + return fmt.Errorf("connector: begin hold: %w", err) + } + defer func() { _ = tx.Rollback() }() + out, err = l.hold(ctx, tx, by, cause) + if err != nil { + return err + } + if err := tx.Commit(); err != nil { + return fmt.Errorf("connector: commit hold: %w", err) + } + return nil + }) + return out, err +} + +// holdStep is a test seam: a crash test kills the process at a named step. +var holdStep = func(string) {} + +func (l *Ledger) hold(ctx context.Context, tx *sql.Tx, by string, cause HoldCause) (HoldResult, error) { + now := l.timestamp() + res, err := tx.ExecContext(ctx, `INSERT INTO generations (cause, opened_by, opened_at) VALUES (?, ?, ?)`, string(cause), by, now) + if err != nil { + return HoldResult{}, fmt.Errorf("connector: open a generation: %w", err) + } + generation, err := res.LastInsertId() + if err != nil { + return HoldResult{}, fmt.Errorf("connector: open a generation: %w", err) + } + if _, err := tx.ExecContext(ctx, ` +INSERT INTO hold_marker (id, generation, cause, held_by, held_at) VALUES (1, ?, ?, ?, ?) +ON CONFLICT (id) DO UPDATE SET generation = excluded.generation`, generation, string(cause), by, now); err != nil { + return HoldResult{}, fmt.Errorf("connector: set the hold marker: %w", err) + } + holdStep("marker") + + var waiting int + if err := tx.QueryRowContext(ctx, `SELECT COUNT(*) FROM events WHERE state IN ('admitted', 'queued')`).Scan(&waiting); err != nil { + return HoldResult{}, fmt.Errorf("connector: count waiting records: %w", err) + } + // Tagging a waiting record holds it: events_review_is_held fires on the + // review column in this same statement (invariant 1). + tagged, err := tx.ExecContext(ctx, ` +UPDATE events SET review = 1, authorized_at = NULL, authorized_by = '' +WHERE state NOT IN ('completed', 'discarded') AND generation < ?`, generation) + if err != nil { + return HoldResult{}, fmt.Errorf("connector: tag records for review: %w", err) + } + n, err := tagged.RowsAffected() + if err != nil { + return HoldResult{}, err + } + if _, err := tx.ExecContext(ctx, ` +UPDATE events SET redispatch_decision = NULL, authorized_at = NULL, authorized_by = '' +WHERE state = 'completed' AND redispatch_decision IS NOT NULL`); err != nil { + return HoldResult{}, fmt.Errorf("connector: revoke waiting redispatches: %w", err) + } + holdStep("tagged") + var stillWaiting int + if err := tx.QueryRowContext(ctx, `SELECT COUNT(*) FROM events WHERE state IN ('admitted', 'queued') AND review = 1`).Scan(&stillWaiting); err != nil { + return HoldResult{}, fmt.Errorf("connector: count held records: %w", err) + } + if stillWaiting != 0 { + return HoldResult{}, fmt.Errorf("connector: %d tagged records are still waiting for a worker", stillWaiting) + } + if err := recordDecision(ctx, tx, decision{action: string(cause), by: by, at: now, + note: fmt.Sprintf("generation %d; %d tagged for review", generation, n)}); err != nil { + return HoldResult{}, err + } + hold, ok, err := readHold(ctx, tx) + if err != nil { + return HoldResult{}, err + } + if !ok { + return HoldResult{}, errors.New("connector: the hold marker did not stand") + } + return HoldResult{Hold: hold, Tagged: int(n), Held: waiting}, nil +} + +// ReleaseResult is what a release did. +type ReleaseResult struct { + // Released is false when no hold stood. + Released bool `json:"released"` + Hold Hold `json:"hold,omitzero"` + // StillHeld counts held records, which stay held. + StillHeld int `json:"still_held"` +} + +// Release clears the hold marker. Held records stay held; records a person +// authorized and records of the newest generation dispatch. +func (l *Ledger) Release(ctx context.Context, by string) (ReleaseResult, error) { + if strings.TrimSpace(by) == "" { + return ReleaseResult{}, errors.New("connector: a release records who released") + } + var out ReleaseResult + err := retryBusy(func() error { + out = ReleaseResult{} + tx, err := l.db.BeginTx(ctx, nil) + if err != nil { + return fmt.Errorf("connector: begin release: %w", err) + } + defer func() { _ = tx.Rollback() }() + hold, ok, err := readHold(ctx, tx) + if err != nil { + return err + } + if err := tx.QueryRowContext(ctx, `SELECT COUNT(*) FROM events WHERE state = 'held'`).Scan(&out.StillHeld); err != nil { + return fmt.Errorf("connector: count held records: %w", err) + } + if !ok { + return nil + } + now := l.timestamp() + if _, err := tx.ExecContext(ctx, `DELETE FROM hold_marker WHERE id = 1`); err != nil { + return fmt.Errorf("connector: clear the hold marker: %w", err) + } + if err := recordDecision(ctx, tx, decision{action: "release", by: by, at: now, + note: fmt.Sprintf("hold of generation %d set by %s", hold.Generation, hold.HeldBy)}); err != nil { + return err + } + if err := tx.Commit(); err != nil { + return fmt.Errorf("connector: commit release: %w", err) + } + out.Released, out.Hold = true, hold + return nil + }) + return out, err +} + +// isHeld reports whether the hold marker stands, inside a caller's +// transaction: what a refused write asks before it calls itself a failure. +func isHeld(ctx context.Context, q rowQuerier) (bool, error) { + _, ok, err := readHold(ctx, q) + return ok, err +} + +// Held reports whether the hold marker stands. Its signature is +// OutboxOptions.Paused's. +func (l *Ledger) Held(ctx context.Context) (bool, error) { + _, ok, err := l.HoldMarker(ctx) + return ok, err +} + +// HoldMarker reads the standing hold, if any. +func (l *Ledger) HoldMarker(ctx context.Context) (Hold, bool, error) { + return readHold(ctx, l.db) +} + +type rowQuerier interface { + QueryRowContext(ctx context.Context, query string, args ...any) *sql.Row +} + +func readHold(ctx context.Context, q rowQuerier) (Hold, bool, error) { + var ( + h Hold + cause, stamp string + ) + err := q.QueryRowContext(ctx, `SELECT generation, cause, held_by, held_at FROM hold_marker WHERE id = 1`).Scan(&h.Generation, &cause, &h.HeldBy, &stamp) + switch { + case errors.Is(err, sql.ErrNoRows): + return Hold{}, false, nil + case err != nil: + return Hold{}, false, fmt.Errorf("connector: read the hold marker: %w", err) + } + h.Cause = HoldCause(cause) + if h.HeldAt, err = parseStamp(stamp); err != nil { + return Hold{}, false, err + } + return h, true, nil +} + +// decision is one row of the decisions table. +type decision struct { + action string + eventID int64 + by, at string + fromState RecordState + fromReason string + fromOutcome Outcome + toState RecordState + supersededTask int64 + note string +} + +func recordDecision(ctx context.Context, tx Tx, d decision) error { + _, err := insertDecision(ctx, tx, d) + return err +} + +func insertDecision(ctx context.Context, tx Tx, d decision) (int64, error) { + res, err := tx.ExecContext(ctx, ` +INSERT INTO decisions (action, event_id, decided_by, decided_at, from_state, from_reason, from_outcome, to_state, superseded_task_id, note) +VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)`, + d.action, nullableID64(d.eventID), d.by, d.at, string(d.fromState), d.fromReason, string(d.fromOutcome), + string(d.toState), nullableID64(d.supersededTask), d.note) + if err != nil { + return 0, fmt.Errorf("connector: record the decision: %w", err) + } + return res.LastInsertId() +} + +// Connection states the run command reports for status. +const ( + // ConnectionRunning is a connector starting its parts — intake, + // admission, dispatch, outbox — having passed every check before them. It + // says nothing finer about the feed's socket, which intake does not report. + ConnectionRunning = "running" + // ConnectionStopped is a connector that exited through its own shutdown. + // A second signal or a crash leaves the last state standing, so status + // reads this beside the instance lock's holder rather than instead of it. + ConnectionStopped = "stopped" +) + +// NoteConnection records the running connector's connection state, for +// status. detail is a short diagnostic phrase and never carries a position, +// a ticket or content. +func (l *Ledger) NoteConnection(ctx context.Context, state, detail string) error { + return retryBusy(func() error { + _, err := l.db.ExecContext(ctx, ` +INSERT INTO connection (id, state, pid, changed_at, detail) VALUES (1, ?, ?, ?, ?) +ON CONFLICT (id) DO UPDATE SET state = excluded.state, pid = excluded.pid, changed_at = excluded.changed_at, detail = excluded.detail`, + state, os.Getpid(), l.timestamp(), detail) + if err != nil { + return fmt.Errorf("connector: note connection state: %w", err) + } + return nil + }) +} diff --git a/internal/connector/ledger_import.go b/internal/connector/ledger_import.go new file mode 100644 index 000000000..6aae30267 --- /dev/null +++ b/internal/connector/ledger_import.go @@ -0,0 +1,262 @@ +package connector + +import ( + "bytes" + "context" + "database/sql" + "encoding/json" + "errors" + "fmt" + "strings" +) + +// ReconciliationVersion is the reconciliation file format import reads. +const ReconciliationVersion = 1 + +// Reconciliation decisions. +const ( + // DecisionDone is an entry a person confirmed the old connector's work + // finished: the record becomes a tombstone. + DecisionDone = "done" + // DecisionHeld is every other mapped entry: the record is tagged for + // review and waits for a person. + DecisionHeld = "held" +) + +// Reconciliation is the cutover's reconciliation file: the old connector's +// handled entries, each mapped to a feed event and decided. +type Reconciliation struct { + Version int `json:"version"` + Entries []ReconciliationEntry `json:"entries"` +} + +// ReconciliationEntry is one mapped entry. +type ReconciliationEntry struct { + EventID int64 `json:"event_id"` + Decision string `json:"decision"` +} + +// ParseReconciliation reads a reconciliation file strictly: unknown fields, +// a second entry for one event, and a decision other than done or held are +// refused, so a file that means something else is never half-understood. +func ParseReconciliation(data []byte) (Reconciliation, error) { + dec := json.NewDecoder(bytes.NewReader(data)) + dec.DisallowUnknownFields() + var r Reconciliation + if err := dec.Decode(&r); err != nil { + return Reconciliation{}, fmt.Errorf("connector: reconciliation file: %w", err) + } + // Everything after the file's one value, not only another value: a stray + // brace is a file that does not say what it looks like it says. + if rest := bytes.TrimSpace(data[dec.InputOffset():]); len(rest) > 0 { + return Reconciliation{}, errors.New("connector: reconciliation file: more than one JSON value") + } + if err := r.Validate(); err != nil { + return Reconciliation{}, err + } + return r, nil +} + +// Validate refuses a reconciliation this build cannot apply: another version, +// an entry without an event, a decision that is neither done nor held, or one +// event decided twice. Import checks it too, so a caller that built the value +// itself meets the same rules as one that parsed a file. +func (r Reconciliation) Validate() error { + if r.Version != ReconciliationVersion { + return fmt.Errorf("connector: reconciliation version %d; this build reads %d", r.Version, ReconciliationVersion) + } + seen := make(map[int64]bool, len(r.Entries)) + for i, e := range r.Entries { + switch { + case e.EventID <= 0: + return fmt.Errorf("connector: reconciliation entry %d names no event id", i) + case e.Decision != DecisionDone && e.Decision != DecisionHeld: + return fmt.Errorf("connector: reconciliation entry for event %d has decision %q; use done or held", e.EventID, e.Decision) + case seen[e.EventID]: + return fmt.Errorf("connector: reconciliation names event %d twice", e.EventID) + } + seen[e.EventID] = true + } + return nil +} + +// ImportResult is what an import did. +type ImportResult struct { + // Tombstoned counts records closed as discarded(imported_done), Inserted + // the tombstones written for events the ledger had never seen. + Tombstoned int `json:"tombstoned"` + Inserted int `json:"tombstones_inserted"` + // AlreadyTerminal counts done entries whose record had already finished. + AlreadyTerminal int `json:"already_terminal"` + // Tagged counts non-terminal records tagged for review, and Held those + // of them that were waiting for a worker and are now held. + Tagged int `json:"tagged_for_review"` + Held int `json:"held"` +} + +// importStep is a test seam: a crash test kills the process at a named step. +var importStep = func(string) {} + +// Import applies a reconciliation in one transaction (invariant 7): a +// tombstone for each entry decided done, and the review tag on every other +// non-terminal record, mapped or not, each keeping its state and blocking +// reason. An entry that cannot be applied — a done entry whose record a +// worker holds, a held entry for an event the ledger never saw — refuses the +// whole file, and nothing is written. +func (l *Ledger) Import(ctx context.Context, r Reconciliation, by string) (ImportResult, error) { + if strings.TrimSpace(by) == "" { + return ImportResult{}, errors.New("connector: an import records who applied it") + } + if err := r.Validate(); err != nil { + return ImportResult{}, err + } + var out ImportResult + err := retryBusy(func() error { + var err error + out, err = l.importReconciliation(ctx, r, by) + return err + }) + return out, err +} + +func (l *Ledger) importReconciliation(ctx context.Context, r Reconciliation, by string) (ImportResult, error) { + tx, err := l.db.BeginTx(ctx, nil) + if err != nil { + return ImportResult{}, fmt.Errorf("connector: begin import: %w", err) + } + defer func() { _ = tx.Rollback() }() + + var out ImportResult + now := l.timestamp() + done := map[int64]bool{} + for _, e := range r.Entries { + var state string + err := tx.QueryRowContext(ctx, `SELECT state FROM events WHERE id = ?`, e.EventID).Scan(&state) + missing := errors.Is(err, sql.ErrNoRows) + if err != nil && !missing { + return ImportResult{}, fmt.Errorf("connector: import event %d: %w", e.EventID, err) + } + recorded := false + toState := StateDiscarded + switch e.Decision { + case DecisionDone: + done[e.EventID] = true + // A person said it is finished: whatever authorized it to run + // again, a redispatch waiting for its task included, is withdrawn. + if !missing { + if _, err := tx.ExecContext(ctx, `UPDATE events SET redispatch_decision = NULL, authorized_at = NULL, authorized_by = '' WHERE id = ?`, e.EventID); err != nil { + return ImportResult{}, fmt.Errorf("connector: import event %d: %w", e.EventID, err) + } + } + switch { + case missing: + // A tombstone and nothing else: the event can never become a + // task, whichever lane serves it later. + if _, err := tx.ExecContext(ctx, ` +INSERT INTO events (id, state, reason, lane, event_type, kind, action, bucket_id, creator_id, recording_id, + created_at, seen_at, updated_at, content_dropped) +VALUES (?, 'discarded', ?, 'import', '', '', '', 0, 0, 0, ?, ?, ?, 1)`, e.EventID, ReasonImportedDone, now, now, now); err != nil { + return ImportResult{}, fmt.Errorf("connector: import tombstone for %d: %w", e.EventID, err) + } + out.Inserted++ + case state == string(StateCompleted): + // An unknown or failed outcome waits for a person, and this + // file is that person's decision: the record closes, so no + // redispatch or notice asks for it again. A success is already + // finished. + task, err := loadEventTask(ctx, tx, e.EventID) + if err != nil { + return ImportResult{}, err + } + if task.outcome != OutcomeUnknown && task.outcome != OutcomeFailed { + out.AlreadyTerminal++ + toState = StateCompleted + break + } + // Recorded before the move, which the database allows out of + // completed only against it (invariant 4). + if err := recordDecision(ctx, tx, decision{action: "import", eventID: e.EventID, by: by, at: notBefore(now, task.completedAt), + fromState: StateCompleted, fromOutcome: task.outcome, toState: StateDiscarded, note: "done"}); err != nil { + return ImportResult{}, err + } + recorded = true + moved, err := l.move(ctx, tx, transition{id: e.EventID, state: StateDiscarded, reason: ReasonImportedDone, + from: []RecordState{StateCompleted}, byOperator: true}) + if err != nil { + return ImportResult{}, err + } + if !moved { + return ImportResult{}, fmt.Errorf("connector: import: event %d (completed) cannot be closed: %w", e.EventID, ErrDecisionRefused) + } + out.Tombstoned++ + case state == string(StateDiscarded): + out.AlreadyTerminal++ + case state == string(StateDispatched): + return ImportResult{}, fmt.Errorf("connector: import: event %d is dispatched to a worker; a done decision cannot close it: %w", e.EventID, ErrDecisionRefused) + default: + moved, err := l.move(ctx, tx, transition{id: e.EventID, state: StateDiscarded, reason: ReasonImportedDone, + from: []RecordState{StateSeen, StateAdmitted, StateQueued, StateBlocked, StateHeld}, byOperator: true}) + if err != nil { + return ImportResult{}, err + } + if !moved { + return ImportResult{}, fmt.Errorf("connector: import: event %d (%s) cannot be closed: %w", e.EventID, state, ErrDecisionRefused) + } + out.Tombstoned++ + } + // As a discard does: what the connector would still have said about + // a record a person closed is not said. + if _, err := tx.ExecContext(ctx, ` +UPDATE outbox SET state = 'canceled', finished_at = ?, note = 'discarded by a person' +WHERE event_id = ? AND state = 'pending' AND kind IN ('guard_ack', 'holding_reply')`, now, e.EventID); err != nil { + return ImportResult{}, fmt.Errorf("connector: cancel lifecycle messages for %d: %w", e.EventID, err) + } + if !recorded { + if err := recordDecision(ctx, tx, decision{action: "import", eventID: e.EventID, by: by, at: now, + fromState: RecordState(state), toState: toState, note: "done"}); err != nil { + return ImportResult{}, err + } + } + case DecisionHeld: + if missing { + return ImportResult{}, fmt.Errorf("connector: import: event %d is not in the ledger, so it cannot be held for review: %w", e.EventID, ErrDecisionRefused) + } + } + importStep("entry") + } + + var waiting int + if err := tx.QueryRowContext(ctx, `SELECT COUNT(*) FROM events WHERE state IN ('admitted', 'queued')`).Scan(&waiting); err != nil { + return ImportResult{}, fmt.Errorf("connector: import: %w", err) + } + // Everything not decided done waits for a person: tagging holds a waiting + // record in the same statement (invariant 1), and leaves every other + // record's state and reason as they are. + res, err := tx.ExecContext(ctx, ` +UPDATE events SET review = 1, authorized_at = NULL, authorized_by = '' +WHERE state NOT IN ('completed', 'discarded')`) + if err != nil { + return ImportResult{}, fmt.Errorf("connector: import: tag for review: %w", err) + } + tagged, err := res.RowsAffected() + if err != nil { + return ImportResult{}, err + } + // As a hold does: a redispatch still waiting for its task was authorized + // before the cutover review, and waits for that review too. + if _, err := tx.ExecContext(ctx, ` +UPDATE events SET redispatch_decision = NULL, authorized_at = NULL, authorized_by = '' +WHERE state = 'completed' AND redispatch_decision IS NOT NULL`); err != nil { + return ImportResult{}, fmt.Errorf("connector: import: withdraw waiting redispatches: %w", err) + } + out.Tagged, out.Held = int(tagged), waiting + importStep("tagged") + if err := recordDecision(ctx, tx, decision{action: "import", by: by, at: now, + note: fmt.Sprintf("%d entries; %d tombstoned, %d tombstones inserted, %d tagged for review", len(r.Entries), out.Tombstoned, out.Inserted, out.Tagged)}); err != nil { + return ImportResult{}, err + } + if err := tx.Commit(); err != nil { + return ImportResult{}, fmt.Errorf("connector: commit import: %w", err) + } + return out, nil +} diff --git a/internal/connector/ledger_status.go b/internal/connector/ledger_status.go new file mode 100644 index 000000000..f168bb059 --- /dev/null +++ b/internal/connector/ledger_status.go @@ -0,0 +1,625 @@ +package connector + +import ( + "context" + "database/sql" + "errors" + "fmt" + "path/filepath" + "strings" + "time" +) + +// OpenLedgerReadOnly opens an existing ledger for reading only: no migration, +// no write to the database, no lock. status uses it beside a running connector +// (invariant 8). SQLite may create the WAL sidecars of a cleanly closed ledger +// to read it; they sit in the ledger's private directory. +// +// The file must already exist, and it is refused unless it is private, as +// OpenLedger refuses it. A ledger an older binary wrote, which the running +// connector has not yet migrated, is refused: its columns are not the ones +// this build reads. +func OpenLedgerReadOnly(ctx context.Context, path string) (*Ledger, error) { + if path == "" { + return nil, errors.New("connector: ledger path is required") + } + if isInMemory(path) || strings.ContainsAny(path, "?#%") { + return nil, fmt.Errorf("connector: ledger path %q cannot be opened as a file", path) + } + abs, err := filepath.Abs(path) + if err != nil { + return nil, fmt.Errorf("connector: ledger path %q: %w", path, err) + } + // Vetted as the writer's open vets it, through the same per-file entry and + // without creating the file: a ledger that vanishes under a reader (a + // promote renaming it) is not recreated empty. The entry matters even for + // a reader — the privacy check opens a descriptor and closes it, and that + // close drops every lock this process holds on the file, including the + // ones a Ledger open beside it is holding. Going through claimLedger runs + // the descriptor check once per file per process and verifies every later + // open with Stat instead. + file := claimLedger(abs) + if file.key != abs { + releaseLedger(file) + return nil, fmt.Errorf("connector: %s and %s are one file: %w", abs, file.key, ErrLedgerUnderAnotherName) + } + if err := checkLedgerFile(file, path, abs, false); err != nil { + releaseLedger(file) + return nil, err + } + dsn := "file:" + path + "?mode=ro&_pragma=busy_timeout(5000)&_pragma=query_only(1)" + db, err := sql.Open("sqlite", dsn) + if err != nil { + releaseLedger(file) + return nil, fmt.Errorf("connector: open ledger: %w", err) + } + db.SetMaxOpenConns(1) + l := &Ledger{db: db, file: file, now: time.Now} + version, err := l.SchemaVersion(ctx) + if err != nil { + _ = l.Close() + return nil, fmt.Errorf("connector: read the ledger's schema: %w", err) + } + switch { + case version < len(migrations): + _ = l.Close() + return nil, fmt.Errorf("connector: the ledger is at schema %d and this build reads %d: %w", version, len(migrations), ErrLedgerOutOfDate) + case version > len(migrations): + // A newer build wrote it: its columns are not this build's to read, + // and no decision of this build's may be written into it. + _ = l.Close() + return nil, fmt.Errorf("connector: ledger at schema %d, this basecamp writes %d: %w", version, len(migrations), ErrLedgerSchema) + } + return l, nil +} + +// ErrLedgerOutOfDate is a ledger an older binary wrote, which this build has +// not migrated. Starting the connector migrates it. +var ErrLedgerOutOfDate = errors.New("the ledger is older than this build; start the connector once to bring it up to date") + +// StatusLimit is how many dispatches status lists. +const StatusLimit = 20 + +// Status is what `basecamp connect status` shows. Every field is ids, states, +// counts and timestamps: no content, no feed position, no token or token hash +// (invariant 8). +type Status struct { + SchemaVersion int `json:"schema_version"` + // Connection is the last run's own record, if one ran on this build. + Connection *ConnectionStatus `json:"connection,omitempty"` + // Hold is the standing hold marker. + Hold *HoldStatus `json:"hold,omitempty"` + Generation int64 `json:"generation"` + + Positions []PositionStatus `json:"positions"` + Gaps []GapStatus `json:"gaps"` + Losses []LossStatus `json:"open_losses"` + Unrecovered int `json:"unrecovered_ids"` + + // Queues counts records by state; Blocked counts blocked records by reason. + Queues map[string]int `json:"queues"` + Blocked map[string]int `json:"blocked"` + // Review counts records tagged for review that have not reached a + // person yet, and Authorized those a person authorized that have not run. + Review int `json:"review_tagged"` + AuthorizedBlocked int `json:"authorized_blocked"` + RedispatchPending int `json:"redispatch_pending"` + + Tasks []TaskStatus `json:"live_tasks"` + Worktrees []WorktreeStatus `json:"retained_worktrees"` + // WorktreesKnown is false when no lister was given: the retained + // worktrees are unavailable, not known to be none. + WorktreesKnown bool `json:"worktrees_known"` + Indeterminate []IntentStatus `json:"indeterminate_intents"` + Held []HeldStatus `json:"held_records"` + Dispatches []DispatchStatus `json:"dispatches"` +} + +// ConnectionStatus is the run command's own record of its last run: running +// as its parts start, stopped when it exited. It is not the feed +// socket's state, which intake does not report. +type ConnectionStatus struct { + State string `json:"state"` + PID int `json:"pid"` + ChangedAt time.Time `json:"changed_at"` + Detail string `json:"detail,omitempty"` +} + +// HoldStatus is the hold marker. +type HoldStatus struct { + Generation int64 `json:"generation"` + Cause string `json:"cause"` + HeldBy string `json:"held_by"` + HeldAt time.Time `json:"held_at"` +} + +// PositionStatus is one feed checkpoint: whether a position is held, never +// the position itself, which resumes the account's feed. +type PositionStatus struct { + Filters string `json:"filters"` + HasPosition bool `json:"has_position"` + LastPollServedID int64 `json:"last_poll_served_id"` + UpdatedAt time.Time `json:"updated_at"` +} + +// GapStatus is one recorded 410. +type GapStatus struct { + ID int64 `json:"id"` + DetectedAt time.Time `json:"detected_at"` + Class string `json:"class"` + EpochAfterID *int64 `json:"epoch_after_id,omitempty"` + EntryClass string `json:"entry_class,omitempty"` +} + +// LossStatus is an overflow still being reconciled. +type LossStatus struct { + ID int64 `json:"id"` + DetectedAt time.Time `json:"detected_at"` + Dropped int `json:"dropped"` + Missing int `json:"missing"` + DeadlineAt time.Time `json:"deadline_at"` +} + +// TaskStatus is a live task and its attempt. +type TaskStatus struct { + TaskID int64 `json:"task_id"` + AttemptID string `json:"attempt_id"` + State string `json:"state"` + Driver string `json:"driver"` + WorkDir string `json:"work_dir"` + PID int `json:"pid,omitempty"` + PGID int `json:"pgid,omitempty"` + // ProcessStartedAt is the start time recorded with the pid: with it, the + // pid is an identity (driver.OwnsWorker). + ProcessStartedAt *time.Time `json:"process_started_at,omitempty"` + // TakerPID, TakerPGID and TakerStartedAt are the process the task token + // went to, where one took it: a worker's MCP server, which lives in a + // process group of its own. + TakerPID int `json:"taker_pid,omitempty"` + TakerPGID int `json:"taker_pgid,omitempty"` + TakerStartedAt *time.Time `json:"taker_started_at,omitempty"` + // Worker and Taker are whether each recorded process is still this task's, + // as the caller established it; the ledger read leaves them empty. + Worker string `json:"worker,omitempty"` + Taker string `json:"taker,omitempty"` + LaunchedAt time.Time `json:"launched_at"` + DeadlineAt *time.Time `json:"deadline_at,omitempty"` + EventIDs []int64 `json:"event_ids"` +} + +// WorktreeStatus is a retained worktree, as the worktree lister reports it. +type WorktreeStatus struct { + Path string `json:"path"` + Branch string `json:"branch,omitempty"` + TaskID int64 `json:"task_id,omitempty"` + Reason string `json:"reason,omitempty"` +} + +// IntentStatus is a lifecycle message waiting for a person. The body is not +// shown. +type IntentStatus struct { + ID int64 `json:"id"` + Kind string `json:"kind"` + EventID int64 `json:"event_id,omitempty"` + AttemptID string `json:"attempt_id,omitempty"` + BucketID int64 `json:"bucket_id"` + MessageKind string `json:"message_kind"` + RecordingID int64 `json:"recording_id"` + SendingAt *time.Time `json:"sending_at,omitempty"` + Note string `json:"note,omitempty"` +} + +// HeldStatus is a held record. +type HeldStatus struct { + EventID int64 `json:"event_id"` + EventType string `json:"event_type"` + Trigger string `json:"trigger,omitempty"` + BucketID int64 `json:"bucket_id"` + RecordingURL string `json:"recording_url,omitempty"` + Reason string `json:"reason,omitempty"` + Generation int64 `json:"generation"` + UpdatedAt time.Time `json:"updated_at"` +} + +// DispatchStatus is one attempt and the outcomes of the events on its task. +type DispatchStatus struct { + TaskID int64 `json:"task_id"` + AttemptID string `json:"attempt_id"` + State string `json:"state"` + StopReason string `json:"stop_reason,omitempty"` + LaunchedAt time.Time `json:"launched_at"` + EndedAt *time.Time `json:"ended_at,omitempty"` + Events []DispatchedEvent `json:"events"` +} + +// DispatchedEvent is one event's delivery and outcome on a task. +type DispatchedEvent struct { + EventID int64 `json:"event_id"` + Delivery string `json:"delivery"` + Outcome string `json:"outcome,omitempty"` + ReplyID *int64 `json:"reply_id,omitempty"` + // Withdrawn is an exposure taken back after a start that ran nothing. + Withdrawn bool `json:"withdrawn,omitempty"` +} + +// WorktreeLister lists retained worktrees for status. Card 19's worktree +// ledger provides it; nil means this build cannot say whether any are +// retained — which status reports as unavailable, never as none. +type WorktreeLister func(ctx context.Context) ([]WorktreeStatus, error) + +// Status reads everything status shows in one read transaction, so the +// numbers agree with each other. +func (l *Ledger) Status(ctx context.Context, worktrees WorktreeLister) (Status, error) { + tx, err := l.db.BeginTx(ctx, &sql.TxOptions{ReadOnly: true}) + if err != nil { + return Status{}, fmt.Errorf("connector: begin status: %w", err) + } + defer func() { _ = tx.Rollback() }() + + s := Status{Queues: map[string]int{}, Blocked: map[string]int{}} + if err := tx.QueryRowContext(ctx, `SELECT COALESCE(MAX(version), 0) FROM schema_migrations`).Scan(&s.SchemaVersion); err != nil { + return Status{}, fmt.Errorf("connector: status schema: %w", err) + } + if err := statusConnection(ctx, tx, &s); err != nil { + return Status{}, err + } + hold, ok, err := readHold(ctx, tx) + if err != nil { + return Status{}, err + } + if ok { + s.Hold = &HoldStatus{Generation: hold.Generation, Cause: string(hold.Cause), HeldBy: hold.HeldBy, HeldAt: hold.HeldAt} + } + if err := tx.QueryRowContext(ctx, `SELECT COALESCE(MAX(id), 0) FROM generations`).Scan(&s.Generation); err != nil { + return Status{}, fmt.Errorf("connector: status generation: %w", err) + } + for _, step := range []func(context.Context, *sql.Tx, *Status) error{ + statusPositions, statusGaps, statusQueues, statusTasks, statusIntents, statusHeld, statusDispatches, + } { + if err := step(ctx, tx, &s); err != nil { + return Status{}, err + } + } + if worktrees != nil { + s.WorktreesKnown = true + if s.Worktrees, err = worktrees(ctx); err != nil { + return Status{}, fmt.Errorf("connector: status worktrees: %w", err) + } + } + if s.Worktrees == nil { + s.Worktrees = []WorktreeStatus{} + } + return s, nil +} + +func statusConnection(ctx context.Context, tx *sql.Tx, s *Status) error { + var ( + c ConnectionStatus + changed string + ) + err := tx.QueryRowContext(ctx, `SELECT state, pid, changed_at, detail FROM connection WHERE id = 1`).Scan(&c.State, &c.PID, &changed, &c.Detail) + switch { + case errors.Is(err, sql.ErrNoRows): + return nil + case err != nil: + return fmt.Errorf("connector: status connection: %w", err) + } + if c.ChangedAt, err = parseStamp(changed); err != nil { + return err + } + s.Connection = &c + return nil +} + +func statusPositions(ctx context.Context, tx *sql.Tx, s *Status) error { + rows, err := tx.QueryContext(ctx, `SELECT flat_key, position <> '', last_poll_served_id, updated_at FROM checkpoints ORDER BY updated_at DESC`) + if err != nil { + return fmt.Errorf("connector: status positions: %w", err) + } + defer func() { _ = rows.Close() }() + s.Positions = []PositionStatus{} + for rows.Next() { + var ( + p PositionStatus + updated string + ) + if err := rows.Scan(&p.Filters, &p.HasPosition, &p.LastPollServedID, &updated); err != nil { + return err + } + if p.UpdatedAt, err = parseStamp(updated); err != nil { + return err + } + s.Positions = append(s.Positions, p) + } + return rows.Err() +} + +func statusGaps(ctx context.Context, tx *sql.Tx, s *Status) error { + rows, err := tx.QueryContext(ctx, `SELECT id, detected_at, class, epoch_after_id, entry_class FROM gaps ORDER BY id`) + if err != nil { + return fmt.Errorf("connector: status gaps: %w", err) + } + s.Gaps = []GapStatus{} + for rows.Next() { + var ( + g GapStatus + detected string + epoch sql.NullInt64 + ) + if err := rows.Scan(&g.ID, &detected, &g.Class, &epoch, &g.EntryClass); err != nil { + _ = rows.Close() + return err + } + if g.DetectedAt, err = parseStamp(detected); err != nil { + _ = rows.Close() + return err + } + if epoch.Valid { + id := epoch.Int64 + g.EpochAfterID = &id + } + s.Gaps = append(s.Gaps, g) + } + if err := rows.Close(); err != nil { + return err + } + + rows, err = tx.QueryContext(ctx, ` +SELECT l.id, l.detected_at, l.dropped_count, l.deadline_at, + (SELECT COUNT(*) FROM loss_ids i WHERE i.loss_id = l.id AND i.state = 'missing') +FROM losses l WHERE l.resolved_at IS NULL ORDER BY l.id`) + if err != nil { + return fmt.Errorf("connector: status losses: %w", err) + } + s.Losses = []LossStatus{} + for rows.Next() { + var ( + loss LossStatus + detected, deadline string + ) + if err := rows.Scan(&loss.ID, &detected, &loss.Dropped, &deadline, &loss.Missing); err != nil { + _ = rows.Close() + return err + } + if loss.DetectedAt, err = parseStamp(detected); err != nil { + _ = rows.Close() + return err + } + if loss.DeadlineAt, err = parseStamp(deadline); err != nil { + _ = rows.Close() + return err + } + s.Losses = append(s.Losses, loss) + } + if err := rows.Close(); err != nil { + return err + } + return tx.QueryRowContext(ctx, `SELECT COUNT(DISTINCT event_id) FROM loss_ids WHERE state = 'unrecovered'`).Scan(&s.Unrecovered) +} + +func statusQueues(ctx context.Context, tx *sql.Tx, s *Status) error { + rows, err := tx.QueryContext(ctx, `SELECT state, reason, COUNT(*) FROM events WHERE state <> 'discarded' AND state <> 'completed' GROUP BY state, reason`) + if err != nil { + return fmt.Errorf("connector: status queues: %w", err) + } + for rows.Next() { + var ( + state, reason string + n int + ) + if err := rows.Scan(&state, &reason, &n); err != nil { + _ = rows.Close() + return err + } + s.Queues[state] += n + if state == string(StateBlocked) { + s.Blocked[reason] += n + } + } + if err := rows.Close(); err != nil { + return err + } + return tx.QueryRowContext(ctx, ` +SELECT + (SELECT COUNT(*) FROM events WHERE review = 1 AND state IN ('seen', 'blocked', 'dispatched') + AND NOT (authorized_at IS NOT NULL AND (state <> 'blocked' OR authorized_at >= blocked_at))), + (SELECT COUNT(*) FROM events WHERE state = 'blocked' AND authorized_at >= blocked_at), + (SELECT COUNT(*) FROM events WHERE redispatch_decision IS NOT NULL)`).Scan(&s.Review, &s.AuthorizedBlocked, &s.RedispatchPending) +} + +func statusTasks(ctx context.Context, tx *sql.Tx, s *Status) error { + rows, err := tx.QueryContext(ctx, ` +SELECT t.id, a.id, a.state, a.driver, t.work_dir, COALESCE(a.pid, 0), COALESCE(a.pgid, 0), a.process_started, + COALESCE(a.taker_pid, 0), COALESCE(a.taker_pgid, 0), a.taker_started, a.launched_at, t.deadline_at +FROM attempts a JOIN tasks t ON t.id = a.task_id +WHERE a.state <> 'ended' ORDER BY a.launched_at, a.id`) + if err != nil { + return fmt.Errorf("connector: status tasks: %w", err) + } + s.Tasks = []TaskStatus{} + for rows.Next() { + var ( + t TaskStatus + launched string + deadline sql.NullString + started sql.NullString + taken sql.NullString + ) + if err := rows.Scan(&t.TaskID, &t.AttemptID, &t.State, &t.Driver, &t.WorkDir, &t.PID, &t.PGID, &started, + &t.TakerPID, &t.TakerPGID, &taken, &launched, &deadline); err != nil { + _ = rows.Close() + return err + } + for _, stamped := range []struct { + raw sql.NullString + to **time.Time + }{{started, &t.ProcessStartedAt}, {taken, &t.TakerStartedAt}} { + if !stamped.raw.Valid { + continue + } + at, err := parseStamp(stamped.raw.String) + if err != nil { + _ = rows.Close() + return err + } + *stamped.to = &at + } + if t.LaunchedAt, err = parseStamp(launched); err != nil { + _ = rows.Close() + return err + } + if deadline.Valid { + at, err := parseStamp(deadline.String) + if err != nil { + _ = rows.Close() + return err + } + t.DeadlineAt = &at + } + s.Tasks = append(s.Tasks, t) + } + if err := rows.Close(); err != nil { + return err + } + for i := range s.Tasks { + ids, err := taskEventIDs(ctx, tx, s.Tasks[i].TaskID) + if err != nil { + return err + } + s.Tasks[i].EventIDs = ids + } + return nil +} + +func taskEventIDs(ctx context.Context, tx *sql.Tx, taskID int64) ([]int64, error) { + rows, err := tx.QueryContext(ctx, `SELECT event_id FROM task_events WHERE task_id = ? AND withdrawn_at IS NULL ORDER BY event_id`, taskID) + if err != nil { + return nil, fmt.Errorf("connector: status task %d: %w", taskID, err) + } + defer func() { _ = rows.Close() }() + ids := []int64{} + for rows.Next() { + var id int64 + if err := rows.Scan(&id); err != nil { + return nil, err + } + ids = append(ids, id) + } + return ids, rows.Err() +} + +func statusIntents(ctx context.Context, tx *sql.Tx, s *Status) error { + rows, err := tx.QueryContext(ctx, selectIntents+` WHERE state = 'indeterminate' ORDER BY id`) + if err != nil { + return fmt.Errorf("connector: status intents: %w", err) + } + intents, err := scanIntents(rows) + if err != nil { + return err + } + s.Indeterminate = make([]IntentStatus, 0, len(intents)) + for _, in := range intents { + s.Indeterminate = append(s.Indeterminate, IntentStatus{ + ID: in.ID, Kind: string(in.Kind), EventID: in.EventID, AttemptID: in.AttemptID, + BucketID: in.Destination.BucketID, MessageKind: string(in.Destination.Kind), RecordingID: in.Destination.RecordingID, + SendingAt: in.SendingAt, Note: in.Note, + }) + } + return nil +} + +func statusHeld(ctx context.Context, tx *sql.Tx, s *Status) error { + rows, err := tx.QueryContext(ctx, ` +SELECT id, event_type, trigger_name, bucket_id, recording_url, reason, generation, updated_at +FROM events WHERE state = 'held' ORDER BY id`) + if err != nil { + return fmt.Errorf("connector: status held records: %w", err) + } + defer func() { _ = rows.Close() }() + s.Held = []HeldStatus{} + for rows.Next() { + var ( + h HeldStatus + updated string + ) + if err := rows.Scan(&h.EventID, &h.EventType, &h.Trigger, &h.BucketID, &h.RecordingURL, &h.Reason, &h.Generation, &updated); err != nil { + return err + } + if h.UpdatedAt, err = parseStamp(updated); err != nil { + return err + } + s.Held = append(s.Held, h) + } + return rows.Err() +} + +func statusDispatches(ctx context.Context, tx *sql.Tx, s *Status) error { + rows, err := tx.QueryContext(ctx, ` +SELECT task_id, id, state, stop_reason, launched_at, ended_at FROM attempts +ORDER BY launched_at DESC, id DESC LIMIT ?`, StatusLimit) + if err != nil { + return fmt.Errorf("connector: status dispatches: %w", err) + } + s.Dispatches = []DispatchStatus{} + for rows.Next() { + var ( + d DispatchStatus + launched string + ended sql.NullString + ) + if err := rows.Scan(&d.TaskID, &d.AttemptID, &d.State, &d.StopReason, &launched, &ended); err != nil { + _ = rows.Close() + return err + } + if d.LaunchedAt, err = parseStamp(launched); err != nil { + _ = rows.Close() + return err + } + if ended.Valid { + at, err := parseStamp(ended.String) + if err != nil { + _ = rows.Close() + return err + } + d.EndedAt = &at + } + s.Dispatches = append(s.Dispatches, d) + } + if err := rows.Close(); err != nil { + return err + } + for i := range s.Dispatches { + events, err := dispatchedEvents(ctx, tx, s.Dispatches[i].TaskID) + if err != nil { + return err + } + s.Dispatches[i].Events = events + } + return nil +} + +func dispatchedEvents(ctx context.Context, tx *sql.Tx, taskID int64) ([]DispatchedEvent, error) { + rows, err := tx.QueryContext(ctx, ` +SELECT event_id, delivery, outcome, COALESCE(reply_id, adopted_reply_id), withdrawn_at IS NOT NULL +FROM task_events WHERE task_id = ? ORDER BY event_id`, taskID) + if err != nil { + return nil, fmt.Errorf("connector: status task %d events: %w", taskID, err) + } + defer func() { _ = rows.Close() }() + out := []DispatchedEvent{} + for rows.Next() { + var ( + e DispatchedEvent + reply sql.NullInt64 + ) + if err := rows.Scan(&e.EventID, &e.Delivery, &e.Outcome, &reply, &e.Withdrawn); err != nil { + return nil, err + } + if reply.Valid { + id := reply.Int64 + e.ReplyID = &id + } + out = append(out, e) + } + return out, rows.Err() +} diff --git a/internal/connector/ledger_tasks.go b/internal/connector/ledger_tasks.go index f6357c6a9..7b99f832b 100644 --- a/internal/connector/ledger_tasks.go +++ b/internal/connector/ledger_tasks.go @@ -429,7 +429,10 @@ func (l *Ledger) joinConversation(ctx context.Context, tx *sql.Tx, taskID int64, // JoinConversation puts the records on a live task's conversation that wait // for a worker onto the task, at delivery admitted, and returns their ids. A -// task that has ended takes none: they start a task of their own. +// task that has ended takes none: they start a task of their own. Nor does a +// task a redispatch superseded while it runs: its worker's token is refused, +// so what joined it could only end unknown. Nor does any task while the hold +// marker stands: joining is a hand-off to a worker (ledger_hold.go). func (l *Ledger) JoinConversation(ctx context.Context, taskID int64) ([]int64, error) { var out []int64 err := retryBusy(func() error { @@ -439,7 +442,8 @@ func (l *Ledger) JoinConversation(ctx context.Context, taskID int64) ([]int64, e } defer func() { _ = tx.Rollback() }() var key, route string - switch err := tx.QueryRowContext(ctx, `SELECT conversation_key, route FROM tasks WHERE id = ? AND ended_at IS NULL`, taskID).Scan(&key, &route); { + switch err := tx.QueryRowContext(ctx, `SELECT conversation_key, route FROM tasks WHERE id = ? AND ended_at IS NULL AND superseded_at IS NULL + AND NOT EXISTS (SELECT 1 FROM hold_marker)`, taskID).Scan(&key, &route); { case errors.Is(err, sql.ErrNoRows): out = nil return nil @@ -520,6 +524,11 @@ func (l *Ledger) ExposeEvent(ctx context.Context, attemptID string, eventID int6 if _, err := tx.ExecContext(ctx, ` UPDATE task_events SET delivery = 'exposed', exposed_at = ?, exposed_attempt_id = ? WHERE task_id = ? AND event_id = ? AND delivery = 'admitted'`, l.timestamp(), attemptID, taskID, eventID); err != nil { + // A hold refuses a first hand-off (ledger_hold.go). That is not a + // failure of the task: nothing more is handed over until release. + if held, holdErr := isHeld(ctx, tx); holdErr == nil && held { + return fmt.Errorf("connector: expose event %d: %w", eventID, ErrHeld) + } return fmt.Errorf("connector: expose event %d: %w", eventID, err) } if err := tx.Commit(); err != nil { @@ -656,6 +665,9 @@ type SettledEvent struct { Withdrawn bool // Blocked is a withdrawal refused a second automatic retry. Blocked bool + // Decided is a record a person has already redispatched or discarded, so + // the completion notice asks nothing of them. + Decided bool } // EndAttempt ends a live attempt with its stop reason, supersedes the task's @@ -890,7 +902,9 @@ WHERE a.state <> 'ended' ORDER BY a.launched_at, a.id`) } // StartableRecords returns up to limit records waiting for a worker, the -// oldest per conversation, oldest first, whatever their route. +// oldest per conversation, oldest first, whatever their route. While the hold +// marker stands there are none: the database would refuse their launch +// (ledger_hold.go). func (l *Ledger) StartableRecords(ctx context.Context, limit int) ([]Record, error) { return l.startable(ctx, "", nil, limit) } @@ -945,6 +959,7 @@ func (l *Ledger) startable(ctx context.Context, extra string, args []any, limit SELECT MIN(e.id) FROM events e WHERE ` + startableCondition + extra + ` AND NOT EXISTS (SELECT 1 FROM tasks t WHERE t.ended_at IS NULL AND t.conversation_key = e.conversation_key) + AND NOT EXISTS (SELECT 1 FROM hold_marker) GROUP BY e.conversation_key ORDER BY MIN(e.id) LIMIT ?` rows, err := l.db.QueryContext(ctx, query, append(args, limit)...) if err != nil { diff --git a/internal/connector/lifecycle.go b/internal/connector/lifecycle.go index 14cd81cff..801ce8d37 100644 --- a/internal/connector/lifecycle.go +++ b/internal/connector/lifecycle.go @@ -73,6 +73,11 @@ func CompletionNeeded(s Settlement) bool { func completionLine(e SettledEvent) string { id := strconv.FormatInt(e.EventID, 10) redispatch := " Needs a person: basecamp connect redispatch " + id + if e.Decided { + // A person already redispatched or discarded it: the notice says what + // happened, and asks for nothing. + redispatch = "" + } switch { case e.Blocked: return "Event " + id + ": the worker could not be started." + redispatch @@ -307,10 +312,19 @@ FROM attempts a JOIN tasks t ON t.id = a.task_id WHERE a.id = ? AND a.state = 'e } s.Stop, s.SpawnFailed, s.OriginatingEventID = StopReason(stop), spawnFailed, originating.Int64 + // Decided is a person's decision this settlement's notice would otherwise + // ask for: the record left the state the notice describes, a redispatch + // waits on it, or an authorization was made strictly after this attempt + // ended. An authorization from before — a redispatch that led to this + // attempt — answered for an earlier outcome, not this one, and a stamp + // equal to the attempt's end is not evidence that it came after: the + // notice asks again, which is the safe direction. rows, err := q.QueryContext(ctx, ` -SELECT te.event_id, te.delivery, te.outcome, te.reply_id, te.withdrawn_at IS NOT NULL, e.state, e.reason +SELECT te.event_id, te.delivery, te.outcome, te.reply_id, te.withdrawn_at IS NOT NULL, e.state, e.reason, + e.state NOT IN ('completed', 'blocked') OR e.redispatch_decision IS NOT NULL + OR COALESCE(e.authorized_at > (SELECT ended_at FROM attempts WHERE id = ?2), 0) FROM task_events te JOIN events e ON e.id = te.event_id -WHERE te.task_id = ? AND (te.withdrawn_at IS NULL OR te.exposed_attempt_id = ?) +WHERE te.task_id = ?1 AND (te.withdrawn_at IS NULL OR te.exposed_attempt_id = ?2) ORDER BY te.event_id`, s.TaskID, attemptID) if err != nil { return Settlement{}, fmt.Errorf("connector: settlement of %s: %w", attemptID, err) @@ -323,7 +337,7 @@ ORDER BY te.event_id`, s.TaskID, attemptID) reason string reply sql.NullInt64 ) - if err := rows.Scan(&e.EventID, &delivery, &outcome, &reply, &e.Withdrawn, &state, &reason); err != nil { + if err := rows.Scan(&e.EventID, &delivery, &outcome, &reply, &e.Withdrawn, &state, &reason, &e.Decided); err != nil { return Settlement{}, fmt.Errorf("connector: settlement of %s: %w", attemptID, err) } switch { diff --git a/internal/connector/lock.go b/internal/connector/lock.go index 4a99c4119..f153542b8 100644 --- a/internal/connector/lock.go +++ b/internal/connector/lock.go @@ -105,3 +105,29 @@ func describeHolder(path string) string { } return fmt.Sprintf("held by pid %d since %s", holder.PID, holder.StartedAt) } + +// InstanceHolderInfo is what a running connector wrote beside its lock. +type InstanceHolderInfo struct { + PID int + StartedAt string +} + +// InstanceHolder reads what a connector holding the lock in dir wrote about +// itself, without taking the lock: status must not make a starting connector +// find its own lock held. It is diagnostic, and can be stale after a crash. +func InstanceHolder(dir, accountID string, agentPersonID int64) (InstanceHolderInfo, bool) { + account, err := strconv.ParseUint(accountID, 10, 64) + if err != nil || account == 0 || agentPersonID <= 0 { + return InstanceHolderInfo{}, false + } + path := filepath.Join(dir, "instance-"+strconv.FormatUint(account, 10)+"-"+strconv.FormatInt(agentPersonID, 10)+".lock.json") + raw, err := os.ReadFile(path) + if err != nil { + return InstanceHolderInfo{}, false + } + var holder instanceHolder + if err := json.Unmarshal(raw, &holder); err != nil || holder.PID <= 0 { + return InstanceHolderInfo{}, false + } + return InstanceHolderInfo{PID: holder.PID, StartedAt: holder.StartedAt}, true +} diff --git a/internal/connector/operator_invariants_test.go b/internal/connector/operator_invariants_test.go new file mode 100644 index 000000000..179f92482 --- /dev/null +++ b/internal/connector/operator_invariants_test.go @@ -0,0 +1,1130 @@ +package connector + +import ( + "context" + "path/filepath" + "strconv" + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + + "github.com/basecamp/basecamp-cli/internal/connector/admission" + "github.com/basecamp/basecamp-cli/internal/connector/driver" +) + +// The operator decisions and the hold (ledger_hold.go). Each test names the +// invariant it holds. + +const ( + opRoute = "/work/connector" + opBy = "local:tester" +) + +// opAdmit writes id seen and commits an admitted verdict on conversation key, +// returning the state the ledger wrote. +func opAdmit(t *testing.T, l *Ledger, id int64, key string) RecordState { + t.Helper() + ctx := context.Background() + record := seenRecord(t, l, id) + v := admittedVerdict(id, record.Revision, key) + v.Route = opRoute + state, err := l.Admission().Commit(ctx, v) + require.NoError(t, err) + return RecordState(state) +} + +func launchOf(t *testing.T, l *Ledger, id int64) Launch { + t.Helper() + launch, err := l.LaunchTask(context.Background(), LaunchSpec{EventID: id, Route: opRoute, Driver: "claude"}) + require.NoError(t, err) + return launch +} + +func stateOf(t *testing.T, l *Ledger, id int64) RecordState { + t.Helper() + return getRecord(t, l, id).State +} + +func decisionsFor(t *testing.T, l *Ledger, id int64) int { + t.Helper() + var n int + require.NoError(t, l.db.QueryRowContext(context.Background(), `SELECT COUNT(*) FROM decisions WHERE event_id = ?`, id).Scan(&n)) + return n +} + +// unknownOutcome takes a fresh record to completed(unknown): launched, running, +// lost. +func unknownOutcome(t *testing.T, l *Ledger, id int64) Launch { + t.Helper() + ctx := context.Background() + require.Equal(t, StateAdmitted, opAdmit(t, l, id, "recording:"+strconv.FormatInt(id, 10))) + launch := launchOf(t, l, id) + require.NoError(t, l.MarkRunning(ctx, launch.AttemptID, AttemptProcess{PID: 4242, PGID: 4242, StartedAt: time.Now()})) + _, err := l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopLost}) + require.NoError(t, err) + require.Equal(t, StateCompleted, stateOf(t, l, id)) + return launch +} + +// Done when: redispatch of completed(unknown) admits the record, supersedes +// the task's token and records who authorized it. +func TestRedispatchAdmitsAnUnknownOutcome(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + launch := unknownOutcome(t, l, 1) + + got, err := l.Redispatch(ctx, 1, opBy) + require.NoError(t, err) + assert.True(t, got.Admitted) + assert.Equal(t, StateAdmitted, got.State) + assert.Equal(t, OutcomeUnknown, got.FromOutcome) + assert.Equal(t, 1, decisionsFor(t, l, 1)) + + var by string + require.NoError(t, l.db.QueryRowContext(context.Background(), `SELECT authorized_by FROM events WHERE id = 1`).Scan(&by)) + assert.Equal(t, opBy, by) + _, err = l.Dispatch(ctx, launch.Token, adapterAgentID) + assert.ErrorIs(t, err, ErrTaskTokenRefused, "the replaced task's token is refused") + + startable, err := l.StartableRecords(ctx, 10) + require.NoError(t, err) + require.Len(t, startable, 1) + second := launchOf(t, l, 1) + assert.NotEqual(t, launch.TaskID, second.TaskID) +} + +// Done when: redispatch of completed(failed) admits it. +func TestRedispatchAdmitsAFailedOutcome(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + require.Equal(t, StateAdmitted, opAdmit(t, l, 1, "recording:1")) + launch := launchOf(t, l, 1) + d, err := l.Dispatch(ctx, launch.Token, adapterAgentID) + require.NoError(t, err) + pulled(t, d, 1) + _, err = d.Complete(ctx, 1, Completion{Outcome: OutcomeFailed}) + require.NoError(t, err) + _, err = l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopFinished}) + require.NoError(t, err) + + got, err := l.Redispatch(ctx, 1, opBy) + require.NoError(t, err) + assert.True(t, got.Admitted) + assert.Equal(t, OutcomeFailed, got.FromOutcome) + assert.Equal(t, StateAdmitted, stateOf(t, l, 1)) +} + +// Invariant 5: an event whose task is still live is not admitted until the +// task ends, so two workers never run for it. +func TestRedispatchOnALiveTaskWaitsForItsEnd(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + require.Equal(t, StateAdmitted, opAdmit(t, l, 1, "recording:9")) + require.Equal(t, StateQueued, opAdmit(t, l, 2, "recording:9")) + launch := launchOf(t, l, 1) + started := time.Now().Add(-time.Minute).UTC() + require.NoError(t, l.MarkRunning(ctx, launch.AttemptID, AttemptProcess{PID: 4242, PGID: 4242, StartedAt: started})) + d, err := l.Dispatch(ctx, launch.Token, adapterAgentID) + require.NoError(t, err) + pulled(t, d, 1) + _, err = d.Complete(ctx, 1, Completion{Outcome: OutcomeFailed}) + require.NoError(t, err) + + got, err := l.Redispatch(ctx, 1, opBy) + require.NoError(t, err) + assert.True(t, got.Pending) + assert.False(t, got.Admitted) + assert.Equal(t, launch.TaskID, got.SupersededTaskID) + require.NotNil(t, got.Worker, "the live worker is handed back to be terminated") + assert.Equal(t, 4242, got.Worker.PGID) + assert.Equal(t, StateCompleted, stateOf(t, l, 1)) + + _, _, err = d.Get(ctx, 2) + assert.ErrorIs(t, err, ErrTaskTokenRefused, "the old worker is refused at once") + _, err = l.LaunchTask(ctx, LaunchSpec{EventID: 1, Route: opRoute, Driver: "claude"}) + assert.ErrorIs(t, err, ErrNotStartable, "no second task while the first is live") + startable, err := l.StartableRecords(ctx, 10) + require.NoError(t, err) + assert.Empty(t, startable) + + _, err = l.Redispatch(ctx, 1, opBy) + assert.ErrorIs(t, err, ErrDecisionRefused, "a second redispatch while the first waits") + + _, err = l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopLost}) + require.NoError(t, err) + assert.Equal(t, StateAdmitted, stateOf(t, l, 1), "admitted in the transaction that ended the task") + var consumed bool + require.NoError(t, l.db.QueryRowContext(context.Background(), `SELECT redispatch_decision IS NULL FROM events WHERE id = 1`).Scan(&consumed)) + assert.True(t, consumed, "the task's end consumed the redispatch") + second := launchOf(t, l, 1) + assert.NotEqual(t, launch.TaskID, second.TaskID) +} + +// Invariant 6: refused for succeeded, discarded and anything live, and a +// refusal writes nothing. +// +//nolint:contextcheck // subtests build their fixtures on background contexts +func TestRedispatchRefusesWhatItMustNotRun(t *testing.T) { + ctx := context.Background() + cases := map[string]func(t *testing.T, l *Ledger){ + "seen": func(t *testing.T, l *Ledger) { seenRecord(t, l, 1) }, + "admitted": func(t *testing.T, l *Ledger) { opAdmit(t, l, 1, "recording:1") }, + "queued": func(t *testing.T, l *Ledger) { + opAdmit(t, l, 7, "recording:1") + require.Equal(t, StateQueued, opAdmit(t, l, 1, "recording:1")) + }, + "dispatched": func(t *testing.T, l *Ledger) { + opAdmit(t, l, 1, "recording:1") + launchOf(t, l, 1) + }, + "discarded": func(t *testing.T, l *Ledger) { + seenRecord(t, l, 1) + require.NoError(t, l.SetState(ctx, 1, StateDiscarded, "untrusted_author")) + }, + "succeeded": func(t *testing.T, l *Ledger) { + opAdmit(t, l, 1, "recording:1") + launch := launchOf(t, l, 1) + d, err := l.Dispatch(ctx, launch.Token, adapterAgentID) + require.NoError(t, err) + pulled(t, d, 1) + _, err = d.Complete(ctx, 1, Completion{Outcome: OutcomeSucceeded}) + require.NoError(t, err) + _, err = l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopFinished}) + require.NoError(t, err) + }, + } + for name, arrange := range cases { + t.Run(name, func(t *testing.T) { + l := newTestLedger(t) + arrange(t, l) + before := getRecord(t, l, 1) + + _, err := l.Redispatch(ctx, 1, opBy) + require.ErrorIs(t, err, ErrDecisionRefused) + after := getRecord(t, l, 1) + assert.Equal(t, before.State, after.State) + assert.Equal(t, before.Revision, after.Revision) + assert.Zero(t, decisionsFor(t, l, 1)) + }) + } +} + +// Done when: a blocked record keeps its state with the authorization +// recorded, and is admitted the moment its prerequisite succeeds. +func TestRedispatchOfABlockedRecordRerunsItsPrerequisite(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + seenRecord(t, l, 1) + _, err := l.Admission().Commit(ctx, blockedVerdict(1, 0, admission.ReasonReadFailed)) + require.NoError(t, err) + // A hold before the redispatch: the authorization is what lets it through. + _, err = l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + + got, err := l.Redispatch(ctx, 1, opBy) + require.NoError(t, err) + assert.True(t, got.Rerun) + assert.True(t, got.Held) + assert.Equal(t, StateBlocked, got.State) + ids, err := l.AuthorizedBlocked(ctx, 10) + require.NoError(t, err) + assert.Equal(t, []int64{1}, ids) + + ev, ok, err := l.Admission().LoadUndecided(ctx, 1) + require.NoError(t, err) + require.True(t, ok) + v := admittedVerdict(1, ev.Revision, "recording:1") + v.Route = opRoute + written, err := l.Admission().Commit(ctx, v) + require.NoError(t, err) + assert.Equal(t, admission.StateAdmitted, written, "authorized, so admitted though tagged for review") + + // Under the hold it is authorized and not launched. + _, err = l.LaunchTask(ctx, LaunchSpec{EventID: 1, Route: opRoute, Driver: "claude"}) + require.Error(t, err) + assert.Contains(t, err.Error(), "held") + _, err = l.Release(ctx, opBy) + require.NoError(t, err) + launchOf(t, l, 1) +} + +// Done when: a held record with its snapshot and route is admitted at once. +func TestRedispatchAdmitsAHeldRecord(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + opAdmit(t, l, 1, "recording:1") + res, err := l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + assert.Equal(t, 1, res.Held) + require.Equal(t, StateHeld, stateOf(t, l, 1)) + + got, err := l.Redispatch(ctx, 1, opBy) + require.NoError(t, err) + assert.True(t, got.Admitted) + assert.Equal(t, StateAdmitted, stateOf(t, l, 1)) +} + +// A held record over a blocking reason runs what blocked it again. +func TestRedispatchOfARecordHeldOverAReasonRerunsIt(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + opAdmit(t, l, 1, "recording:1") + _, err := l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + _, err = l.db.ExecContext(context.Background(), `UPDATE events SET reason = 'no_route' WHERE id = 1`) + require.NoError(t, err) + + got, err := l.Redispatch(ctx, 1, opBy) + require.NoError(t, err) + assert.True(t, got.Rerun) + record := getRecord(t, l, 1) + assert.Equal(t, StateBlocked, record.State) + assert.Equal(t, "no_route", record.Reason) + assert.Nil(t, record.Decision.Snapshot, "a blocked record carries no content") +} + +// Done when: a review-tagged seen record becomes held, not dispatched — and +// the verdict says so, so no guard acknowledgement is called for. +func TestInvariant1AReviewTaggedSeenRecordIsHeldNotDispatched(t *testing.T) { + l := newTestLedger(t) + l.SetHooks(LifecycleHooks(l, LifecycleOptions{})) + ctx := context.Background() + seenRecord(t, l, 1) + _, err := l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + + state := opAdmit(t, l, 1, "recording:1") + assert.Equal(t, StateHeld, state) + assert.Equal(t, StateHeld, stateOf(t, l, 1)) + startable, err := l.StartableRecords(ctx, 10) + require.NoError(t, err) + assert.Empty(t, startable) + intents, err := l.Intents(ctx, IntentFilter{EventID: 1}) + require.NoError(t, err) + assert.Empty(t, intents, "a held record calls for no guard acknowledgement") + + _, err = l.Release(ctx, opBy) + require.NoError(t, err) + assert.Equal(t, StateHeld, stateOf(t, l, 1), "held records stay held on release") + startable, err = l.StartableRecords(ctx, 10) + require.NoError(t, err) + assert.Empty(t, startable) +} + +// Records of the generation a hold opened are not tagged, and dispatch once +// the hold is released. +func TestANewGenerationIsNotTagged(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + _, err := l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + assert.Equal(t, StateAdmitted, opAdmit(t, l, 1, "recording:1")) + _, err = l.Release(ctx, opBy) + require.NoError(t, err) + launchOf(t, l, 1) +} + +// Invariant 1, for every path to admitted: a tagged sibling a task's end +// returns is held. +func TestInvariant1ATaggedSiblingReturnedByATaskIsHeld(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + opAdmit(t, l, 1, "recording:9") + require.Equal(t, StateQueued, opAdmit(t, l, 2, "recording:9")) + launch := launchOf(t, l, 1) + _, err := l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + require.Equal(t, StateDispatched, stateOf(t, l, 2)) + + settlement, err := l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopShutdown}) + require.NoError(t, err) + require.Len(t, settlement.Events, 2) + assert.True(t, settlement.Events[1].Returned) + assert.Equal(t, StateHeld, stateOf(t, l, 2)) +} + +// Invariant 1, at the database: any write of admitted onto a tagged, +// unauthorized record lands held. +func TestInvariant1TheDatabaseHoldsATaggedRecord(t *testing.T) { + l := newTestLedger(t) + opAdmit(t, l, 1, "recording:1") + _, err := l.db.ExecContext(context.Background(), `UPDATE events SET state = 'blocked', reason = 'x' WHERE id = 1`) + require.NoError(t, err) + _, err = l.db.ExecContext(context.Background(), `UPDATE events SET review = 1 WHERE id = 1`) + require.NoError(t, err) + _, err = l.db.ExecContext(context.Background(), `UPDATE events SET state = 'admitted', reason = '' WHERE id = 1`) + require.NoError(t, err) + assert.Equal(t, StateHeld, stateOf(t, l, 1)) +} + +// Done when: a held ledger survives restart until release, and the database +// refuses a launch while it stands. +func TestInvariant2AHeldLedgerSurvivesRestartUntilRelease(t *testing.T) { + path := filepath.Join(t.TempDir(), "state", LedgerFile) + ctx := context.Background() + l, err := OpenLedger(path) + require.NoError(t, err) + _, err = l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + require.NoError(t, l.Close()) + + l, err = OpenLedger(path) + require.NoError(t, err) + t.Cleanup(func() { _ = l.Close() }) + held, err := l.Held(ctx) + require.NoError(t, err) + assert.True(t, held) + // A record of the new generation, which a person need not review, still + // does not launch while the marker stands. + assert.Equal(t, StateAdmitted, opAdmit(t, l, 1, "recording:1")) + startable, err := l.StartableRecords(ctx, 10) + require.NoError(t, err) + assert.Empty(t, startable, "the dispatcher is offered nothing while the hold stands") + _, err = l.LaunchTask(ctx, LaunchSpec{EventID: 1, Route: opRoute, Driver: "claude"}) + require.Error(t, err) + assert.Equal(t, StateAdmitted, stateOf(t, l, 1), "the refused launch rolled back") + + released, err := l.Release(ctx, opBy) + require.NoError(t, err) + assert.True(t, released.Released) + held, err = l.Held(ctx) + require.NoError(t, err) + assert.False(t, held) + launchOf(t, l, 1) +} + +// Invariant 2: nothing moves to sending under the hold. +func TestInvariant2NothingIsPostedUnderTheHold(t *testing.T) { + l := newTestLedger(t) + l.SetHooks(LifecycleHooks(l, LifecycleOptions{})) + ctx := context.Background() + seenRecord(t, l, 1) + v := blockedVerdict(1, 0, admission.ReasonNoRoute) + v.Trigger, v.Acknowledge = admission.TriggerMentioned, true + v.Reply = &admission.ReplyDestination{Kind: admission.ReplyComment, RecordingID: 10304028989} + _, err := l.Admission().Commit(ctx, v) + require.NoError(t, err) + pending, err := l.Intents(ctx, IntentFilter{States: []IntentState{IntentPending}}) + require.NoError(t, err) + require.Len(t, pending, 1) + + _, err = l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + _, _, err = l.claimIntent(ctx) + require.Error(t, err) + assert.Contains(t, err.Error(), "held") + + _, err = l.Release(ctx, opBy) + require.NoError(t, err) + claimed, ok, err := l.claimIntent(ctx) + require.NoError(t, err) + require.True(t, ok) + assert.Equal(t, IntentSending, claimed.State) +} + +// A held record's pending guard acknowledgement is not sent later. +func TestHoldingARecordCancelsItsPendingGuard(t *testing.T) { + l := newTestLedger(t) + l.SetHooks(LifecycleHooks(l, LifecycleOptions{})) + ctx := context.Background() + opAdmit(t, l, 1, "recording:1") + guards, err := l.Intents(ctx, IntentFilter{Kinds: []IntentKind{IntentGuardAck}, States: []IntentState{IntentPending}}) + require.NoError(t, err) + require.Len(t, guards, 1) + + _, err = l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + guard, err := l.Intent(ctx, guards[0].ID) + require.NoError(t, err) + assert.Equal(t, IntentCanceled, guard.State) +} + +// Invariant 4: a terminal record leaves its state only with a decision +// written in the same statement. +// +//nolint:contextcheck // subtests build their fixtures on background contexts +func TestInvariant4TheDatabaseRefusesATerminalMoveWithoutADecision(t *testing.T) { + ctx := context.Background() + t.Run("completed to admitted without a redispatch", func(t *testing.T) { + l := newTestLedger(t) + unknownOutcome(t, l, 1) + _, err := l.db.ExecContext(ctx, `UPDATE events SET state = 'admitted' WHERE id = 1`) + require.Error(t, err) + assert.Contains(t, err.Error(), "terminal") + }) + t.Run("a redispatch of a success", func(t *testing.T) { + l := newTestLedger(t) + unknownOutcome(t, l, 1) + decision := rawDecision(t, l, 1, "redispatch", "9999-01-01T00:00:00.000000000Z") + _, err := l.db.ExecContext(ctx, `UPDATE task_events SET outcome = 'succeeded' WHERE event_id = 1`) + require.NoError(t, err) + _, err = l.db.ExecContext(ctx, `UPDATE events SET redispatch_decision = ? WHERE id = 1`, decision) + require.NoError(t, err) + _, err = l.db.ExecContext(ctx, `UPDATE events SET state = 'admitted', redispatch_decision = NULL WHERE id = 1`) + require.Error(t, err) + }) + t.Run("a redispatch naming another event's decision", func(t *testing.T) { + l := newTestLedger(t) + unknownOutcome(t, l, 1) + seenRecord(t, l, 2) + decision := rawDecision(t, l, 2, "redispatch", "9999-01-01T00:00:00.000000000Z") + _, err := l.db.ExecContext(ctx, `UPDATE events SET redispatch_decision = ? WHERE id = 1`, decision) + require.NoError(t, err) + _, err = l.db.ExecContext(ctx, `UPDATE events SET state = 'admitted', redispatch_decision = NULL WHERE id = 1`) + require.Error(t, err) + }) + t.Run("a redispatch decided before the outcome settled", func(t *testing.T) { + l := newTestLedger(t) + unknownOutcome(t, l, 1) + decision := rawDecision(t, l, 1, "redispatch", "2000-01-01T00:00:00.000000000Z") + _, err := l.db.ExecContext(ctx, `UPDATE events SET redispatch_decision = ? WHERE id = 1`, decision) + require.NoError(t, err) + _, err = l.db.ExecContext(ctx, `UPDATE events SET state = 'admitted', redispatch_decision = NULL WHERE id = 1`) + require.Error(t, err) + }) + t.Run("a discard with no decision", func(t *testing.T) { + l := newTestLedger(t) + unknownOutcome(t, l, 1) + // Decisions that are not this record's discard do not stand in for one. + seenRecord(t, l, 2) + rawDecision(t, l, 2, "discard", "9999-01-01T00:00:00.000000000Z") + rawDecision(t, l, 1, "redispatch", "9999-01-01T00:00:00.000000000Z") + _, err := l.db.ExecContext(ctx, `UPDATE events SET state = 'discarded', reason = 'by_operator' WHERE id = 1`) + require.Error(t, err) + }) + t.Run("a discard decided before the outcome settled", func(t *testing.T) { + l := newTestLedger(t) + unknownOutcome(t, l, 1) + rawDecision(t, l, 1, "discard", "2000-01-01T00:00:00.000000000Z") + _, err := l.db.ExecContext(ctx, `UPDATE events SET state = 'discarded', reason = 'by_operator' WHERE id = 1`) + require.Error(t, err) + }) + t.Run("discarded never leaves", func(t *testing.T) { + l := newTestLedger(t) + seenRecord(t, l, 1) + require.NoError(t, l.SetState(ctx, 1, StateDiscarded, ReasonByOperator)) + decision := rawDecision(t, l, 1, "redispatch", "9999-01-01T00:00:00.000000000Z") + _, err := l.db.ExecContext(ctx, `UPDATE events SET redispatch_decision = ? WHERE id = 1`, decision) + require.NoError(t, err) + _, err = l.db.ExecContext(ctx, `UPDATE events SET state = 'admitted', redispatch_decision = NULL WHERE id = 1`) + require.Error(t, err) + }) + t.Run("an unknown outcome discarded for another reason", func(t *testing.T) { + l := newTestLedger(t) + unknownOutcome(t, l, 1) + rawDecision(t, l, 1, "discard", "9999-01-01T00:00:00.000000000Z") + _, err := l.db.ExecContext(ctx, `UPDATE events SET state = 'discarded', reason = 'untrusted_author' WHERE id = 1`) + require.Error(t, err) + }) +} + +// Done when: discard closes held, blocked and unknown records as +// discarded(by_operator), and refuses the rest. +// +//nolint:contextcheck // subtests build their fixtures on background contexts +func TestDiscard(t *testing.T) { + ctx := context.Background() + accepted := map[string]func(t *testing.T, l *Ledger){ + "held": func(t *testing.T, l *Ledger) { + opAdmit(t, l, 1, "recording:1") + _, err := l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + }, + "blocked": func(t *testing.T, l *Ledger) { + seenRecord(t, l, 1) + _, err := l.Admission().Commit(ctx, blockedVerdict(1, 0, admission.ReasonReadFailed)) + require.NoError(t, err) + }, + "unknown": func(t *testing.T, l *Ledger) { unknownOutcome(t, l, 1) }, + } + for name, arrange := range accepted { + t.Run(name, func(t *testing.T) { + l := newTestLedger(t) + arrange(t, l) + got, err := l.Discard(ctx, 1, opBy) + require.NoError(t, err) + assert.False(t, got.Already) + record := getRecord(t, l, 1) + assert.Equal(t, StateDiscarded, record.State) + assert.Equal(t, ReasonByOperator, record.Reason) + assert.Equal(t, 1, decisionsFor(t, l, 1)) + + again, err := l.Discard(ctx, 1, opBy) + require.NoError(t, err) + assert.True(t, again.Already) + _, err = l.Redispatch(ctx, 1, opBy) + assert.ErrorIs(t, err, ErrDecisionRefused) + }) + } + refused := map[string]func(t *testing.T, l *Ledger){ + "seen": func(t *testing.T, l *Ledger) { seenRecord(t, l, 1) }, + "admitted": func(t *testing.T, l *Ledger) { opAdmit(t, l, 1, "recording:1") }, + "dispatched": func(t *testing.T, l *Ledger) { + opAdmit(t, l, 1, "recording:1") + launchOf(t, l, 1) + }, + "failed": func(t *testing.T, l *Ledger) { + opAdmit(t, l, 1, "recording:1") + launch := launchOf(t, l, 1) + d, err := l.Dispatch(ctx, launch.Token, adapterAgentID) + require.NoError(t, err) + pulled(t, d, 1) + _, err = d.Complete(ctx, 1, Completion{Outcome: OutcomeFailed}) + require.NoError(t, err) + }, + "discarded by admission": func(t *testing.T, l *Ledger) { + seenRecord(t, l, 1) + require.NoError(t, l.SetState(ctx, 1, StateDiscarded, "untrusted_author")) + }, + } + for name, arrange := range refused { + t.Run("refuses "+name, func(t *testing.T) { + l := newTestLedger(t) + arrange(t, l) + before := getRecord(t, l, 1) + _, err := l.Discard(ctx, 1, opBy) + require.ErrorIs(t, err, ErrDecisionRefused) + assert.Equal(t, before.State, stateOf(t, l, 1)) + assert.Zero(t, decisionsFor(t, l, 1)) + }) + } +} + +// A discard cancels the lifecycle messages still pending for the record. +func TestDiscardCancelsAPendingHoldingReply(t *testing.T) { + l := newTestLedger(t) + l.SetHooks(LifecycleHooks(l, LifecycleOptions{})) + ctx := context.Background() + seenRecord(t, l, 1) + v := blockedVerdict(1, 0, admission.ReasonNoRoute) + v.Trigger, v.Acknowledge = admission.TriggerMentioned, true + v.Reply = &admission.ReplyDestination{Kind: admission.ReplyComment, RecordingID: 10304028989} + _, err := l.Admission().Commit(ctx, v) + require.NoError(t, err) + + got, err := l.Discard(ctx, 1, opBy) + require.NoError(t, err) + assert.Equal(t, 1, got.Canceled) + pending, err := l.Intents(ctx, IntentFilter{States: []IntentState{IntentPending}}) + require.NoError(t, err) + assert.Empty(t, pending) +} + +// rawDecision writes a decisions row directly, as something other than this +// package could. +func rawDecision(t *testing.T, l *Ledger, eventID int64, action, at string) int64 { + t.Helper() + res, err := l.db.ExecContext(context.Background(), `INSERT INTO decisions (action, event_id, decided_by, decided_at) VALUES (?, ?, 'raw', ?)`, action, eventID, at) + require.NoError(t, err) + id, err := res.LastInsertId() + require.NoError(t, err) + return id +} + +// pulled hands the worker its dispatch for eventID, as a real worker does +// before it acknowledges or completes: a record is exposed at launch, but the +// ledger refuses an acknowledgement or a completion until the worker has +// pulled it. +func pulled(t *testing.T, d *TaskDispatch, eventID int64) { + t.Helper() + _, ok, err := d.Get(context.Background(), eventID) + require.NoError(t, err) + require.True(t, ok, "the worker is handed event %d", eventID) +} + +// pendingRedispatch leaves event 1 completed(failed) on a live task with a +// redispatch waiting for the task to end, and returns the task's launch. +func pendingRedispatch(t *testing.T, l *Ledger) Launch { + t.Helper() + ctx := context.Background() + require.Equal(t, StateAdmitted, opAdmit(t, l, 1, "recording:9")) + launch := launchOf(t, l, 1) + d, err := l.Dispatch(ctx, launch.Token, adapterAgentID) + require.NoError(t, err) + pulled(t, d, 1) + _, err = d.Complete(ctx, 1, Completion{Outcome: OutcomeFailed}) + require.NoError(t, err) + got, err := l.Redispatch(ctx, 1, opBy) + require.NoError(t, err) + require.True(t, got.Pending) + return launch +} + +// Retention never strands a waiting redispatch: the record keeps what its +// admission needs, and the task's end is never refused. +func TestRetentionKeepsARecordAWaitingRedispatchNeeds(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + launch := pendingRedispatch(t, l) + dropped, err := l.DropContent(ctx, time.Now().Add(24*time.Hour), time.Now().Add(24*time.Hour)) + require.NoError(t, err) + assert.Zero(t, dropped) + + _, err = l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopLost}) + require.NoError(t, err) + assert.Equal(t, StateAdmitted, stateOf(t, l, 1)) +} + +// A task's end never fails for a waiting redispatch whose record cannot be +// admitted: it stays completed. +func TestATaskEndIsNeverRefusedForAWaitingRedispatch(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + launch := pendingRedispatch(t, l) + _, err := l.db.ExecContext(ctx, `UPDATE events SET content_dropped = 1, snapshot = NULL WHERE id = 1`) + require.NoError(t, err) + + _, err = l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopLost}) + require.NoError(t, err) + assert.Equal(t, StateCompleted, stateOf(t, l, 1)) +} + +// Invariant 3: a hold withdraws a redispatch still waiting for its task. +func TestInvariant3AHoldWithdrawsAWaitingRedispatch(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + launch := pendingRedispatch(t, l) + _, err := l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + + _, err = l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopLost}) + require.NoError(t, err) + assert.Equal(t, StateCompleted, stateOf(t, l, 1), "the authorization did not survive the hold") + _, err = l.Redispatch(ctx, 1, opBy) + require.NoError(t, err, "a person can authorize it again") +} + +// An import withdraws a waiting redispatch, whether the file says the entry is +// done or does not name it. +func TestImportWithdrawsAWaitingRedispatch(t *testing.T) { + for name, c := range map[string]struct { + entries []ReconciliationEntry + want RecordState + }{ + "done": {entries: []ReconciliationEntry{{EventID: 1, Decision: DecisionDone}}, want: StateDiscarded}, + "unnamed": {want: StateCompleted}, + } { + t.Run(name, func(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + launch := pendingRedispatch(t, l) + _, err := l.Import(ctx, Reconciliation{Version: 1, Entries: c.entries}, opBy) + require.NoError(t, err) + + _, err = l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopLost}) + require.NoError(t, err) + assert.Equal(t, c.want, stateOf(t, l, 1), "never admitted by the withdrawn redispatch") + }) + } +} + +// A task a redispatch superseded while it runs takes no follow-up: the event +// waits for the task to end and starts its own. +func TestASupersededTaskTakesNoFollowUp(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + launch := pendingRedispatch(t, l) + require.Equal(t, StateAdmitted, opAdmit(t, l, 2, "recording:9"), "the conversation's task is superseded, so a new event is admitted") + + joined, err := l.JoinConversation(ctx, launch.TaskID) + require.NoError(t, err) + assert.Empty(t, joined) + _, err = l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopLost}) + require.NoError(t, err) + startable, err := l.StartableRecords(ctx, 10) + require.NoError(t, err) + require.Len(t, startable, 1) + second := launchOf(t, l, 1) + assert.ElementsMatch(t, []int64{1, 2}, second.EventIDs) +} + +// A held record redispatched onto a live conversation is queued, as admission +// would write it. +func TestRedispatchQueuesAHeldRecordBehindALiveConversation(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + opAdmit(t, l, 1, "recording:9") + _, err := l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + require.Equal(t, StateAdmitted, opAdmit(t, l, 2, "recording:9"), "a new generation's record on the same conversation") + + got, err := l.Redispatch(ctx, 1, opBy) + require.NoError(t, err) + assert.Equal(t, StateQueued, got.State) + assert.False(t, got.Admitted) +} + +// A completion notice asks nothing of a person who has already decided the +// record: the notice says what happened, and no more. +func TestACompletionNoticeAsksNothingOfADecidedRecord(t *testing.T) { + l := newTestLedger(t) + l.SetHooks(LifecycleHooks(l, LifecycleOptions{})) + ctx := context.Background() + launch := pendingRedispatch(t, l) + + _, err := l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopLost}) + require.NoError(t, err) + intents, err := l.Intents(ctx, IntentFilter{Kinds: []IntentKind{IntentCompletion}}) + require.NoError(t, err) + require.Len(t, intents, 1) + assert.Contains(t, intents[0].Body, "Event 1: failed") + assert.NotContains(t, intents[0].Body, "redispatch 1", "a person already redispatched it") +} + +// An import that closes a record does not leave it a lifecycle message that +// asks for a redispatch the ledger would refuse. +func TestImportCancelsTheMessagesOfARecordItCloses(t *testing.T) { + l := newTestLedger(t) + l.SetHooks(LifecycleHooks(l, LifecycleOptions{})) + ctx := context.Background() + seenRecord(t, l, 1) + v := blockedVerdict(1, 0, admission.ReasonNoRoute) + v.Trigger, v.Acknowledge = admission.TriggerMentioned, true + v.Reply = &admission.ReplyDestination{Kind: admission.ReplyComment, RecordingID: 10304028989} + _, err := l.Admission().Commit(ctx, v) + require.NoError(t, err) + + _, err = l.Import(ctx, Reconciliation{Version: 1, Entries: []ReconciliationEntry{{EventID: 1, Decision: DecisionDone}}}, opBy) + require.NoError(t, err) + pending, err := l.Intents(ctx, IntentFilter{States: []IntentState{IntentPending}}) + require.NoError(t, err) + assert.Empty(t, pending, "nothing is posted about a record a person closed") +} + +// A completion notice waiting in the outbox is rendered again when it is +// claimed: a record a person decided in between asks nothing of them. +func TestACompletionNoticeIsRenderedAgainWhenItIsClaimed(t *testing.T) { + l := newTestLedger(t) + l.SetHooks(LifecycleHooks(l, LifecycleOptions{})) + ctx := context.Background() + opAdmit(t, l, 1, "recording:1") + launch := launchOf(t, l, 1) + _, err := l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopLost}) + require.NoError(t, err) + notices, err := l.Intents(ctx, IntentFilter{Kinds: []IntentKind{IntentCompletion}}) + require.NoError(t, err) + require.Len(t, notices, 1) + require.Contains(t, notices[0].Body, "redispatch 1") + + _, err = l.Discard(ctx, 1, opBy) + require.NoError(t, err) + claimed, ok, err := l.claimIntent(ctx) + require.NoError(t, err) + require.True(t, ok) + assert.Equal(t, IntentSending, claimed.State) + assert.Contains(t, claimed.Body, "Event 1: unknown") + assert.NotContains(t, claimed.Body, "redispatch 1", "a person already decided it") +} + +// Invariant 2, at the database: a task takes no follow-up while the hold +// marker stands, however the hold arrived. +func TestInvariant2ATaskTakesNoFollowUpUnderTheHold(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + opAdmit(t, l, 1, "recording:9") + launch := launchOf(t, l, 1) + _, err := l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + require.Equal(t, StateQueued, opAdmit(t, l, 2, "recording:9"), "a new generation's record on the live conversation") + + joined, err := l.JoinConversation(ctx, launch.TaskID) + require.NoError(t, err) + assert.Empty(t, joined) + assert.Equal(t, StateQueued, stateOf(t, l, 2)) +} + +// A record a person authorized is decided too, though it stays blocked until +// its prerequisite runs: the notice claimed meanwhile asks nothing more. +func TestACompletionNoticeAsksNothingOfAnAuthorizedBlockedRecord(t *testing.T) { + l := newTestLedger(t) + l.SetHooks(LifecycleHooks(l, LifecycleOptions{})) + ctx := context.Background() + opAdmit(t, l, 1, "recording:1") + for range 2 { + launch := launchOf(t, l, 1) + _, err := l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopFailed, SpawnFailed: true}) + require.NoError(t, err) + } + require.Equal(t, StateBlocked, stateOf(t, l, 1)) + notices, err := l.Intents(ctx, IntentFilter{Kinds: []IntentKind{IntentCompletion}}) + require.NoError(t, err) + require.Len(t, notices, 1) + require.Contains(t, notices[0].Body, "redispatch 1") + + got, err := l.Redispatch(ctx, 1, opBy) + require.NoError(t, err) + require.True(t, got.Rerun) + claimed, ok, err := l.claimIntent(ctx) + require.NoError(t, err) + require.True(t, ok) + assert.NotContains(t, claimed.Body, "redispatch 1") +} + +// An authorization answers for the outcome it was made on. When the attempt it +// led to ends unknown again, or cannot start, the notice asks again. +func TestAnEarlierAuthorizationDoesNotSilenceALaterNotice(t *testing.T) { + for name, second := range map[string]func(t *testing.T, l *Ledger){ + "unknown again": func(t *testing.T, l *Ledger) { + launch := launchOf(t, l, 1) + _, err := l.EndAttempt(context.Background(), AttemptEnd{AttemptID: launch.AttemptID, Stop: StopLost}) + require.NoError(t, err) + }, + "blocked on its start": func(t *testing.T, l *Ledger) { + for range 2 { + launch := launchOf(t, l, 1) + _, err := l.EndAttempt(context.Background(), AttemptEnd{AttemptID: launch.AttemptID, Stop: StopFailed, SpawnFailed: true}) + require.NoError(t, err) + } + ids, err := l.AuthorizedBlocked(context.Background(), 10) + require.NoError(t, err) + assert.Empty(t, ids, "the old authorization does not stand for the new block") + }, + } { + t.Run(name, func(t *testing.T) { + l := newTestLedger(t) + l.SetHooks(LifecycleHooks(l, LifecycleOptions{})) + ctx := context.Background() + first := unknownOutcome(t, l, 1) + _, err := l.Redispatch(ctx, 1, opBy) + require.NoError(t, err) + second(t, l) + + notices, err := l.Intents(ctx, IntentFilter{Kinds: []IntentKind{IntentCompletion}}) + require.NoError(t, err) + var latest Intent + for _, n := range notices { + if n.AttemptID != first.AttemptID { + latest = n + break + } + } + require.NotZero(t, latest.ID) + assert.Contains(t, latest.Body, "redispatch 1", "a person is asked again") + }) + } +} + +// An import's done decision closes an unknown or failed outcome for good: no +// redispatch is accepted for it and no notice asks for one. A success stays +// as it was. +func TestImportDoneClosesAnOutcomeThatWaitedForAPerson(t *testing.T) { + l := newTestLedger(t) + l.SetHooks(LifecycleHooks(l, LifecycleOptions{})) + ctx := context.Background() + unknownOutcome(t, l, 1) + opAdmit(t, l, 2, "recording:2") + launch := launchOf(t, l, 2) + d, err := l.Dispatch(ctx, launch.Token, adapterAgentID) + require.NoError(t, err) + pulled(t, d, 2) + reply := int64(77) + _, err = d.Complete(ctx, 2, Completion{Outcome: OutcomeSucceeded, ReplyID: &reply}) + require.NoError(t, err) + _, err = l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopFinished}) + require.NoError(t, err) + + got, err := l.Import(ctx, Reconciliation{Version: 1, Entries: []ReconciliationEntry{ + {EventID: 1, Decision: DecisionDone}, {EventID: 2, Decision: DecisionDone}, + }}, opBy) + require.NoError(t, err) + assert.Equal(t, 1, got.Tombstoned) + assert.Equal(t, 1, got.AlreadyTerminal) + + one := getRecord(t, l, 1) + assert.Equal(t, StateDiscarded, one.State) + assert.Equal(t, ReasonImportedDone, one.Reason) + assert.Equal(t, StateCompleted, stateOf(t, l, 2)) + var recordedAs string + require.NoError(t, l.db.QueryRowContext(ctx, `SELECT to_state FROM decisions WHERE event_id = 2 AND action = 'import'`).Scan(&recordedAs)) + assert.Equal(t, string(StateCompleted), recordedAs, "the audit says what happened, not what would have") + _, err = l.Redispatch(ctx, 1, opBy) + assert.ErrorIs(t, err, ErrDecisionRefused) + claimed, ok, err := l.claimIntent(ctx) + require.NoError(t, err) + if ok { + assert.NotContains(t, claimed.Body, "redispatch 1") + } +} + +// A record held over a blocking reason and redispatched is authorized for the +// block that redispatch put it in, though the move stamps the block after the +// authorization's own time was taken. +func TestARedispatchOntoBlockedIsAuthorizedForThatBlock(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + opAdmit(t, l, 1, "recording:1") + _, err := l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + _, err = l.db.ExecContext(ctx, `UPDATE events SET reason = 'no_route' WHERE id = 1`) + require.NoError(t, err) + base := time.Now() + calls := 0 + l.now = func() time.Time { calls++; return base.Add(time.Duration(calls) * time.Second) } // each stamp later than the last + + _, err = l.Redispatch(ctx, 1, opBy) + require.NoError(t, err) + ids, err := l.AuthorizedBlocked(ctx, 10) + require.NoError(t, err) + assert.Equal(t, []int64{1}, ids) +} + +// A person who redispatches and then discards the same record has decided +// twice: the discard stands, and the redispatch waiting for the task's end is +// withdrawn with it. +func TestADiscardWithdrawsARedispatchWaitingForItsTask(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + launch := pendingRedispatch(t, l) + _, err := l.db.ExecContext(ctx, `UPDATE task_events SET outcome = 'unknown' WHERE event_id = 1`) + require.NoError(t, err) + + _, err = l.Discard(ctx, 1, opBy) + require.NoError(t, err) + _, err = l.EndAttempt(ctx, AttemptEnd{AttemptID: launch.AttemptID, Stop: StopLost}) + require.NoError(t, err) + record := getRecord(t, l, 1) + assert.Equal(t, StateDiscarded, record.State, "the task's end does not reopen what a person closed") + assert.Equal(t, ReasonByOperator, record.Reason) + var waiting bool + require.NoError(t, l.db.QueryRowContext(ctx, `SELECT redispatch_decision IS NOT NULL FROM events WHERE id = 1`).Scan(&waiting)) + assert.False(t, waiting, "the authorization went with the record") +} + +// A canceled guard is finished like every other intent the ledger closes. +func TestAHeldRecordsCanceledGuardIsFinished(t *testing.T) { + l := newTestLedger(t) + l.SetHooks(LifecycleHooks(l, LifecycleOptions{})) + ctx := context.Background() + opAdmit(t, l, 1, "recording:1") + guards, err := l.Intents(ctx, IntentFilter{Kinds: []IntentKind{IntentGuardAck}}) + require.NoError(t, err) + require.Len(t, guards, 1) + + _, err = l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + guard, err := l.Intent(ctx, guards[0].ID) + require.NoError(t, err) + assert.Equal(t, IntentCanceled, guard.State) + assert.NotNil(t, guard.FinishedAt, "a canceled intent says when it was finished") +} + +// Invariant 2, for the worker a crashed connector left running: while the hold +// stands, get_dispatch hands out nothing it had not already handed out. +func TestInvariant2AWorkerIsHandedNothingNewUnderTheHold(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + opAdmit(t, l, 1, "recording:9") + require.Equal(t, StateQueued, opAdmit(t, l, 2, "recording:9")) + launch := launchOf(t, l, 1) + d, err := l.Dispatch(ctx, launch.Token, adapterAgentID) + require.NoError(t, err) + first, ok, err := d.Get(ctx, 1) + require.NoError(t, err) + require.True(t, ok) + + _, err = l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + + // The instruction it already holds is answered again; the sibling it never + // pulled is not handed over. + repeat, ok, err := d.Get(ctx, 1) + require.NoError(t, err) + require.True(t, ok) + assert.Equal(t, first.EventID, repeat.EventID) + _, _, err = d.Get(ctx, 2) + require.Error(t, err) + assert.Contains(t, err.Error(), "held") + _, err = l.ExposeEvent(ctx, launch.AttemptID, 2) + require.Error(t, err) + assert.Contains(t, err.Error(), "held") + + _, err = l.Release(ctx, opBy) + require.NoError(t, err) + _, ok, err = d.Get(ctx, 2) + require.NoError(t, err) + assert.True(t, ok, "released, the follow-up is handed over") +} + +// A hold arriving mid-task is not a failure of that task: the exposure is +// refused as held, and the dispatcher's follow-up loop stops asking. +func TestAHoldRefusesAnExposureAsHeldNotAsAFailure(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + opAdmit(t, l, 1, "recording:9") + require.Equal(t, StateQueued, opAdmit(t, l, 2, "recording:9")) + launch := launchOf(t, l, 1) + _, err := l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + + _, err = l.ExposeEvent(ctx, launch.AttemptID, 2) + require.ErrorIs(t, err, ErrHeld) +} + +// Through the dispatcher: a hold that lands while a task runs withholds the +// next instruction and lets the task finish, rather than failing it. +// +//nolint:contextcheck // the harness builds its fixtures on background contexts +func TestAHoldWithholdsTheNextInstructionWithoutFailingTheTask(t *testing.T) { + ctx := context.Background() + release := make(chan struct{}) + fake := newFakeDriver() + var h *dispatchHarness + fake.turn = func(_ *fakeSession, n int, _ string) (driver.PromptResult, error) { + if n == 1 { + <-release + } + return driver.PromptResult{Stop: driver.TurnEndTurn}, nil + } + h = newDispatchHarness(t, fake, nil) + opAdmit(t, h.ledger, 1, "recording:1") + h.run(t) + s := <-fake.made + opAdmit(t, h.ledger, 2, "recording:1") + require.Eventually(t, func() bool { + var n int + _ = h.ledger.db.QueryRowContext(ctx, `SELECT COUNT(*) FROM task_events WHERE event_id = 2`).Scan(&n) + return n == 1 + }, 5*time.Second, 10*time.Millisecond, "the follow-up joined the task") + + _, err := h.ledger.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + close(release) + + rows := h.attemptsEnded(t, 1) + assert.Equal(t, "finished", rows[0].StopReason, "a held connector is not a failed task") + assert.Len(t, s.promptList(), 1, "nothing more was handed over") + assert.Equal(t, StateHeld, stateOf(t, h.ledger, 2), "the follow-up waits for a person") +} + +// Invariant 2: an event the launch exposed carries only a pointer until a +// worker pulls its instruction, so the hold refuses that first pull too — +// the case a crash during launch and a restart under --hold leaves behind. +func TestInvariant2AFirstPullIsRefusedUnderTheHold(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + opAdmit(t, l, 1, "recording:1") + launch := launchOf(t, l, 1) + d, err := l.Dispatch(ctx, launch.Token, adapterAgentID) + require.NoError(t, err) + _, err = l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + + _, _, err = d.Get(ctx, 1) + require.ErrorIs(t, err, ErrHeld, "the instruction is not handed over under the hold") + + _, err = l.Release(ctx, opBy) + require.NoError(t, err) + first, ok, err := d.Get(ctx, 1) + require.NoError(t, err) + require.True(t, ok) + + // Pulled once, a repeat is answered even if a hold lands after it. + _, err = l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + repeat, ok, err := d.Get(ctx, 1) + require.NoError(t, err) + require.True(t, ok) + assert.Equal(t, first.EventID, repeat.EventID) +} diff --git a/internal/connector/operator_migration_test.go b/internal/connector/operator_migration_test.go new file mode 100644 index 000000000..2ccb12b22 --- /dev/null +++ b/internal/connector/operator_migration_test.go @@ -0,0 +1,451 @@ +//go:build unix + +package connector + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "os" + "os/exec" + "path/filepath" + "strconv" + "strings" + "syscall" + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// Shadow promote and import (invariant 7), with a real process killed at every +// step. + +const ( + opAccount = "2914079" + opAgent = adapterAgentID +) + +// shadowFixture is a shadow state directory whose ledger holds an admitted +// record (1), a seen record (2), a blocked record (3) and a discarded one (4), +// and the empty normal state directory beside it. +func shadowFixture(t *testing.T) (shadowDir, stateDir string) { + t.Helper() + root := filepath.Join(t.TempDir(), "basecamp") + shadowDir = filepath.Join(root, "connect-shadow", StateDirName(opAccount, opAgent)) + stateDir = filepath.Join(root, "connect", StateDirName(opAccount, opAgent)) + for _, dir := range []string{root, filepath.Dir(shadowDir), filepath.Dir(stateDir)} { + require.NoError(t, os.MkdirAll(dir, 0o700)) + require.NoError(t, os.Chmod(dir, 0o700)) + } + l, err := OpenLedger(filepath.Join(shadowDir, LedgerFile)) + require.NoError(t, err) + ctx := context.Background() + opAdmit(t, l, 1, "recording:1") + seenRecord(t, l, 2) + seenRecord(t, l, 3) + _, err = l.Admission().Commit(ctx, blockedVerdict(3, 0, "read_failed")) + require.NoError(t, err) + seenRecord(t, l, 4) + require.NoError(t, l.SetState(ctx, 4, StateDiscarded, "untrusted_author")) + require.NoError(t, l.Close()) + return shadowDir, stateDir +} + +func promoteOptions(shadowDir, stateDir string) PromoteOptions { + return PromoteOptions{ShadowDir: shadowDir, StateDir: stateDir, AccountID: opAccount, AgentID: opAgent, By: opBy} +} + +// Done when: shadow promote yields a held ledger at the normal path, with every +// non-terminal record tagged and the waiting one held. +func TestShadowPromoteYieldsAHeldLedger(t *testing.T) { + shadowDir, stateDir := shadowFixture(t) + ctx := context.Background() + + got, err := PromoteShadow(ctx, promoteOptions(shadowDir, stateDir)) + require.NoError(t, err) + assert.Equal(t, HoldByPromote, got.Hold.Cause) + assert.Equal(t, 3, got.Tagged) + assert.Equal(t, 1, got.Held) + _, err = os.Lstat(filepath.Join(shadowDir, LedgerFile)) + assert.ErrorIs(t, err, os.ErrNotExist, "the shadow ledger moved") + + l, err := OpenLedger(filepath.Join(stateDir, LedgerFile)) + require.NoError(t, err) + t.Cleanup(func() { _ = l.Close() }) + held, err := l.Held(ctx) + require.NoError(t, err) + assert.True(t, held) + assert.Equal(t, StateHeld, stateOf(t, l, 1)) + assert.Equal(t, StateHeld, admitSeen(t, l, 2), "a shadow record mid-read becomes held when admitted") + + again, err := PromoteShadow(ctx, promoteOptions(shadowDir, stateDir)) + require.NoError(t, err) + assert.True(t, again.Already) +} + +func admitSeen(t *testing.T, l *Ledger, id int64) RecordState { + t.Helper() + record := getRecord(t, l, id) + v := admittedVerdict(id, record.Revision, "recording:"+strconv.FormatInt(id, 10)) + state, err := l.Admission().Commit(context.Background(), v) + require.NoError(t, err) + return RecordState(state) +} + +//nolint:contextcheck // subtests build their fixtures on background contexts +func TestShadowPromoteRefusesARunningShadowOrAnExistingLedger(t *testing.T) { + ctx := context.Background() + t.Run("the shadow is running", func(t *testing.T) { + shadowDir, stateDir := shadowFixture(t) + lock, err := AcquireInstanceLock(shadowDir, opAccount, opAgent, timeNow()) + require.NoError(t, err) + defer func() { _ = lock.Release() }() + _, err = PromoteShadow(ctx, promoteOptions(shadowDir, stateDir)) + require.ErrorIs(t, err, ErrAlreadyRunning) + assertUntouchedShadow(t, shadowDir) + }) + t.Run("the connector is running", func(t *testing.T) { + shadowDir, stateDir := shadowFixture(t) + lock, err := AcquireInstanceLock(stateDir, opAccount, opAgent, timeNow()) + require.NoError(t, err) + defer func() { _ = lock.Release() }() + _, err = PromoteShadow(ctx, promoteOptions(shadowDir, stateDir)) + require.ErrorIs(t, err, ErrAlreadyRunning) + assertUntouchedShadow(t, shadowDir) + }) + t.Run("a ledger is already there", func(t *testing.T) { + shadowDir, stateDir := shadowFixture(t) + l, err := OpenLedger(filepath.Join(stateDir, LedgerFile)) + require.NoError(t, err) + require.NoError(t, l.Close()) + _, err = PromoteShadow(ctx, promoteOptions(shadowDir, stateDir)) + require.ErrorIs(t, err, ErrLedgerExists) + assertUntouchedShadow(t, shadowDir) + }) +} + +// assertUntouchedShadow checks the shadow ledger is where it was, unheld, its +// records as the fixture left them. +func assertUntouchedShadow(t *testing.T, shadowDir string) { + t.Helper() + l, err := OpenLedgerReadOnly(context.Background(), filepath.Join(shadowDir, LedgerFile)) + require.NoError(t, err) + defer func() { _ = l.Close() }() + held, err := l.Held(context.Background()) + require.NoError(t, err) + assert.False(t, held) + assert.Equal(t, StateAdmitted, stateOf(t, l, 1)) +} + +// crashEnv names the step a helper process kills itself at. +const crashEnv = "BASECAMP_CONNECTOR_CRASH_AT" + +// TestCrashHelper is not a test: it is the process the crash tests start and +// kill. It runs promote or import against the directories in its environment +// and SIGKILLs itself at the named step. +func TestCrashHelper(t *testing.T) { + at := os.Getenv(crashEnv) + if at == "" { + t.Skip("run by the crash tests") + } + op, step, _ := strings.Cut(at, ":") + kill := func(name string) { + if name == step { + _ = syscall.Kill(os.Getpid(), syscall.SIGKILL) + select {} + } + } + promoteStep, holdStep, importStep = kill, kill, kill + ctx := context.Background() + switch op { + case "promote": + _, err := PromoteShadow(ctx, promoteOptions(os.Getenv("SHADOW_DIR"), os.Getenv("STATE_DIR"))) + require.NoError(t, err) + case "import": + l, err := OpenLedger(os.Getenv("LEDGER")) + require.NoError(t, err) + var r Reconciliation + require.NoError(t, json.Unmarshal([]byte(os.Getenv("RECONCILIATION")), &r)) + _, err = l.Import(ctx, r, opBy) + require.NoError(t, err) + } + t.Fatal("the helper reached its end without being killed at " + step) +} + +func runKilled(t *testing.T, at string, env ...string) { + t.Helper() + cmd := exec.CommandContext(context.Background(), os.Args[0], "-test.run=^TestCrashHelper$", "-test.count=1") + cmd.Env = append(append(os.Environ(), crashEnv+"="+at), env...) + out, err := cmd.CombinedOutput() + var exit *exec.ExitError + require.True(t, errors.As(err, &exit), "the helper must die: %v\n%s", err, out) + status, ok := exit.Sys().(syscall.WaitStatus) + require.True(t, ok) + require.True(t, status.Signaled() && status.Signal() == syscall.SIGKILL, "killed at %s, got %v\n%s", at, err, out) +} + +// Invariant 7: a crash at any point of promote leaves either the untouched +// shadow or a held ledger — never an unheld ledger at the normal path, never +// two ledgers and never none — and promote run again finishes. +// +//nolint:contextcheck // subtests build their fixtures on background contexts +func TestInvariant7PromoteSurvivesAKillAtEveryStep(t *testing.T) { + if testing.Short() { + t.Skip("starts processes") + } + type crash struct { + step string + // preHeld is a shadow already run with --hold, whose marker keeps + // that cause through the promote. + preHeld bool + } + steps := []string{"locked", "marker", "tagged", "held", "checkpointed", "renamed", "synced"} + crashes := make([]crash, 0, len(steps)+2) + crashes = append(crashes, crash{step: "renamed", preHeld: true}, crash{step: "synced", preHeld: true}) + for _, step := range steps { + crashes = append(crashes, crash{step: step}) + } + for _, c := range crashes { + step := c.step + name := step + if c.preHeld { + name += " of a held shadow" + } + t.Run(name, func(t *testing.T) { + shadowDir, stateDir := shadowFixture(t) + if c.preHeld { + l, err := OpenLedger(filepath.Join(shadowDir, LedgerFile)) + require.NoError(t, err) + _, err = l.SetHold(context.Background(), opBy, HoldByOperator) + require.NoError(t, err) + require.NoError(t, l.Close()) + } + runKilled(t, "promote:"+step, "SHADOW_DIR="+shadowDir, "STATE_DIR="+stateDir) + + shadowLedger := filepath.Join(shadowDir, LedgerFile) + stateLedger := filepath.Join(stateDir, LedgerFile) + _, shadowErr := os.Lstat(shadowLedger) + _, stateErr := os.Lstat(stateLedger) + require.True(t, (shadowErr == nil) != (stateErr == nil), "exactly one ledger exists (shadow: %v, normal: %v)", shadowErr, stateErr) + + if stateErr == nil { + assertHeld(t, stateLedger) + } else if c.preHeld || ledgerIsHeld(t, shadowLedger) { + assertHeld(t, shadowLedger) + } else { + assertUntouchedShadow(t, shadowDir) + } + + got, err := PromoteShadow(context.Background(), promoteOptions(shadowDir, stateDir)) + require.NoError(t, err, "promote run again finishes") + if !c.preHeld { + assert.Equal(t, HoldByPromote, got.Hold.Cause) + } + assertHeld(t, stateLedger) + }) + } +} + +func ledgerIsHeld(t *testing.T, path string) bool { + t.Helper() + l, err := OpenLedgerReadOnly(context.Background(), path) + require.NoError(t, err) + defer func() { _ = l.Close() }() + held, err := l.Held(context.Background()) + require.NoError(t, err) + return held +} + +func assertHeld(t *testing.T, path string) { + t.Helper() + l, err := OpenLedger(path) + require.NoError(t, err) + defer func() { _ = l.Close() }() + held, err := l.Held(context.Background()) + require.NoError(t, err) + require.True(t, held, "%s is held", path) + assert.Equal(t, StateHeld, stateOf(t, l, 1), "the waiting record is held") + var untagged int + require.NoError(t, l.db.QueryRowContext(context.Background(), `SELECT COUNT(*) FROM events WHERE state NOT IN ('completed', 'discarded') AND review = 0`).Scan(&untagged)) + assert.Zero(t, untagged, "every non-terminal record is tagged") +} + +// Done when: import applies a reconciliation in one transaction — tombstones +// only for done entries, everything else tagged, states and reasons kept. +func TestImportTombstonesDoneAndTagsTheRest(t *testing.T) { + l := newTestLedger(t) + ctx := context.Background() + opAdmit(t, l, 1, "recording:1") + seenRecord(t, l, 2) + seenRecord(t, l, 3) + _, err := l.Admission().Commit(ctx, blockedVerdict(3, 0, "read_failed")) + require.NoError(t, err) + seenRecord(t, l, 5) + + got, err := l.Import(ctx, Reconciliation{Version: 1, Entries: []ReconciliationEntry{ + {EventID: 2, Decision: DecisionDone}, + {EventID: 99, Decision: DecisionDone}, + {EventID: 3, Decision: DecisionHeld}, + }}, opBy) + require.NoError(t, err) + assert.Equal(t, 1, got.Tombstoned) + assert.Equal(t, 1, got.Inserted) + assert.Equal(t, 3, got.Tagged) + assert.Equal(t, 1, got.Held) + + assert.Equal(t, StateHeld, stateOf(t, l, 1)) + two := getRecord(t, l, 2) + assert.Equal(t, StateDiscarded, two.State) + assert.Equal(t, ReasonImportedDone, two.Reason) + three := getRecord(t, l, 3) + assert.Equal(t, StateBlocked, three.State) + assert.Equal(t, "read_failed", three.Reason, "the blocking reason is kept") + assert.Equal(t, StateSeen, stateOf(t, l, 5)) + + fresh, err := l.RecordSeen(ctx, testEvent(99), LanePoll) + require.NoError(t, err) + assert.False(t, fresh, "an imported tombstone is never new work") + assert.Equal(t, StateHeld, admitSeen(t, l, 5), "an unmapped record is tagged too") +} + +//nolint:contextcheck // subtests build their fixtures on background contexts +func TestImportRefusesAFileItCannotApplyWhole(t *testing.T) { + ctx := context.Background() + for name, entries := range map[string][]ReconciliationEntry{ + "held for an unseen event": {{EventID: 2, Decision: DecisionDone}, {EventID: 404, Decision: DecisionHeld}}, + "done for a dispatched event": {{EventID: 2, Decision: DecisionDone}, {EventID: 1, Decision: DecisionDone}}, + } { + t.Run(name, func(t *testing.T) { + l := newTestLedger(t) + opAdmit(t, l, 1, "recording:1") + launchOf(t, l, 1) + seenRecord(t, l, 2) + + _, err := l.Import(ctx, Reconciliation{Version: 1, Entries: entries}, opBy) + require.ErrorIs(t, err, ErrDecisionRefused) + assert.Equal(t, StateSeen, stateOf(t, l, 2), "nothing was applied") + var tagged int + require.NoError(t, l.db.QueryRowContext(context.Background(), `SELECT COUNT(*) FROM events WHERE review = 1`).Scan(&tagged)) + assert.Zero(t, tagged) + }) + } +} + +func TestParseReconciliationIsStrict(t *testing.T) { + for name, body := range map[string]string{ + "unknown field": `{"version":1,"entries":[{"event_id":1,"decision":"done","note":"x"}]}`, + "other decision": `{"version":1,"entries":[{"event_id":1,"decision":"maybe"}]}`, + "duplicate": `{"version":1,"entries":[{"event_id":1,"decision":"done"},{"event_id":1,"decision":"held"}]}`, + "no id": `{"version":1,"entries":[{"decision":"done"}]}`, + "other version": `{"version":2,"entries":[]}`, + "trailing value": `{"version":1,"entries":[]} {}`, + "trailing brace": `{"version":1,"entries":[]} }`, + "trailing bracket": `{"version":1,"entries":[]} ]`, + "trailing text": `{"version":1,"entries":[]} done`, + } { + t.Run(name, func(t *testing.T) { + _, err := ParseReconciliation([]byte(body)) + assert.Error(t, err) + }) + } + r, err := ParseReconciliation([]byte(`{"version":1,"entries":[{"event_id":7,"decision":"held"}]}`)) + require.NoError(t, err) + assert.Equal(t, []ReconciliationEntry{{EventID: 7, Decision: DecisionHeld}}, r.Entries) +} + +// Invariant 7: an import killed mid-transaction applied nothing. +// +//nolint:contextcheck // subtests build their fixtures on background contexts +func TestInvariant7ImportSurvivesAKillAtEveryStep(t *testing.T) { + if testing.Short() { + t.Skip("starts processes") + } + for _, step := range []string{"entry", "tagged"} { + t.Run(step, func(t *testing.T) { + path := filepath.Join(t.TempDir(), "state", LedgerFile) + l, err := OpenLedger(path) + require.NoError(t, err) + opAdmit(t, l, 1, "recording:1") + seenRecord(t, l, 2) + require.NoError(t, l.Close()) + file := `{"version":1,"entries":[{"event_id":2,"decision":"done"},{"event_id":1,"decision":"held"}]}` + + runKilled(t, "import:"+step, "LEDGER="+path, "RECONCILIATION="+file) + + l, err = OpenLedger(path) + require.NoError(t, err) + defer func() { _ = l.Close() }() + assert.Equal(t, StateAdmitted, stateOf(t, l, 1)) + assert.Equal(t, StateSeen, stateOf(t, l, 2)) + var decisions int + require.NoError(t, l.db.QueryRowContext(context.Background(), `SELECT COUNT(*) FROM decisions`).Scan(&decisions)) + assert.Zero(t, decisions, fmt.Sprintf("killed at %s: nothing recorded", step)) + }) + } +} + +func timeNow() time.Time { return time.Now() } + +// A promote run again after its rename finishes the move rather than refusing +// it, and does not mind a shadow directory a person has cleared away. +func TestPromoteRunAgainFinishesAMoveWithoutItsShadow(t *testing.T) { + shadowDir, stateDir := shadowFixture(t) + ctx := context.Background() + _, err := PromoteShadow(ctx, promoteOptions(shadowDir, stateDir)) + require.NoError(t, err) + require.NoError(t, os.RemoveAll(shadowDir)) + + got, err := PromoteShadow(ctx, promoteOptions(shadowDir, stateDir)) + require.NoError(t, err) + assert.True(t, got.Already) + assertHeld(t, filepath.Join(stateDir, LedgerFile)) +} + +// Import validates the reconciliation it is handed, not only the file it was +// parsed from: a caller that built the value itself meets the same rules. +// +//nolint:contextcheck // subtests build their fixtures on background contexts +func TestImportValidatesWhatItIsHanded(t *testing.T) { + ctx := context.Background() + for name, r := range map[string]Reconciliation{ + "another version": {Version: ReconciliationVersion + 1}, + "unknown decision": {Version: ReconciliationVersion, Entries: []ReconciliationEntry{{EventID: 1, Decision: "maybe"}}}, + "no event": {Version: ReconciliationVersion, Entries: []ReconciliationEntry{{Decision: DecisionDone}}}, + "one event twice": {Version: ReconciliationVersion, Entries: []ReconciliationEntry{{EventID: 1, Decision: DecisionDone}, {EventID: 1, Decision: DecisionHeld}}}, + } { + t.Run(name, func(t *testing.T) { + l := newTestLedger(t) + opAdmit(t, l, 1, "recording:1") + + _, err := l.Import(ctx, r, opBy) + require.Error(t, err) + assert.Equal(t, StateAdmitted, stateOf(t, l, 1), "nothing was tagged or closed") + var tagged int + require.NoError(t, l.db.QueryRowContext(ctx, `SELECT COUNT(*) FROM events WHERE review = 1`).Scan(&tagged)) + assert.Zero(t, tagged) + }) + } +} + +// A promote run again takes the connector's lock even when there is no shadow +// state left to stop: it never reports on a ledger a connector is running on. +func TestPromoteRunAgainStillNeedsTheConnectorStopped(t *testing.T) { + shadowDir, stateDir := shadowFixture(t) + ctx := context.Background() + _, err := PromoteShadow(ctx, promoteOptions(shadowDir, stateDir)) + require.NoError(t, err) + require.NoError(t, os.RemoveAll(shadowDir)) + + lock, err := AcquireInstanceLock(stateDir, opAccount, opAgent, timeNow()) + require.NoError(t, err) + _, err = PromoteShadow(ctx, promoteOptions(shadowDir, stateDir)) + require.ErrorIs(t, err, ErrAlreadyRunning) + require.NoError(t, lock.Release()) + + got, err := PromoteShadow(ctx, promoteOptions(shadowDir, stateDir)) + require.NoError(t, err) + assert.True(t, got.Already) +} diff --git a/internal/connector/operator_status_test.go b/internal/connector/operator_status_test.go new file mode 100644 index 000000000..c0a30fece --- /dev/null +++ b/internal/connector/operator_status_test.go @@ -0,0 +1,141 @@ +package connector + +import ( + "context" + "encoding/json" + "os" + "path/filepath" + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// Invariant 8: status reads beside a writer, writes nothing, and shows no +// content, position or token. +func TestInvariant8StatusReadsBesideAWriterAndShowsNoSecrets(t *testing.T) { + ctx := context.Background() + path := filepath.Join(t.TempDir(), "state", LedgerFile) + l, err := OpenLedger(path) + require.NoError(t, err) + t.Cleanup(func() { _ = l.Close() }) + l.SetHooks(LifecycleHooks(l, LifecycleOptions{})) + + const position = "signed-position-not-real-7f3a" + require.NoError(t, l.Save(ctx, testKey(), position)) + require.NoError(t, l.NotePollServed(ctx, testKey(), 41)) + require.NoError(t, l.NoteConnection(ctx, ConnectionRunning, "")) + + unknownOutcome(t, l, 2) + opAdmit(t, l, 1, "recording:1") + launch := launchOf(t, l, 1) + require.NoError(t, l.MarkRunning(ctx, launch.AttemptID, AttemptProcess{PID: 4242, PGID: 4242, StartedAt: time.Now()})) + seenRecord(t, l, 5) + _, err = l.Admission().Commit(ctx, blockedVerdict(5, 0, "read_failed")) + require.NoError(t, err) + _, err = l.db.ExecContext(context.Background(), `UPDATE outbox SET state = 'sending', sending_at = ? WHERE event_id = 1`, stamp(time.Now())) + require.NoError(t, err) + _, err = l.db.ExecContext(context.Background(), `UPDATE outbox SET state = 'indeterminate', note = 'two candidates' WHERE event_id = 1`) + require.NoError(t, err) + l.SetHooks(Hooks{}) + opAdmit(t, l, 3, "recording:3") + seenRecord(t, l, 4) + _, err = l.SetHold(ctx, opBy, HoldByOperator) + require.NoError(t, err) + + // A writer holds the write lock while status reads. + writer, err := l.db.BeginTx(ctx, nil) + require.NoError(t, err) + _, err = writer.ExecContext(ctx, `UPDATE events SET updated_at = updated_at WHERE id = 4`) + require.NoError(t, err) + defer func() { _ = writer.Rollback() }() + + reader, err := OpenLedgerReadOnly(context.Background(), path) + require.NoError(t, err) + defer func() { _ = reader.Close() }() + s, err := reader.Status(ctx, nil) + require.NoError(t, err) + + require.NotNil(t, s.Hold) + assert.Equal(t, "hold", s.Hold.Cause) + require.NotNil(t, s.Connection) + assert.Equal(t, ConnectionRunning, s.Connection.State) + require.Len(t, s.Positions, 1) + assert.True(t, s.Positions[0].HasPosition) + assert.Equal(t, int64(41), s.Positions[0].LastPollServedID) + require.Len(t, s.Tasks, 1) + assert.Equal(t, launch.TaskID, s.Tasks[0].TaskID) + assert.Equal(t, 4242, s.Tasks[0].PID) + require.Len(t, s.Held, 1) + assert.Equal(t, int64(3), s.Held[0].EventID) + assert.Equal(t, 1, s.Queues["held"]) + assert.Equal(t, 1, s.Queues["seen"]) + assert.Equal(t, 3, s.Review, "the seen, the blocked and the dispatched record wait for review") + assert.Equal(t, map[string]int{"read_failed": 1}, s.Blocked) + require.Len(t, s.Indeterminate, 1) + assert.Equal(t, int64(1), s.Indeterminate[0].EventID) + require.Len(t, s.Dispatches, 2) + assert.False(t, s.WorktreesKnown) + + raw, err := json.Marshal(s) + require.NoError(t, err) + out := string(raw) + assert.NotContains(t, out, position) + assert.NotContains(t, out, "please look", "no snapshot content") + assert.NotContains(t, out, tokenHash(launch.Token)) + assert.NotContains(t, out, launch.Token) +} + +func TestOpenLedgerReadOnlyCreatesNothing(t *testing.T) { + dir := filepath.Join(t.TempDir(), "state") + _, err := OpenLedgerReadOnly(context.Background(), filepath.Join(dir, LedgerFile)) + require.ErrorIs(t, err, os.ErrNotExist) + _, err = os.Lstat(dir) + assert.ErrorIs(t, err, os.ErrNotExist) + + l, err := OpenLedger(filepath.Join(dir, "other.db")) + require.NoError(t, err) + require.NoError(t, l.Close()) + _, err = OpenLedgerReadOnly(context.Background(), filepath.Join(dir, LedgerFile)) + require.ErrorIs(t, err, os.ErrNotExist, "a ledger gone from a private directory") + _, err = os.Lstat(filepath.Join(dir, LedgerFile)) + assert.ErrorIs(t, err, os.ErrNotExist, "is not recreated by a reader") + + l, err = OpenLedger(filepath.Join(dir, LedgerFile)) + require.NoError(t, err) + require.NoError(t, l.Close()) + reader, err := OpenLedgerReadOnly(context.Background(), filepath.Join(dir, LedgerFile)) + require.NoError(t, err) + defer func() { _ = reader.Close() }() + _, err = reader.db.ExecContext(context.Background(), `DELETE FROM events`) + assert.Error(t, err, "a read-only ledger refuses writes") +} + +// A ledger a newer build wrote is not this build's to read or decide in. +func TestOpenLedgerReadOnlyRefusesANewerSchema(t *testing.T) { + path := filepath.Join(t.TempDir(), "state", LedgerFile) + l, err := OpenLedger(path) + require.NoError(t, err) + _, err = l.db.ExecContext(context.Background(), `INSERT INTO schema_migrations (version, applied_at) VALUES (?, ?)`, len(migrations)+1, stamp(time.Now())) + require.NoError(t, err) + require.NoError(t, l.Close()) + + _, err = OpenLedgerReadOnly(context.Background(), path) + require.ErrorIs(t, err, ErrLedgerSchema) + assert.NotErrorIs(t, err, ErrLedgerOutOfDate) +} + +// The connector's own open refuses a ledger a newer build wrote too: an older +// binary rolled back onto it must not run over rules it does not know. +func TestOpenLedgerRefusesANewerSchema(t *testing.T) { + path := filepath.Join(t.TempDir(), "state", LedgerFile) + l, err := OpenLedger(path) + require.NoError(t, err) + _, err = l.db.ExecContext(context.Background(), `INSERT INTO schema_migrations (version, applied_at) VALUES (?, ?)`, len(migrations)+1, stamp(time.Now())) + require.NoError(t, err) + require.NoError(t, l.Close()) + + _, err = OpenLedger(path) + require.ErrorIs(t, err, ErrLedgerSchema) +} diff --git a/internal/connector/outbox_run.go b/internal/connector/outbox_run.go index 6092a44c8..7a09682da 100644 --- a/internal/connector/outbox_run.go +++ b/internal/connector/outbox_run.go @@ -376,6 +376,31 @@ func (l *Ledger) claimIntent(ctx context.Context, skip ...int64) (Intent, bool, in := intents[0] next, note := IntentSending, "" + if in.Kind == IntentCompletion { + // A person can decide an event between the settlement that wrote + // the notice and the send. One indexed read says whether anyone + // did; only then is the notice rendered again from the records, so + // it never asks for what is already done. + decided, err := decidedSince(ctx, tx, in.AttemptID) + if err != nil { + return err + } + if decided { + settled, err := settlementFromRecords(ctx, tx, in.AttemptID) + if err != nil { + return err + } + switch body := renderCompletion(in.Destination.Kind, settled); { + case !CompletionNeeded(settled): + next, note = IntentCanceled, "every event it named was decided" + case body != in.Body: + if _, err := tx.ExecContext(ctx, `UPDATE outbox SET body = ? WHERE id = ? AND state = 'pending'`, body, in.ID); err != nil { + return fmt.Errorf("connector: outbox claim completion %d: %w", in.ID, err) + } + in.Body = body + } + } + } if in.Kind == IntentHoldingReply { // The reply answers a record with no route. If the route arrived // and the record moved on — it may be running now — the answer is @@ -900,3 +925,21 @@ func (o *Outbox) line(in Intent) { o.log.Warn("connector: outbox line", "error", err) } } + +// decidedSince reports whether any event on an attempt's task has left the +// state its completion notice was rendered from — a person redispatched or +// discarded it. It is one indexed read, so the ordinary claim, where nobody +// decided anything, does not pay for a full re-render. +func decidedSince(ctx context.Context, tx *sql.Tx, attemptID string) (bool, error) { + var decided bool + if err := tx.QueryRowContext(ctx, ` +SELECT EXISTS ( + SELECT 1 FROM task_events te JOIN events e ON e.id = te.event_id + WHERE te.task_id = (SELECT task_id FROM attempts WHERE id = ?1) + AND (te.delivery = 'completed' OR (te.withdrawn_at IS NOT NULL AND te.exposed_attempt_id = ?1)) + AND (e.state NOT IN ('completed', 'blocked') OR e.redispatch_decision IS NOT NULL + OR COALESCE(e.authorized_at > (SELECT ended_at FROM attempts WHERE id = ?1), 0)))`, attemptID).Scan(&decided); err != nil { + return false, fmt.Errorf("connector: outbox claim completion for %s: %w", attemptID, err) + } + return decided, nil +} diff --git a/internal/connector/policy.go b/internal/connector/policy.go index 79476d375..94b0a161f 100644 --- a/internal/connector/policy.go +++ b/internal/connector/policy.go @@ -87,6 +87,12 @@ func (p Policy) inside(locations []string) bool { return false } for _, loc := range locations { + if strings.TrimSpace(loc) == "" { + // A location that names nothing resolves to the working directory + // itself, which would let a request that named no path pass as one + // inside it. + return false + } if !filepath.IsAbs(loc) { loc = filepath.Join(p.WorkDir, loc) } diff --git a/internal/connector/policy_test.go b/internal/connector/policy_test.go index e9fa270e6..71cf8bfdb 100644 --- a/internal/connector/policy_test.go +++ b/internal/connector/policy_test.go @@ -116,3 +116,20 @@ func TestThePolicyRefusesFilesystemCallsWithNoPath(t *testing.T) { assert.False(t, allow(driver.ToolEdit)) assert.True(t, allow(driver.ToolThink), "the one allowed kind that touches no file") } + +// A location that names nothing is not a location inside the working +// directory: it would otherwise resolve to the directory itself and pass. +func TestPolicyRefusesAnEditThatNamesNoPath(t *testing.T) { + dir := t.TempDir() + p := DefaultPolicy(dir) + for _, loc := range []string{"", " "} { + decision := p.Decide(context.Background(), driver.PermissionRequest{ + Tool: "Edit", Kind: driver.ToolEdit, Locations: []string{loc}, + }) + assert.False(t, decision.Allow, "an edit whose location is %q", loc) + } + allowed := p.Decide(context.Background(), driver.PermissionRequest{ + Tool: "Edit", Kind: driver.ToolEdit, Locations: []string{filepath.Join(dir, "file.go")}, + }) + assert.True(t, allowed.Allow) +} diff --git a/internal/connector/promote.go b/internal/connector/promote.go new file mode 100644 index 000000000..dc7c6d1e3 --- /dev/null +++ b/internal/connector/promote.go @@ -0,0 +1,251 @@ +package connector + +import ( + "context" + "database/sql" + "errors" + "fmt" + "os" + "path/filepath" + "strings" + "time" +) + +// PromoteOptions names the two state directories of one account and agent. +type PromoteOptions struct { + // ShadowDir is the shadow run's state directory, StateDir the normal + // one. Both must be on one filesystem: the ledger moves by rename. + ShadowDir string + StateDir string + AccountID string + AgentID int64 + // By records who promoted. + By string +} + +// PromoteResult is what a promote did. +type PromoteResult struct { + // Already says an earlier promote finished: the normal ledger stands + // under its hold and there was no shadow ledger left to move. + Already bool `json:"already_promoted,omitempty"` + Hold Hold `json:"hold"` + Tagged int `json:"tagged_for_review"` + Held int `json:"held"` + // Ledger is the promoted ledger's path. + Ledger string `json:"ledger"` +} + +// Errors from promote. +var ( + // ErrNoShadowLedger is a shadow directory without a ledger. + ErrNoShadowLedger = errors.New("there is no shadow ledger to promote") + // ErrLedgerExists is a normal state directory that already has a ledger. + ErrLedgerExists = errors.New("the connector already has a ledger") +) + +// promoteStep is a test seam: a crash test kills the process at a named step. +var promoteStep = func(string) {} + +// PromoteShadow turns a shadow run's ledger into the connector's, held +// (invariant 7). In order: +// +// 1. Both instance locks are taken, the shadow's and the connector's: no +// shadow writer and no connector is running. +// 2. In the shadow ledger, in one transaction: the hold marker, a new +// generation, every non-terminal record tagged for review, waiting +// records held. +// 3. The shadow ledger is checkpointed into its single database file. +// 4. That file is renamed into the connector's state directory, which +// exposes it; the directory is synced. +// +// A crash before 2 commits leaves the untouched shadow. After it, the ledger +// at either path is held, and running promote again finishes the move. The +// hold is committed before the rename, so no unheld ledger is ever at the +// normal path. +func PromoteShadow(ctx context.Context, opts PromoteOptions) (PromoteResult, error) { + switch { + case opts.ShadowDir == "" || opts.StateDir == "": + return PromoteResult{}, errors.New("connector: promote needs the shadow and the normal state directory") + case filepath.Clean(opts.ShadowDir) == filepath.Clean(opts.StateDir): + return PromoteResult{}, errors.New("connector: the shadow and the normal state directory are the same directory") + case strings.TrimSpace(opts.By) == "": + return PromoteResult{}, errors.New("connector: a promote records who promoted") + } + shadowPath := filepath.Join(opts.ShadowDir, LedgerFile) + statePath := filepath.Join(opts.StateDir, LedgerFile) + + if _, err := os.Lstat(opts.ShadowDir); err != nil { + if !errors.Is(err, os.ErrNotExist) { + return PromoteResult{}, fmt.Errorf("connector: inspect the shadow state: %w", err) + } + // No shadow state at all: this can only be a promote run again, and + // it still says so under the connector's own lock. + stateLock, err := AcquireInstanceLock(opts.StateDir, opts.AccountID, opts.AgentID, time.Now()) + if err != nil { + return PromoteResult{}, fmt.Errorf("connector: the connector must be stopped first: %w", err) + } + defer func() { _ = stateLock.Release() }() + return promoted(ctx, opts, statePath) + } + shadowLock, err := AcquireInstanceLock(opts.ShadowDir, opts.AccountID, opts.AgentID, time.Now()) + if err != nil { + return PromoteResult{}, fmt.Errorf("connector: the shadow connector must be stopped first: %w", err) + } + defer func() { _ = shadowLock.Release() }() + stateLock, err := AcquireInstanceLock(opts.StateDir, opts.AccountID, opts.AgentID, time.Now()) + if err != nil { + return PromoteResult{}, fmt.Errorf("connector: the connector must be stopped first: %w", err) + } + defer func() { _ = stateLock.Release() }() + promoteStep("locked") + + if _, err := os.Lstat(shadowPath); err != nil { + if errors.Is(err, os.ErrNotExist) { + return promoted(ctx, opts, statePath) + } + return PromoteResult{}, fmt.Errorf("connector: inspect the shadow ledger: %w", err) + } + for _, p := range []string{statePath, statePath + "-wal", statePath + "-shm", statePath + "-journal"} { + switch _, err := os.Lstat(p); { + case err == nil: + return PromoteResult{}, fmt.Errorf("connector: %s: %w", p, ErrLedgerExists) + case !errors.Is(err, os.ErrNotExist): + return PromoteResult{}, fmt.Errorf("connector: inspect %s: %w", p, err) + } + } + + ledger, err := OpenLedger(shadowPath) //nolint:contextcheck // OpenLedger migrates on its own context + if err != nil { + return PromoteResult{}, err + } + closed := false + defer func() { + if !closed { + _ = ledger.Close() + } + }() + held, err := ledger.SetHold(ctx, opts.By, HoldByPromote) + if err != nil { + return PromoteResult{}, err + } + promoteStep("held") + + // One file, so one rename moves all of it: the WAL is folded into the + // database and the journal mode leaves no sidecar behind. + if err := checkpointToOneFile(ctx, ledger.db); err != nil { + return PromoteResult{}, err + } + if err := ledger.Close(); err != nil { + return PromoteResult{}, fmt.Errorf("connector: close the shadow ledger: %w", err) + } + closed = true + for _, p := range []string{shadowPath + "-wal", shadowPath + "-shm", shadowPath + "-journal"} { + switch _, err := os.Lstat(p); { + case err == nil: + return PromoteResult{}, fmt.Errorf("connector: the shadow ledger still has %s after its checkpoint; it is held, run promote again", filepath.Base(p)) + case !errors.Is(err, os.ErrNotExist): + return PromoteResult{}, fmt.Errorf("connector: inspect %s: %w", p, err) + } + } + promoteStep("checkpointed") + + if err := os.Rename(shadowPath, statePath); err != nil { + return PromoteResult{}, fmt.Errorf("connector: move the shadow ledger: %w", err) + } + promoteStep("renamed") + if err := syncDirectory(opts.StateDir); err != nil { + return PromoteResult{}, err + } + if err := syncDirectory(opts.ShadowDir); err != nil { + return PromoteResult{}, err + } + promoteStep("synced") + + // Opened once more the normal way, which vets the file where it now is + // and puts it back in WAL mode, and read: the hold must stand. + moved, err := OpenLedger(statePath) //nolint:contextcheck // OpenLedger migrates on its own context + if err != nil { + return PromoteResult{}, err + } + defer func() { _ = moved.Close() }() + hold, ok, err := moved.HoldMarker(ctx) + if err != nil { + return PromoteResult{}, err + } + if !ok { + return PromoteResult{}, errors.New("connector: the promoted ledger has no hold marker") + } + return PromoteResult{Hold: hold, Tagged: held.Tagged, Held: held.Held, Ledger: statePath}, nil +} + +// promoted answers a promote with no shadow ledger left: an earlier promote +// finished when the normal ledger stands under a promote's hold. It finishes +// what that promote may not have: a crash after the rename leaves the move +// without its durability barrier, so both directories are synced again before +// this says it is done. +func promoted(ctx context.Context, opts PromoteOptions, statePath string) (PromoteResult, error) { + if _, err := os.Lstat(statePath); err != nil { + if errors.Is(err, os.ErrNotExist) { + return PromoteResult{}, fmt.Errorf("connector: %w", ErrNoShadowLedger) + } + return PromoteResult{}, err + } + ledger, err := OpenLedgerReadOnly(ctx, statePath) + if err != nil { + return PromoteResult{}, err + } + defer func() { _ = ledger.Close() }() + hold, ok, err := ledger.HoldMarker(ctx) + if err != nil { + return PromoteResult{}, err + } + // The promote's own decision is the mark, not the hold's cause: a shadow + // already held by --hold keeps its first cause through the promote. + var promotedHere bool + if err := ledger.db.QueryRowContext(ctx, `SELECT EXISTS (SELECT 1 FROM decisions WHERE action = 'shadow_promote')`).Scan(&promotedHere); err != nil { + return PromoteResult{}, fmt.Errorf("connector: read the ledger's promote: %w", err) + } + if !ok || !promotedHere { + return PromoteResult{}, fmt.Errorf("connector: %w", ErrNoShadowLedger) + } + for _, dir := range []string{opts.StateDir, opts.ShadowDir} { + if err := syncDirectory(dir); err != nil && !errors.Is(err, os.ErrNotExist) { + return PromoteResult{}, err + } + } + return PromoteResult{Already: true, Hold: hold, Ledger: statePath}, nil +} + +func checkpointToOneFile(ctx context.Context, db *sql.DB) error { + var busy, logged, checkpointed int + if err := db.QueryRowContext(ctx, `PRAGMA wal_checkpoint(TRUNCATE)`).Scan(&busy, &logged, &checkpointed); err != nil { + return fmt.Errorf("connector: checkpoint the shadow ledger: %w", err) + } + if busy != 0 { + return errors.New("connector: the shadow ledger is in use; stop whatever holds it and run promote again") + } + var mode string + if err := db.QueryRowContext(ctx, `PRAGMA journal_mode = DELETE`).Scan(&mode); err != nil { + return fmt.Errorf("connector: leave WAL mode: %w", err) + } + if !strings.EqualFold(mode, "delete") { + return fmt.Errorf("connector: the shadow ledger stayed in %s mode; it is held, run promote again", mode) + } + return nil +} + +func syncDirectory(dir string) error { + f, err := os.Open(dir) + if errors.Is(err, os.ErrNotExist) { + // A shadow directory a person has already cleared away. + return err + } + if err != nil { + return fmt.Errorf("connector: sync %s: %w", dir, err) + } + defer f.Close() + if err := f.Sync(); err != nil { + return fmt.Errorf("connector: sync %s: %w", dir, err) + } + return nil +} diff --git a/skills/basecamp-connect/SKILL.md b/skills/basecamp-connect/SKILL.md index e3899af6f..d538c43b5 100644 --- a/skills/basecamp-connect/SKILL.md +++ b/skills/basecamp-connect/SKILL.md @@ -5,11 +5,14 @@ description: | connector's setup: the agent's credential (basecamp auth agent connect), connect.json (who may drive the agent, which project routes to which directory), and readiness (basecamp connect setup). Explains every setup - result and failure. Starting and supervising the connector is not in this - skill yet. + result and failure. Also reads what the connector ran (status, doctor) and + carries out a person's decisions on its records (redispatch, discard, + release, the cutover's shadow promote and import). Starting and supervising + the connector is not in this skill yet. Use when asked to connect an agent, set up or change the connector, add or - remove a project, change who can drive the agent, or find out why setup - says the connector is not ready. + remove a project, change who can drive the agent, find out why setup says + the connector is not ready, or see, retry, close or release what the + connector holds. triggers: - /basecamp-connect - connect an agent @@ -20,6 +23,11 @@ triggers: - route a project to a directory - who can drive the agent - connector not ready + - basecamp connect status + - basecamp connect doctor + - redispatch an event + - held records + - release the hold --- # Basecamp connector: connect an agent and manage its setup @@ -70,7 +78,8 @@ explain the result. This skill is the reference you do that from. computer. Show them in this conversation only; never post them to Basecamp, chat, a file or anywhere else. Whoever approves that code chooses which agent this computer acts as. -- Setup and the connection refuse to run while `BASECAMP_TOKEN` is set. Tell the +- Setup, the connection, doctor and redispatch refuse to run while + `BASECAMP_TOKEN` is set. Tell the person to unset it in their shell; do not set, print or work around it. **Identity.** Never set up a profile whose identity you have not confirmed with @@ -111,7 +120,7 @@ the link and code while it waits; then wait for it to finish. | Credential | The CLI's credential store, under the profile. `basecamp auth status -P '<profile>' --json` describes it (see Inspecting). Never open it. | | connect.json | `$XDG_CONFIG_HOME/basecamp/connect/<profile>/connect.json`, default `~/.config/basecamp/connect/<profile>/connect.json`. Setup's JSON result gives the exact `path`. | | Setup lock | `.connect.lock` beside connect.json. One setup per profile at a time. | -| Connector runtime state (ledger, checkpoint, lock) | Does not exist yet: it comes with the connector run (card 24, behind step 21). Do not look for it. | +| Connector runtime state (ledger, checkpoint, lock) | `$XDG_STATE_HOME/basecamp/connect/<account>-<agent person id>/`, default under `~/.local/state`; a shadow run's is under `connect-shadow/` instead. Read it only through `basecamp connect status` and `basecamp connect doctor`; never open or copy the files. | The CLI's configuration, its profiles and (when it uses files) its credential store also live under `$XDG_CONFIG_HOME/basecamp`, so pointing @@ -393,14 +402,55 @@ is bound to account X, and this command named account Y* (drop `--account`), and *Profile holds a person's login, not an Agent's credential* (either it is a bot user and needs `--expect-identity`, or the wrong login is stored: ask). -## Not built yet - -Setup is all there is today. These come with card 24, behind step 21, and do not -exist in the CLI yet, so do not try them or look for flags for them: - -- starting and supervising the connector, and reading its pointer lines; -- a `service install` subcommand that keeps it running under systemd or launchd; -- status, doctor and redispatch commands for the connector; +## Seeing and deciding what the connector ran + +These read or change the connector's own ledger for a set-up profile. They are +the person's decisions, so run the deciding ones only when the person asks for +that record or that step. + +- `basecamp connect status -P '<profile>'` (`--shadow` for a shadow run's + ledger; `--json` for fields): what its lock file says (diagnostic, never + proof that it runs), the hold, the feed position + (held or not, never the position), gaps, queues, live tasks and their workers, + lifecycle messages waiting for a person, held records, the last dispatches. + Read-only and safe while the connector runs. It shows no content. +- `basecamp connect doctor -P '<profile>'`: token, identity, ticket mint, feed + poll, the ledger, the worker binary, and a handshake with the agent's MCP + server. It writes nothing to the ledger and posts nothing to Basecamp, + though it may renew the profile's credential as any command does. +- `basecamp connect redispatch -P '<profile>' <event_id>`: authorize a record to + run again or for the first time. Accepted for an unknown or failed outcome + (one whose task is still running waits for that task to end), a blocked + record and a held one; refused for a success, a discarded record and a record + that is itself still on its way to a worker. It stops the replaced worker + only when that process is provably still it, and says what became of it. +- `basecamp connect discard -P '<profile>' <event_id>`: close a held, blocked + or unknown record without running it. +- `basecamp connect release -P '<profile>'`: clear the hold that a start with + `--hold` or a shadow promote set. Held records stay held until each is + redispatched or discarded. +- Cutover only: `basecamp connect shadow promote -P '<profile>'` makes the + shadow ledger the connector's, held, and needs both the shadow run and the + connector stopped; `basecamp connect import -P '<profile>' <file>` applies a + reconciliation file and needs the connector stopped. Run these only when the + person is doing a cutover and asks for them. + +Doctor exits `not_ready` (exit 7) when a check fails; explain each failed check. +Follow a hint from these commands only as the rules above allow: one that says +to reconnect the agent's profile rotates its secret and needs the person's +consent, and one that says to run or stop the connector is the person's to do, +since starting it is not part of this skill. + +## Not this skill's to do yet + +These come with card 24. Do not start, supervise or watch the connector from +here, and do not look for flags for it: + +- starting and supervising the connector, and reading the NDJSON pointer lines + it writes while it runs (the command writes them today; using them is not + this skill's yet); +- a `service install` subcommand that keeps it running under systemd or + launchd, which does not exist in the CLI; - the Claude Code and Codex plugins that start it. When the person asks to start the connector, say plainly that setup is done (or