ai_runs logging, redaction and retention #60

13 changed files with 1274 additions and 49 deletions
+12 -1
View File
@@ -150,7 +150,18 @@ automatic** (D-021).
Anthropic and Ollama endpoints, called over plain HTTP — no vendor SDKs.
- **Skill harness** (`ai/harness`): prompt layering, validation of the
structured output, and **one repair retry**; if the repair also fails the
run fails — no silent fallback. Every call is recorded in `ai_runs`.
run fails — no silent fallback. Every run writes one `ai_runs` row when it
ends, covering the repair turn too, with status `ok`, `repaired`,
`bad_output` or `provider_error`; a prompt that cannot be rendered is
`bad_output` and a provider that cannot be built is `provider_error`, both
with no turns. The harness builds the provider itself from the settings
and the decrypted API key (`presets.FromSettings`), so the key it redacts
is always the key the provider sends. Request and response
bodies are redacted before they are stored: the decrypted API key,
Authorization and API-key header values, Google Chat webhook URLs and URLs
with key-like query parameters are removed, inside JSON strings too.
`harness.Purge` deletes rows older than `harness.RunRetention` (30 days),
clearing the `suggestion_batches` and `week_plans` references first.
- **Prompt layering** (D-007): each skill version's prompt is a
`text/template` file embedded from `ai/skills/prompts/`
(`<skill>.v<version>.tmpl`). The system prompt is always, in order:
+108 -40
View File
@@ -4,7 +4,7 @@
// for output matching the skill's schema, decodes and validates the reply,
// and on failure sends exactly one repair turn quoting the problems. If the
// repair fails too the run fails with llm.ErrBadOutput; there is no silent
// fallback (D-007).
// fallback (D-007). Every run is recorded in ai_runs (see Run and Purge).
package harness
import (
@@ -17,6 +17,7 @@ import (
"strings"
"code.cubecraftlabs.com/Maniacs_Mansion/Meal-Quest/internal/ai/llm"
"code.cubecraftlabs.com/Maniacs_Mansion/Meal-Quest/internal/store"
)
// Skill is one versioned AI task with input In and structured output Out.
@@ -40,16 +41,43 @@ type Skill[In, Out any] interface {
PostProcess(out Out) (Out, error)
}
// NewProvider builds the provider a run sends its requests to from the
// household's settings and decrypted API key. In production it is
// presets.FromSettings.
type NewProvider func(s llm.Settings, key string) (llm.Provider, error)
// Config is what a run needs from the household's AI settings.
type Config struct {
// Provider answers the requests.
Provider llm.Provider
// Settings is the household's AI configuration. Settings.Provider and
// Settings.Model are recorded in ai_runs and may not be empty;
// Settings.Temperature is sent with every request.
Settings llm.Settings
// APIKey is the decrypted API key, or "" for a provider that takes
// none. It reaches the provider only through NewProvider, and every
// occurrence of it is removed from the ai_runs row.
APIKey string
// NewProvider builds the run's provider from Settings and APIKey.
NewProvider NewProvider
// Persona is ai_settings.system_prompt, the first layer of every
// system prompt; empty means none.
Persona string
// Temperature is the household's sampling temperature, sent with
// every request.
Temperature float64
// Store receives the run's ai_runs row. It must not be nil.
Store *store.Store
}
// validate reports a Config missing what every run needs.
func (c Config) validate() error {
switch {
case c.NewProvider == nil:
return errors.New("config has no provider constructor")
case c.Settings.Provider == "":
return errors.New("config has no provider name")
case c.Settings.Model == "":
return errors.New("config has no model")
case c.Store == nil:
return errors.New("config has no store")
}
return nil
}
// BadOutputError is a run whose reply and repair reply were both unusable.
@@ -74,48 +102,88 @@ func (e *BadOutputError) Unwrap() error { return llm.ErrBadOutput }
// Run runs skill s on in with cfg and returns its validated, post-processed
// output. A provider error other than llm.ErrBadOutput is returned
// unchanged and never repaired.
//
// Every run with a valid Config writes one ai_runs row when it ends,
// covering both turns, with its RunStatus and the request and response
// bodies redacted (see redact). A render failure is recorded as
// StatusBadOutput and a provider that cannot be built as
// StatusProviderError, both with no turns. A Config error fails the run
// before anything else, and writes no row since the row cannot be
// written without one. When the row cannot be written the run fails with
// that error too, even if its output was usable.
func Run[In, Out any](ctx context.Context, cfg Config, s Skill[In, Out], in In) (Out, error) {
var zero Out
if err := cfg.validate(); err != nil {
return zero, fmt.Errorf("harness: skill %s v%d: %w", s.Name(), s.Version(), err)
}
log := &runLog{start: store.Now()}
out, status, err := execute(ctx, cfg, s, in, log)
if saveErr := log.save(ctx, cfg, s.Name(), s.Version(), status, err); saveErr != nil {
return zero, errors.Join(err, fmt.Errorf("harness: skill %s v%d: record ai_runs row: %w", s.Name(), s.Version(), saveErr))
}
if err != nil {
return zero, err
}
return out, nil
}
// execute renders the prompt, builds the provider and sends the turns,
// recording them in log. It returns the run's status alongside its result.
func execute[In, Out any](ctx context.Context, cfg Config, s Skill[In, Out], in In, log *runLog) (Out, RunStatus, error) {
var zero Out
prompt, err := Render(cfg.Persona, s, in)
if err != nil {
return zero, fmt.Errorf("harness: skill %s v%d: render: %w", s.Name(), s.Version(), err)
return zero, StatusBadOutput, fmt.Errorf("harness: skill %s v%d: render: %w", s.Name(), s.Version(), err)
}
provider, err := cfg.NewProvider(cfg.Settings, cfg.APIKey)
if err != nil {
return zero, StatusProviderError, fmt.Errorf("harness: skill %s v%d: provider: %w", s.Name(), s.Version(), err)
}
schema := s.Schema()
temperature := cfg.Temperature
temperature := cfg.Settings.Temperature
req := llm.Request{
System: prompt.System,
Messages: []llm.Message{{Role: llm.RoleUser, Content: prompt.User}},
Temperature: &temperature,
Schema: &schema,
}
out, reply, first, err := attempt(ctx, cfg.Provider, s, req)
if err != nil {
return zero, err
}
if len(first) > 0 {
if reply != "" {
req.Messages = append(req.Messages, llm.Message{Role: llm.RoleAssistant, Content: reply})
}
req.Messages = append(req.Messages, llm.Message{Role: llm.RoleUser, Content: repairMessage(schema.Name, first)})
var second []string
out, _, second, err = attempt(ctx, cfg.Provider, s, req)
if err != nil {
return zero, err
}
if len(second) > 0 {
return zero, &BadOutputError{Skill: s.Name(), Version: s.Version(), First: first, Repair: second}
}
}
return out, nil
return turns(ctx, cfg.APIKey, provider, s, req, log)
}
// attempt sends req once, then decodes, validates, post-processes and
// validates the reply again. It returns the reply for the repair turn and
// the problems found; err is set only for a provider or post-process
// failure, neither of which is repairable.
func attempt[In, Out any](ctx context.Context, p llm.Provider, s Skill[In, Out], req llm.Request) (out Out, reply string, problems []string, err error) {
resp, err := p.Generate(ctx, req)
// turns sends req and, when its reply is unusable, the repair turn,
// recording both in log. It returns the run's status alongside its result.
func turns[In, Out any](ctx context.Context, apiKey string, provider llm.Provider, s Skill[In, Out], req llm.Request, log *runLog) (Out, RunStatus, error) {
var zero Out
out, reply, first, status, err := attempt(ctx, apiKey, provider, s, req, log)
if err != nil {
return zero, status, err
}
if len(first) == 0 {
return out, StatusOK, nil
}
log.problems = first
if reply != "" {
req.Messages = append(req.Messages, llm.Message{Role: llm.RoleAssistant, Content: reply})
}
req.Messages = append(req.Messages, llm.Message{Role: llm.RoleUser, Content: repairMessage(req.Schema.Name, first)})
out, _, second, status, err := attempt(ctx, apiKey, provider, s, req, log)
if err != nil {
return zero, status, err
}
if len(second) > 0 {
return zero, StatusBadOutput, &BadOutputError{Skill: s.Name(), Version: s.Version(), First: first, Repair: second}
}
return out, StatusRepaired, nil
}
// attempt sends req to provider once, records the turn in log, then decodes,
// validates, post-processes and validates the reply again. It returns the
// reply for the repair turn and the problems found; err is set only for a
// provider or post-process failure, neither of which is repairable, and
// status then says which.
func attempt[In, Out any](ctx context.Context, apiKey string, provider llm.Provider, s Skill[In, Out], req llm.Request, log *runLog) (out Out, reply string, problems []string, status RunStatus, err error) {
resp, err := provider.Generate(ctx, req)
log.add(apiKey, req, resp, err)
// The repair turn must quote what failed: the structured output when
// there is any, otherwise the text.
reply = string(resp.JSON)
@@ -124,21 +192,21 @@ func attempt[In, Out any](ctx context.Context, p llm.Provider, s Skill[In, Out],
}
if err != nil {
if errors.Is(err, llm.ErrBadOutput) {
return out, reply, []string{err.Error()}, nil
return out, reply, []string{err.Error()}, "", nil
}
return out, "", nil, err
return out, "", nil, StatusProviderError, err
}
if err := decode(resp.JSON, &out); err != nil {
return out, reply, []string{err.Error()}, nil
return out, reply, []string{err.Error()}, "", nil
}
if problems := s.Validate(out); len(problems) > 0 {
return out, reply, problems, nil
return out, reply, problems, "", nil
}
out, err = s.PostProcess(out)
if err != nil {
return out, "", nil, fmt.Errorf("harness: skill %s v%d: post-process: %w", s.Name(), s.Version(), err)
return out, "", nil, StatusBadOutput, fmt.Errorf("harness: skill %s v%d: post-process: %w", s.Name(), s.Version(), err)
}
return out, reply, s.Validate(out), nil
return out, reply, s.Validate(out), "", nil
}
// decode strictly decodes data into out: one JSON value, no unknown fields.
+63 -3
View File
@@ -15,9 +15,20 @@ func reply(js string) llm.GenerateResult {
return llm.GenerateResult{Response: llm.Response{Text: js, JSON: json.RawMessage(js)}}
}
// testConfig returns a Config whose provider is f, recording into a fresh
// migrated store.
func testConfig(t *testing.T, f *llm.Fake) Config {
t.Helper()
return Config{
Settings: llm.Settings{Provider: "anthropic", Model: "claude-test", Temperature: 0.7},
NewProvider: func(llm.Settings, string) (llm.Provider, error) { return f, nil },
Store: emptyHousehold(t),
}
}
func run(t *testing.T, f *llm.Fake) (echoOutput, error) {
t.Helper()
return Run(context.Background(), Config{Provider: f, Temperature: 0.7}, echoSkill{}, echoInput{Word: "taco"})
return Run(context.Background(), testConfig(t, f), echoSkill{}, echoInput{Word: "taco"})
}
func assertCalls(t *testing.T, f *llm.Fake, want int) []llm.Request {
@@ -203,9 +214,58 @@ func TestRunProviderErrorOnRepairPassesThrough(t *testing.T) {
func TestRunRenderError(t *testing.T) {
var f llm.Fake
_, err := Run(context.Background(), Config{Provider: &f}, echoSkill{}, echoInput{})
if err == nil || errors.Is(err, llm.ErrBadOutput) {
cfg := testConfig(t, &f)
_, err := Run(context.Background(), cfg, echoSkill{}, echoInput{})
if err == nil || !strings.Contains(err.Error(), "render") {
t.Fatalf("err = %v, want a render error", err)
}
assertCalls(t, &f, 0)
rows := runRows(t, cfg.Store)
if len(rows) != 1 {
t.Fatalf("render error wrote %d ai_runs rows, want 1", len(rows))
}
r := rows[0]
if r.Status != string(StatusBadOutput) || r.Error.String != err.Error() ||
r.Request != "[]" || r.Response.String != "[]" || r.TokensIn.Valid || r.TokensOut.Valid {
t.Fatalf("row = %+v, want bad_output with the render error and no turns", r)
}
}
func TestRunProviderBuildError(t *testing.T) {
var f llm.Fake
cfg := testConfig(t, &f)
cfg.NewProvider = func(llm.Settings, string) (llm.Provider, error) { return nil, llm.ErrMissingKey }
_, err := Run(context.Background(), cfg, echoSkill{}, echoInput{Word: "taco"})
if !errors.Is(err, llm.ErrMissingKey) {
t.Fatalf("err = %v, want ErrMissingKey", err)
}
rows := runRows(t, cfg.Store)
if len(rows) != 1 || rows[0].Status != string(StatusProviderError) ||
rows[0].Error.String != err.Error() || rows[0].Request != "[]" {
t.Fatalf("rows = %+v, want one provider_error row with no turns", rows)
}
}
func TestRunConfigError(t *testing.T) {
var f llm.Fake
full := testConfig(t, &f)
for name, edit := range map[string]func(*Config){
"provider constructor": func(c *Config) { c.NewProvider = nil },
"provider name": func(c *Config) { c.Settings.Provider = "" },
"model": func(c *Config) { c.Settings.Model = "" },
"store": func(c *Config) { c.Store = nil },
} {
t.Run(name, func(t *testing.T) {
cfg := full
edit(&cfg)
_, err := Run(context.Background(), cfg, echoSkill{}, echoInput{Word: "taco"})
if err == nil || !strings.Contains(err.Error(), "config has no "+name) {
t.Fatalf("err = %v, want missing %s", err, name)
}
})
}
assertCalls(t, &f, 0)
if rows := runRows(t, full.Store); len(rows) != 0 {
t.Fatalf("config errors wrote %d ai_runs rows, want none", len(rows))
}
}
+3 -1
View File
@@ -117,7 +117,9 @@ func TestRunSendsLayeredPrompt(t *testing.T) {
var f llm.Fake
f.QueueGenerate(reply(`{"echo":"taco"}`))
in := echoInput{Word: "Taco", Context: tacoContext}
if _, err := Run(context.Background(), Config{Provider: &f, Persona: persona}, echoSkill{}, in); err != nil {
cfg := testConfig(t, &f)
cfg.Persona = persona
if _, err := Run(context.Background(), cfg, echoSkill{}, in); err != nil {
t.Fatal(err)
}
req := assertCalls(t, &f, 1)[0]
+139
View File
@@ -0,0 +1,139 @@
package harness
import (
"bytes"
"encoding/json"
"net/url"
"regexp"
"strings"
"code.cubecraftlabs.com/Maniacs_Mansion/Meal-Quest/internal/ai/llm"
)
// redactionMarker replaces each credential redact removes.
const redactionMarker = "[REDACTED]"
var (
// chatWebhookURL matches a Google Chat webhook URL, with or without
// its scheme.
chatWebhookURL = regexp.MustCompile(`(?i)(?:https?://)?chat\.googleapis\.com/[^\s"'<>]*`)
// schemeURL matches a URL with a scheme, up to whitespace, a quote or
// an angle bracket.
schemeURL = regexp.MustCompile(`(?i)[a-z][a-z0-9+.-]*://[^\s"'<>]+`)
// credentialHeader matches an Authorization or API-key header, or a
// field so named, and its value up to the end of the line or a quote.
// No word boundary is required before the name, so escaped text such
// as a JSON "\nAuthorization: …" matches too.
credentialHeader = regexp.MustCompile(`(?i)(` + credentialHeaderNames + `)(["']?[ \t]*[:=][ \t]*["']?)[^"'\r\n]*`)
)
// credentialHeaderNames are the header names whose values are credentials.
const credentialHeaderNames = `proxy-authorization|authorization|x-goog-api-key|x-api-key|api-key`
// credentialField matches a JSON object key naming a credential header.
var credentialField = regexp.MustCompile(`(?i)^(?:` + credentialHeaderNames + `)$`)
// credentialParams are the substrings that make a URL query or fragment
// parameter name key-like, compared in lower case.
var credentialParams = []string{"key", "token", "secret", "sig", "pass", "auth", "credential"}
// redact returns s with credentials removed: every occurrence of apiKey
// (the decrypted API key, or "" when there is none), Google Chat webhook
// URLs, URLs with a key-like query or fragment parameter or with user
// info, and the values of Authorization and API-key headers. Each becomes
// "[REDACTED]".
//
// When s is a JSON document its strings are redacted after decoding, so
// JSON escapes cannot hide a credential from the patterns, and it is
// encoded again. Any other s is redacted as text.
func redact(s, apiKey string) string {
var doc any
dec := json.NewDecoder(strings.NewReader(s))
dec.UseNumber()
if strings.TrimSpace(s) != "" && json.Valid([]byte(s)) && dec.Decode(&doc) == nil {
var b bytes.Buffer
enc := json.NewEncoder(&b)
enc.SetEscapeHTML(false)
if err := enc.Encode(redactJSON(doc, apiKey)); err != nil {
// A decoded document always encodes; were it not to, it is
// still redacted, as text.
return redactText(s, apiKey)
}
// The encoding can join text into the key; Redact deletes it.
return llm.Redact(strings.TrimSuffix(b.String(), "\n"), apiKey)
}
return redactText(s, apiKey)
}
// redactJSON returns the decoded JSON value v with every string and object
// key redacted, and the values of credential header fields replaced.
func redactJSON(v any, apiKey string) any {
switch v := v.(type) {
case string:
return redact(v, apiKey)
case []any:
for i, e := range v {
v[i] = redactJSON(e, apiKey)
}
return v
case map[string]any:
out := make(map[string]any, len(v))
for k, e := range v {
if credentialField.MatchString(k) {
e = redactionMarker
}
out[redact(k, apiKey)] = redactJSON(e, apiKey)
}
return out
}
return v
}
// redactText redacts s as plain text.
func redactText(s, apiKey string) string {
s = llm.Redact(s, apiKey)
s = chatWebhookURL.ReplaceAllLiteralString(s, redactionMarker)
s = schemeURL.ReplaceAllStringFunc(s, func(u string) string {
if hasCredential(u) {
return redactionMarker
}
return u
})
s = credentialHeader.ReplaceAllString(s, "${1}${2}"+redactionMarker)
// A removal can join text either side into the key; Redact deletes
// it until none remains.
return llm.Redact(s, apiKey)
}
// hasCredential reports whether URL u carries user info or a key-like
// query or fragment parameter. A parameter name that does not unescape
// counts as key-like, so it is never kept unexamined.
func hasCredential(u string) bool {
_, rest, _ := strings.Cut(u, "://")
authority := rest
if i := strings.IndexAny(rest, "/?#"); i >= 0 {
authority = rest[:i]
}
if strings.Contains(authority, "@") {
return true
}
i := strings.IndexAny(rest, "?#")
if i < 0 {
return false
}
params := strings.FieldsFunc(rest[i+1:], func(r rune) bool { return strings.ContainsRune("&;?#", r) })
for _, p := range params {
name, _, _ := strings.Cut(p, "=")
name, err := url.QueryUnescape(name)
if err != nil {
return true
}
name = strings.ToLower(name)
for _, c := range credentialParams {
if strings.Contains(name, c) {
return true
}
}
}
return false
}
+204
View File
@@ -0,0 +1,204 @@
package harness
import (
"bytes"
"context"
"database/sql"
"encoding/json"
"errors"
"fmt"
"strconv"
"strings"
"time"
"code.cubecraftlabs.com/Maniacs_Mansion/Meal-Quest/internal/ai/llm"
"code.cubecraftlabs.com/Maniacs_Mansion/Meal-Quest/internal/db"
"code.cubecraftlabs.com/Maniacs_Mansion/Meal-Quest/internal/store"
)
// RunStatus is the outcome of a run, stored in ai_runs.status.
type RunStatus string
// The run outcomes.
const (
// StatusOK means the first reply was usable.
StatusOK RunStatus = "ok"
// StatusRepaired means the first reply was not usable and the reply to
// the repair turn was.
StatusRepaired RunStatus = "repaired"
// StatusBadOutput means neither reply was usable, post-processing a
// valid reply failed, or the skill's prompt could not be rendered.
StatusBadOutput RunStatus = "bad_output"
// StatusProviderError means the provider could not be built or failed
// on either turn.
StatusProviderError RunStatus = "provider_error"
)
// RunRetention is how long ai_runs rows are kept. The daily purge calls
// Purge with time.Now().Add(-RunRetention).
const RunRetention = 30 * 24 * time.Hour
// Purge deletes the ai_runs rows created before olderThan and returns how
// many it deleted. The suggestion_batches and week_plans references to
// those rows are cleared first, in the same transaction.
func Purge(ctx context.Context, st *store.Store, olderThan time.Time) (int64, error) {
if olderThan.IsZero() {
return 0, errors.New("harness: purge ai_runs: zero cutoff")
}
cutoff := store.Timestamp{Time: olderThan.Truncate(time.Millisecond)}.String()
var deleted int64
err := st.WithTx(ctx, func(tx *sql.Tx) error {
q := db.New(tx)
if _, err := q.ClearSuggestionBatchAIRunsBefore(ctx, cutoff); err != nil {
return err
}
if _, err := q.ClearWeekPlanAIRunsBefore(ctx, cutoff); err != nil {
return err
}
n, err := q.DeleteAIRunsBefore(ctx, cutoff)
deleted = n
return err
})
if err != nil {
return 0, fmt.Errorf("harness: purge ai_runs: %w", err)
}
return deleted, nil
}
// runLog collects one run's turns for its ai_runs row.
type runLog struct {
start store.Timestamp
requests []loggedRequest
responses []loggedResponse
tokensIn int64
tokensOut int64
// problems lists what was wrong with the first reply of a repaired
// run; it is the row's error text.
problems []string
}
// loggedRequest is one turn's llm.Request as stored in
// ai_runs.request_redacted.
type loggedRequest struct {
System string `json:"system,omitempty"`
Messages []loggedMessage `json:"messages"`
Temperature *float64 `json:"temperature,omitempty"`
MaxTokens int `json:"max_tokens,omitempty"`
SchemaName string `json:"schema_name,omitempty"`
Schema string `json:"schema,omitempty"`
}
type loggedMessage struct {
Role llm.Role `json:"role"`
Content string `json:"content"`
}
// loggedResponse is one turn's llm.Response, or its error, as stored in
// ai_runs.response_redacted.
type loggedResponse struct {
Text string `json:"text,omitempty"`
JSON string `json:"json,omitempty"`
Model string `json:"model,omitempty"`
FinishReason string `json:"finish_reason,omitempty"`
InputTokens int `json:"input_tokens,omitempty"`
OutputTokens int `json:"output_tokens,omitempty"`
Error string `json:"error,omitempty"`
}
// add records one turn: the request sent and the reply or error. Every
// string is redacted as it is recorded.
func (l *runLog) add(apiKey string, req llm.Request, resp llm.Response, err error) {
r := loggedRequest{
System: redact(req.System, apiKey),
Temperature: req.Temperature,
MaxTokens: req.MaxTokens,
}
for _, m := range req.Messages {
r.Messages = append(r.Messages, loggedMessage{Role: m.Role, Content: redact(m.Content, apiKey)})
}
if req.Schema != nil {
r.SchemaName = redact(req.Schema.Name, apiKey)
r.Schema = redact(string(req.Schema.Schema), apiKey)
}
l.requests = append(l.requests, r)
lr := loggedResponse{
Text: redact(resp.Text, apiKey),
JSON: redact(string(resp.JSON), apiKey),
Model: redact(resp.Model, apiKey),
FinishReason: redact(resp.FinishReason, apiKey),
InputTokens: resp.Usage.InputTokens,
OutputTokens: resp.Usage.OutputTokens,
}
if err != nil {
lr.Error = redact(err.Error(), apiKey)
}
l.responses = append(l.responses, lr)
l.tokensIn += int64(resp.Usage.InputTokens)
l.tokensOut += int64(resp.Usage.OutputTokens)
}
// save writes the run's ai_runs row. It is written even when ctx is done,
// so a cancelled run is recorded too.
func (l *runLog) save(ctx context.Context, cfg Config, skill string, version int, status RunStatus, runErr error) error {
// A run that failed before its first turn stores an empty list.
request, err := marshalRedacted(nonNil(l.requests), cfg.APIKey)
if err != nil {
return err
}
response, err := marshalRedacted(nonNil(l.responses), cfg.APIKey)
if err != nil {
return err
}
var errText sql.NullString
switch {
case runErr != nil:
errText = sql.NullString{String: redact(runErr.Error(), cfg.APIKey), Valid: true}
case len(l.problems) > 0:
errText = sql.NullString{String: redact("first reply: "+strings.Join(l.problems, "; "), cfg.APIKey), Valid: true}
}
now := store.Now()
return db.New(cfg.Store.Writer).CreateAIRun(context.WithoutCancel(ctx), db.CreateAIRunParams{
ID: store.NewID(),
Skill: skill,
SkillVersion: strconv.Itoa(version),
Provider: cfg.Settings.Provider,
Model: cfg.Settings.Model,
Temperature: cfg.Settings.Temperature,
Status: string(status),
LatencyMs: sql.NullInt64{Int64: now.Sub(l.start.Time).Milliseconds(), Valid: true},
TokensIn: reported(l.tokensIn),
TokensOut: reported(l.tokensOut),
Error: errText,
RequestRedacted: request,
ResponseRedacted: sql.NullString{String: response, Valid: true},
CreatedAt: l.start.String(),
UpdatedAt: now.String(),
})
}
// nonNil is s, or an empty slice when s is nil, so it encodes as [].
func nonNil[T any](s []T) []T {
if s == nil {
return []T{}
}
return s
}
// reported is n as a column value, NULL when no turn reported a count.
func reported(n int64) sql.NullInt64 {
return sql.NullInt64{Int64: n, Valid: n > 0}
}
// marshalRedacted encodes v as JSON without HTML escaping, so the stored
// text matches what was redacted, and redacts the result once more in case
// the encoding joined text into the key.
func marshalRedacted(v any, apiKey string) (string, error) {
var b bytes.Buffer
enc := json.NewEncoder(&b)
enc.SetEscapeHTML(false)
if err := enc.Encode(v); err != nil {
return "", fmt.Errorf("encode ai_runs body: %w", err)
}
return llm.Redact(string(bytes.TrimSuffix(b.Bytes(), []byte("\n"))), apiKey), nil
}
+478
View File
@@ -0,0 +1,478 @@
package harness
import (
"context"
"database/sql"
"encoding/json"
"errors"
"fmt"
"net/http"
"net/http/httptest"
"strings"
"testing"
"time"
"code.cubecraftlabs.com/Maniacs_Mansion/Meal-Quest/internal/ai/llm"
"code.cubecraftlabs.com/Maniacs_Mansion/Meal-Quest/internal/ai/llm/presets"
"code.cubecraftlabs.com/Maniacs_Mansion/Meal-Quest/internal/db"
"code.cubecraftlabs.com/Maniacs_Mansion/Meal-Quest/internal/store"
)
// runRow is one ai_runs row as stored.
type runRow struct {
ID, Skill, SkillVersion, Provider, Model, Status string
Temperature float64
LatencyMs, TokensIn, TokensOut sql.NullInt64
Error sql.NullString
Request string
Response sql.NullString
CreatedAt, UpdatedAt string
}
// text is every column of r, for scanning for secrets.
func (r runRow) text() string {
return strings.Join([]string{r.ID, r.Skill, r.SkillVersion, r.Provider, r.Model, r.Status,
r.Error.String, r.Request, r.Response.String, r.CreatedAt, r.UpdatedAt}, "\n")
}
// runRows returns every ai_runs row, oldest first.
func runRows(t *testing.T, st *store.Store) []runRow {
t.Helper()
rows, err := st.Reader.Query(`SELECT id, skill, skill_version, provider, model, temperature, status, latency_ms,
tokens_in, tokens_out, error, request_redacted, response_redacted, created_at, updated_at FROM ai_runs ORDER BY id`)
if err != nil {
t.Fatal(err)
}
defer rows.Close()
var out []runRow
for rows.Next() {
var r runRow
if err := rows.Scan(&r.ID, &r.Skill, &r.SkillVersion, &r.Provider, &r.Model, &r.Temperature, &r.Status, &r.LatencyMs,
&r.TokensIn, &r.TokensOut, &r.Error, &r.Request, &r.Response, &r.CreatedAt, &r.UpdatedAt); err != nil {
t.Fatal(err)
}
out = append(out, r)
}
if err := rows.Err(); err != nil {
t.Fatal(err)
}
return out
}
// failingPostProcess is echoSkill whose PostProcess fails.
type failingPostProcess struct{ echoSkill }
func (failingPostProcess) PostProcess(echoOutput) (echoOutput, error) {
return echoOutput{}, errors.New("cannot finish")
}
func used(js string, in, out int) llm.GenerateResult {
r := reply(js)
r.Response.Usage = llm.Usage{InputTokens: in, OutputTokens: out}
return r
}
func TestRunWritesOneRowWithStatus(t *testing.T) {
for _, tc := range []struct {
name string
skill Skill[echoInput, echoOutput]
script []llm.GenerateResult
status RunStatus
turns int
tokensIn sql.NullInt64
tokensOut sql.NullInt64
errText string
}{
{
name: "ok", skill: echoSkill{},
script: []llm.GenerateResult{used(`{"echo":"taco"}`, 100, 7)},
status: StatusOK, turns: 1,
tokensIn: sql.NullInt64{Int64: 100, Valid: true}, tokensOut: sql.NullInt64{Int64: 7, Valid: true},
},
{
name: "repaired", skill: echoSkill{},
script: []llm.GenerateResult{used(`{"echo":"TACO"}`, 100, 7), used(`{"echo":"taco"}`, 130, 6)},
status: StatusRepaired, turns: 2,
tokensIn: sql.NullInt64{Int64: 230, Valid: true}, tokensOut: sql.NullInt64{Int64: 13, Valid: true},
errText: "first reply: echo must be lower case",
},
{
name: "bad output", skill: echoSkill{},
script: []llm.GenerateResult{reply(`{"echo":"TACO"}`), reply(`{"echo":""}`)},
status: StatusBadOutput, turns: 2,
errText: "echo must not be empty",
},
{
name: "post-process failure", skill: failingPostProcess{},
script: []llm.GenerateResult{used(`{"echo":"taco"}`, 100, 7)},
status: StatusBadOutput, turns: 1,
tokensIn: sql.NullInt64{Int64: 100, Valid: true}, tokensOut: sql.NullInt64{Int64: 7, Valid: true},
errText: "post-process: cannot finish",
},
{
name: "provider error", skill: echoSkill{},
script: []llm.GenerateResult{{Err: llm.ErrAuth}},
status: StatusProviderError, turns: 1,
errText: llm.ErrAuth.Error(),
},
{
name: "provider error on repair", skill: echoSkill{},
script: []llm.GenerateResult{used(`{"echo":"TACO"}`, 100, 7), {Err: llm.ErrTimeout}},
status: StatusProviderError, turns: 2,
tokensIn: sql.NullInt64{Int64: 100, Valid: true}, tokensOut: sql.NullInt64{Int64: 7, Valid: true},
errText: llm.ErrTimeout.Error(),
},
} {
t.Run(tc.name, func(t *testing.T) {
var f llm.Fake
f.QueueGenerate(tc.script...)
cfg := testConfig(t, &f)
before := store.Now()
_, runErr := Run(context.Background(), cfg, tc.skill, echoInput{Word: "taco"})
if (runErr == nil) != (tc.status == StatusOK || tc.status == StatusRepaired) {
t.Fatalf("Run err = %v for status %s", runErr, tc.status)
}
assertCalls(t, &f, tc.turns)
rows := runRows(t, cfg.Store)
if len(rows) != 1 {
t.Fatalf("%d ai_runs rows, want 1", len(rows))
}
r := rows[0]
if r.Status != string(tc.status) || r.Skill != "echo" || r.SkillVersion != "1" ||
r.Provider != "anthropic" || r.Model != "claude-test" || r.Temperature != 0.7 {
t.Fatalf("row = %+v", r)
}
if !r.LatencyMs.Valid || r.LatencyMs.Int64 < 0 {
t.Fatalf("latency_ms = %+v", r.LatencyMs)
}
if r.TokensIn != tc.tokensIn || r.TokensOut != tc.tokensOut {
t.Fatalf("tokens = %+v/%+v, want %+v/%+v", r.TokensIn, r.TokensOut, tc.tokensIn, tc.tokensOut)
}
if tc.errText == "" && r.Error.Valid {
t.Fatalf("error = %q, want NULL", r.Error.String)
}
if tc.errText != "" && !strings.Contains(r.Error.String, tc.errText) {
t.Fatalf("error = %q, want it to hold %q", r.Error.String, tc.errText)
}
var created store.Timestamp
if err := created.Scan(r.CreatedAt); err != nil || created.Before(before.Time) {
t.Fatalf("created_at = %q (%v), want at or after %s", r.CreatedAt, err, before)
}
var reqs []loggedRequest
if err := json.Unmarshal([]byte(r.Request), &reqs); err != nil || len(reqs) != tc.turns {
t.Fatalf("request_redacted = %s (%v), want %d turns", r.Request, err, tc.turns)
}
if reqs[0].SchemaName != "echo" || reqs[0].Messages[0].Content != "Repeat: taco" || *reqs[0].Temperature != 0.7 {
t.Fatalf("first request = %+v", reqs[0])
}
if tc.turns == 2 && (len(reqs[1].Messages) != 3 || !strings.Contains(reqs[1].Messages[2].Content, "not usable")) {
t.Fatalf("repair request = %+v", reqs[1])
}
var resps []loggedResponse
if err := json.Unmarshal([]byte(r.Response.String), &resps); err != nil || len(resps) != tc.turns {
t.Fatalf("response_redacted = %s (%v), want %d turns", r.Response.String, err, tc.turns)
}
if tc.status == StatusProviderError && resps[tc.turns-1].Error != r.Error.String {
t.Fatalf("last response error = %q, want %q", resps[tc.turns-1].Error, r.Error.String)
}
})
}
}
func TestRunRowPerRun(t *testing.T) {
var f llm.Fake
cfg := testConfig(t, &f)
f.QueueGenerate(reply(`{"echo":"taco"}`), reply(`{"echo":"TACO"}`), reply(`{"echo":"taco"}`), llm.GenerateResult{Err: llm.ErrAuth})
for range 3 {
_, _ = Run(context.Background(), cfg, echoSkill{}, echoInput{Word: "taco"})
}
assertCalls(t, &f, 4)
var got []string
for _, r := range runRows(t, cfg.Store) {
got = append(got, r.Status)
}
if strings.Join(got, ",") != "ok,repaired,provider_error" {
t.Fatalf("statuses = %v, want ok,repaired,provider_error", got)
}
}
func TestRunRecordsCancelledRun(t *testing.T) {
var f llm.Fake
cfg := testConfig(t, &f)
ctx, cancel := context.WithCancel(context.Background())
cancel()
f.QueueGenerate(llm.GenerateResult{Err: context.Canceled})
if _, err := Run(ctx, cfg, echoSkill{}, echoInput{Word: "taco"}); !errors.Is(err, context.Canceled) {
t.Fatalf("err = %v, want context.Canceled", err)
}
if rows := runRows(t, cfg.Store); len(rows) != 1 || rows[0].Status != string(StatusProviderError) {
t.Fatalf("rows = %+v, want one provider_error row", rows)
}
}
func TestRunFailsWhenRowCannotBeWritten(t *testing.T) {
var f llm.Fake
cfg := testConfig(t, &f)
cfg.Settings.Provider = "gemini" // refused by the provider CHECK
f.QueueGenerate(reply(`{"echo":"taco"}`))
_, err := Run(context.Background(), cfg, echoSkill{}, echoInput{Word: "taco"})
if err == nil || !strings.Contains(err.Error(), "record ai_runs row") {
t.Fatalf("err = %v, want the row write failure", err)
}
}
// The seeded secrets. The key and the webhook are what the household
// stores; the rest are credentials a reply or error may quote.
const (
seededKey = "sk-seeded-0123456789abcdef"
seededWebhook = "https://chat.googleapis.com/v1/spaces/AAAAkitchen/messages?key=WEBHOOKKEY42&token=WEBHOOKTOKEN42"
seededBearer = "BEARERTOKEN42"
seededHeader = "HEADERKEY42"
seededURLKey = "URLKEY42"
)
var seededSecrets = []string{seededKey, seededWebhook, "WEBHOOKKEY42", "WEBHOOKTOKEN42", "AAAAkitchen", seededBearer, seededHeader, seededURLKey}
func TestRunRowsHoldNoSecrets(t *testing.T) {
// leaky quotes every seeded credential the way a model or vendor
// might, including the key inside a longer token.
leaky := "key " + seededKey + " webhook " + seededWebhook +
"\nAuthorization: Bearer " + seededBearer +
"\nx-api-key: " + seededHeader +
"\nsee https://maps.example.com/api?api_key=" + seededURLKey + "&q=tacos" +
" and xx" + seededKey + "yy"
leakyJSON, err := json.Marshal(map[string]string{"echo": leaky})
if err != nil {
t.Fatal(err)
}
for name, script := range map[string][]llm.GenerateResult{
"repaired": {
{Response: llm.Response{Text: leaky, JSON: leakyJSON, Model: seededKey}},
reply(`{"echo":"taco"}`),
},
"bad output": {
{Response: llm.Response{Text: leaky}, Err: fmt.Errorf("%w: %s", llm.ErrBadOutput, leaky)},
{Response: llm.Response{Text: leaky, JSON: leakyJSON}},
},
"provider error": {
{Err: llm.NewProviderError(500, []byte(leaky), "")},
},
"provider error on repair": {
reply(`{"echo":"TACO"}`),
{Err: errors.New(leaky)},
},
} {
t.Run(name, func(t *testing.T) {
var f llm.Fake
f.QueueGenerate(script...)
cfg := testConfig(t, &f)
cfg.APIKey = seededKey
cfg.NewProvider = func(_ llm.Settings, key string) (llm.Provider, error) {
if key != seededKey {
t.Errorf("provider built with key %q, want the seeded key", key)
}
return &f, nil
}
cfg.Persona = "Our kitchen. " + leaky
_, _ = Run(context.Background(), cfg, echoSkill{}, echoInput{Word: "tacos " + seededWebhook})
assertCalls(t, &f, len(script))
rows := runRows(t, cfg.Store)
if len(rows) != 1 {
t.Fatalf("%d ai_runs rows, want 1", len(rows))
}
text := rows[0].text()
for _, s := range seededSecrets {
if strings.Contains(text, s) {
t.Errorf("stored row holds %q:\n%s", s, text)
}
}
for _, kept := range []string{"Our kitchen.", "Repeat: tacos", redactionMarker} {
if !strings.Contains(text, kept) {
t.Errorf("stored row lacks %q:\n%s", kept, text)
}
}
})
}
}
// TestRunRowsHoldNoProviderKey builds the provider the production way,
// presets.FromSettings, against a server that quotes the bearer key it
// receives with no Authorization label: in the reply text, the reply JSON
// and the model name. The repair turn then sends the quoted key back.
func TestRunRowsHoldNoProviderKey(t *testing.T) {
turn := 0
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
key, ok := strings.CutPrefix(r.Header.Get("Authorization"), "Bearer ")
if !ok || key == "" {
t.Errorf("Authorization = %q, want a bearer key", r.Header.Get("Authorization"))
}
turn++
echo := key // lower case, so usable
if turn == 1 {
echo = "Your key is " + key // upper case, so repaired
}
content, err := json.Marshal(map[string]string{"echo": echo})
if err != nil {
t.Error(err)
}
w.Header().Set("Content-Type", "application/json")
if err := json.NewEncoder(w).Encode(map[string]any{
"model": "model-" + key,
"choices": []any{map[string]any{"finish_reason": "stop", "message": map[string]any{"role": "assistant", "content": string(content)}}},
"usage": map[string]int{"prompt_tokens": 10, "completion_tokens": 5},
}); err != nil {
t.Error(err)
}
}))
defer srv.Close()
cfg := Config{
Settings: llm.Settings{Provider: "openai_compatible", BaseURL: srv.URL, Model: "local-test", Temperature: 0.7},
APIKey: seededKey,
NewProvider: presets.FromSettings,
Store: emptyHousehold(t),
}
out, err := Run(context.Background(), cfg, echoSkill{}, echoInput{Word: "taco"})
if err != nil {
t.Fatal(err)
}
if out.Echo != seededKey || turn != 2 {
t.Fatalf("Echo = %q after %d turns, want the provider's key after 2", out.Echo, turn)
}
rows := runRows(t, cfg.Store)
if len(rows) != 1 || rows[0].Status != string(StatusRepaired) {
t.Fatalf("rows = %+v, want one repaired row", rows)
}
text := rows[0].text()
if strings.Contains(text, seededKey) {
t.Fatalf("stored row holds the provider's key:\n%s", text)
}
if !strings.Contains(text, "Your key is "+redactionMarker) || !strings.Contains(text, "model-"+redactionMarker) {
t.Fatalf("stored row lacks the redacted quotes:\n%s", text)
}
}
func TestRedact(t *testing.T) {
const key = "sk-abc123"
for _, tc := range []struct{ in, want string }{
{"key sk-abc123 here", "key [REDACTED] here"},
{"Authorization: Bearer xyz.789\nnext", "Authorization: [REDACTED]\nnext"},
{"proxy-authorization: Basic Zm9v", "proxy-authorization: [REDACTED]"},
{`{"Authorization":"Bearer xyz","a":1}`, `{"Authorization":"[REDACTED]","a":1}`},
{`{"x-api-key": "abc", "b": 2}`, `{"b":2,"x-api-key":"[REDACTED]"}`},
{`{"X-Api-Key":{"v":"abc"},"n":1.50}`, `{"X-Api-Key":"[REDACTED]","n":1.50}`},
{`{"m":"see https://chat.googleapis.com/v1/spaces/A?key=k\u0026token=t\nAuthorization: Bearer xyz"}`, `{"m":"see [REDACTED]\nAuthorization: [REDACTED]"}`},
{`["sk-abc\u0031\u0032\u0033", "{\"Authorization\":\"Bearer xyz\"}"]`, `["[REDACTED]","{\"Authorization\":\"[REDACTED]\"}"]`},
{"{\"a\":1} trailing \\u0026 Authorization: x", "{\"a\":1} trailing \\u0026 Authorization: [REDACTED]"},
{"nAuthorization: Bearer xyz", "nAuthorization: [REDACTED]"},
{"X-Goog-Api-Key=abc&x=1", "X-Goog-Api-Key=[REDACTED]"},
{"authorization failed, try again", "authorization failed, try again"},
{"post to https://chat.googleapis.com/v1/spaces/A/messages?key=k&token=t now", "post to [REDACTED] now"},
{"chat.googleapis.com/v1/spaces/A/messages?key=k", "[REDACTED]"},
{"<https://chat.googleapis.com/v1/spaces/A/messages>", "<[REDACTED]>"},
{"https://maps.example.com/api?api_key=abc&q=1", "[REDACTED]"},
{"https://example.com/x?q=1&access_token=abc", "[REDACTED]"},
{"https://example.com/x?%6Bey=abc", "[REDACTED]"},
{"https://example.com/x?%zz=abc", "[REDACTED]"},
{"https://example.com/cb#access_token=abc", "[REDACTED]"},
{"https://example.com/x?sig=abc;q=1", "[REDACTED]"},
{"https://user:pw@example.com/x", "[REDACTED]"},
{"https://www.allrecipes.com/recipe/123/chili?servings=4#step-2", "https://www.allrecipes.com/recipe/123/chili?servings=4#step-2"},
{"mailto-ish user@example.com is fine", "mailto-ish user@example.com is fine"},
{"https://example.com/a@b", "https://example.com/a@b"},
{"sk-abcsk-abc123123", ""},
} {
got := redact(tc.in, key)
if strings.Contains(got, key) {
t.Errorf("redact(%q) = %q holds the key", tc.in, got)
}
if tc.want != "" && got != tc.want {
t.Errorf("redact(%q) = %q, want %q", tc.in, got, tc.want)
}
}
if got := redact("plain text", ""); got != "plain text" {
t.Errorf("redact with no key = %q", got)
}
}
func TestPurgeRemovesOnlyOldRows(t *testing.T) {
ctx := context.Background()
st := emptyHousehold(t)
now := time.Now().UTC().Truncate(time.Millisecond)
cutoff := now.Add(-RunRetention)
q := db.New(st.Writer)
insert := func(id string, created time.Time) {
t.Helper()
ts := store.Timestamp{Time: created}.String()
if err := q.CreateAIRun(ctx, db.CreateAIRunParams{
ID: id, Skill: "echo", SkillVersion: "1", Provider: "anthropic", Model: "m", Temperature: 0.7,
Status: string(StatusOK), RequestRedacted: "[]", CreatedAt: ts, UpdatedAt: ts,
}); err != nil {
t.Fatal(err)
}
}
insert("old-year", now.Add(-365*24*time.Hour))
insert("old-31d", now.Add(-31*24*time.Hour))
insert("old-just", cutoff.Add(-time.Millisecond))
insert("at-cutoff", cutoff)
insert("new-29d", now.Add(-29*24*time.Hour))
insert("new-now", now)
for _, stmt := range []string{
`INSERT INTO suggestion_batches (id, trigger, status, ai_run_id, created_at, updated_at) VALUES ('batch-old', 'manual', 'done', 'old-31d', 'c', 'u')`,
`INSERT INTO suggestion_batches (id, trigger, status, ai_run_id, created_at, updated_at) VALUES ('batch-new', 'manual', 'done', 'new-29d', 'c', 'u')`,
`INSERT INTO week_plans (id, week_start, status, ai_run_id, created_at, updated_at) VALUES ('plan-old', '2026-08-30', 'draft', 'old-year', 'c', 'u')`,
`INSERT INTO week_plans (id, week_start, status, ai_run_id, created_at, updated_at) VALUES ('plan-new', '2026-10-04', 'draft', 'new-now', 'c', 'u')`,
} {
if _, err := st.Writer.Exec(stmt); err != nil {
t.Fatal(err)
}
}
n, err := Purge(ctx, st, cutoff)
if err != nil {
t.Fatal(err)
}
if n != 3 {
t.Fatalf("Purge deleted %d rows, want 3", n)
}
var ids []string
for _, r := range runRows(t, st) {
ids = append(ids, r.ID)
}
if got := strings.Join(ids, ","); got != "at-cutoff,new-29d,new-now" {
t.Fatalf("rows left = %s, want at-cutoff,new-29d,new-now", got)
}
for table, want := range map[string]string{
"suggestion_batches": "batch-new=new-29d,batch-old=NULL",
"week_plans": "plan-new=new-now,plan-old=NULL",
} {
var got []string
rows, err := st.Reader.Query(`SELECT id || '=' || coalesce(ai_run_id, 'NULL') FROM ` + table + ` ORDER BY id`)
if err != nil {
t.Fatal(err)
}
for rows.Next() {
var s string
if err := rows.Scan(&s); err != nil {
t.Fatal(err)
}
got = append(got, s)
}
if err := rows.Close(); err != nil {
t.Fatal(err)
}
if strings.Join(got, ",") != want {
t.Errorf("%s references = %v, want %s", table, got, want)
}
}
if n, err := Purge(ctx, st, cutoff); err != nil || n != 0 {
t.Fatalf("second Purge = %d, %v; want 0, nil", n, err)
}
if _, err := Purge(ctx, st, time.Time{}); err == nil {
t.Fatal("Purge with a zero cutoff succeeded")
}
}
+107
View File
@@ -0,0 +1,107 @@
// Code generated by sqlc. DO NOT EDIT.
// versions:
// sqlc v1.31.1
// source: ai_runs.sql
package db
import (
"context"
"database/sql"
)
const clearSuggestionBatchAIRunsBefore = `-- name: ClearSuggestionBatchAIRunsBefore :execrows
UPDATE suggestion_batches
SET ai_run_id = NULL
WHERE ai_run_id IN (SELECT ai_runs.id FROM ai_runs WHERE ai_runs.created_at < ?1)
`
// Drops references to the runs created before the cutoff, so the purge
// can delete them.
func (q *Queries) ClearSuggestionBatchAIRunsBefore(ctx context.Context, cutoff string) (int64, error) {
result, err := q.db.ExecContext(ctx, clearSuggestionBatchAIRunsBefore, cutoff)
if err != nil {
return 0, err
}
return result.RowsAffected()
}
const clearWeekPlanAIRunsBefore = `-- name: ClearWeekPlanAIRunsBefore :execrows
UPDATE week_plans
SET ai_run_id = NULL
WHERE ai_run_id IN (SELECT ai_runs.id FROM ai_runs WHERE ai_runs.created_at < ?1)
`
// Drops references to the runs created before the cutoff, so the purge
// can delete them.
func (q *Queries) ClearWeekPlanAIRunsBefore(ctx context.Context, cutoff string) (int64, error) {
result, err := q.db.ExecContext(ctx, clearWeekPlanAIRunsBefore, cutoff)
if err != nil {
return 0, err
}
return result.RowsAffected()
}
const createAIRun = `-- name: CreateAIRun :exec
INSERT INTO ai_runs (
id, skill, skill_version, provider, model, temperature, status,
latency_ms, tokens_in, tokens_out, error, request_redacted,
response_redacted, created_at, updated_at
) VALUES (
?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?,
?, ?, ?
)
`
type CreateAIRunParams struct {
ID string
Skill string
SkillVersion string
Provider string
Model string
Temperature float64
Status string
LatencyMs sql.NullInt64
TokensIn sql.NullInt64
TokensOut sql.NullInt64
Error sql.NullString
RequestRedacted string
ResponseRedacted sql.NullString
CreatedAt string
UpdatedAt string
}
func (q *Queries) CreateAIRun(ctx context.Context, arg CreateAIRunParams) error {
_, err := q.db.ExecContext(ctx, createAIRun,
arg.ID,
arg.Skill,
arg.SkillVersion,
arg.Provider,
arg.Model,
arg.Temperature,
arg.Status,
arg.LatencyMs,
arg.TokensIn,
arg.TokensOut,
arg.Error,
arg.RequestRedacted,
arg.ResponseRedacted,
arg.CreatedAt,
arg.UpdatedAt,
)
return err
}
const deleteAIRunsBefore = `-- name: DeleteAIRunsBefore :execrows
DELETE FROM ai_runs
WHERE created_at < ?1
`
func (q *Queries) DeleteAIRunsBefore(ctx context.Context, cutoff string) (int64, error) {
result, err := q.db.ExecContext(ctx, deleteAIRunsBefore, cutoff)
if err != nil {
return 0, err
}
return result.RowsAffected()
}
+8
View File
@@ -15,11 +15,19 @@ type Querier interface {
// Marks the oldest queued job running and returns it. Returns sql.ErrNoRows
// when no job is queued.
ClaimNextJob(ctx context.Context, now sql.NullString) (Job, error)
// Drops references to the runs created before the cutoff, so the purge
// can delete them.
ClearSuggestionBatchAIRunsBefore(ctx context.Context, cutoff string) (int64, error)
// Drops references to the runs created before the cutoff, so the purge
// can delete them.
ClearWeekPlanAIRunsBefore(ctx context.Context, cutoff string) (int64, error)
CreateAIRun(ctx context.Context, arg CreateAIRunParams) error
CreateDinner(ctx context.Context, arg CreateDinnerParams) (Dinner, error)
CreateJob(ctx context.Context, arg CreateJobParams) error
CreatePhoto(ctx context.Context, arg CreatePhotoParams) (Photo, error)
CreateRecipeIngredient(ctx context.Context, arg CreateRecipeIngredientParams) error
CreateRecipeStep(ctx context.Context, arg CreateRecipeStepParams) error
DeleteAIRunsBefore(ctx context.Context, cutoff string) (int64, error)
DeleteRecipeIngredients(ctx context.Context, recipeID string) error
DeleteRecipeSteps(ctx context.Context, recipeID string) error
FailJob(ctx context.Context, arg FailJobParams) (int64, error)
+75 -4
View File
@@ -175,8 +175,8 @@ func TestMigrateEmbeddedMigrations(t *testing.T) {
if err := Migrate(context.Background(), s.Writer, migrations.FS); err != nil {
t.Fatal(err)
}
if got := versions(migrationRows(t, s)); got != "0000_bootstrap,0001_init,0002_household_settings_updated_by,0003_jobs_status,0004_ai_provider_presets,0005_ai_provider_xai" {
t.Errorf("versions = %q, want 0000_bootstrap,0001_init,0002_household_settings_updated_by,0003_jobs_status,0004_ai_provider_presets,0005_ai_provider_xai", got)
if got := versions(migrationRows(t, s)); got != "0000_bootstrap,0001_init,0002_household_settings_updated_by,0003_jobs_status,0004_ai_provider_presets,0005_ai_provider_xai,0006_ai_runs_status" {
t.Errorf("versions = %q, want 0000_bootstrap,0001_init,0002_household_settings_updated_by,0003_jobs_status,0004_ai_provider_presets,0005_ai_provider_xai,0006_ai_runs_status", got)
}
}
@@ -196,8 +196,8 @@ func TestMigrateBootstrapThenEmbeddedInitApplies(t *testing.T) {
if err := Migrate(ctx, s.Writer, migrations.FS); err != nil {
t.Fatal(err)
}
if got := versions(migrationRows(t, s)); got != "0000_bootstrap,0001_init,0002_household_settings_updated_by,0003_jobs_status,0004_ai_provider_presets,0005_ai_provider_xai" {
t.Errorf("versions = %q, want 0000_bootstrap,0001_init,0002_household_settings_updated_by,0003_jobs_status,0004_ai_provider_presets,0005_ai_provider_xai", got)
if got := versions(migrationRows(t, s)); got != "0000_bootstrap,0001_init,0002_household_settings_updated_by,0003_jobs_status,0004_ai_provider_presets,0005_ai_provider_xai,0006_ai_runs_status" {
t.Errorf("versions = %q, want 0000_bootstrap,0001_init,0002_household_settings_updated_by,0003_jobs_status,0004_ai_provider_presets,0005_ai_provider_xai,0006_ai_runs_status", got)
}
if !tableExists(t, s, "dinners") {
t.Error("table from 0001_init was not created")
@@ -486,3 +486,74 @@ func TestMigrateAIProviderXAIKeepsRowsAndReferences(t *testing.T) {
}
}
}
// TestMigrateAIRunsStatus upgrades a database at 0005 and checks 0006
// keeps an ok run and its references, accepts every harness outcome, and
// stops on a run with a pre-harness status rather than guess its outcome.
func TestMigrateAIRunsStatus(t *testing.T) {
ctx := context.Background()
before := fstest.MapFS{}
for _, name := range []string{"0000_bootstrap.sql", "0001_init.sql", "0002_household_settings_updated_by.sql", "0003_jobs_status.sql", "0004_ai_provider_presets.sql", "0005_ai_provider_xai.sql"} {
body, err := fs.ReadFile(migrations.FS, name)
if err != nil {
t.Fatal(err)
}
before[name] = &fstest.MapFile{Data: body}
}
seedRun := func(t *testing.T, s *Store, status string) {
t.Helper()
if err := Migrate(ctx, s.Writer, before); err != nil {
t.Fatal(err)
}
for _, stmt := range []string{
`INSERT INTO ai_runs (id, skill, skill_version, provider, model, temperature, status, latency_ms, tokens_in, tokens_out, error, request_redacted, response_redacted, created_at, updated_at)
VALUES ('run-1', 'suggest', '1', 'xai', 'grok', 0.5, '` + status + `', 10, 20, 30, 'e', 'req', 'resp', 'c', 'u')`,
`INSERT INTO suggestion_batches (id, trigger, status, ai_run_id, created_at, updated_at)
VALUES ('batch-1', 'manual', 'done', 'run-1', 'c', 'u')`,
} {
if _, err := s.Writer.Exec(stmt); err != nil {
t.Fatalf("seed: %v", err)
}
}
}
t.Run("ok row kept", func(t *testing.T) {
s := openTestStore(t)
seedRun(t, s, "ok")
if err := Migrate(ctx, s.Writer, migrations.FS); err != nil {
t.Fatal(err)
}
var status, request string
if err := s.Reader.QueryRow(`SELECT status, request_redacted FROM ai_runs WHERE id = 'run-1'`).Scan(&status, &request); err != nil {
t.Fatal(err)
}
if status != "ok" || request != "req" {
t.Errorf("ai_runs row = %s, %s; want ok, req", status, request)
}
if _, err := s.Writer.Exec(`DELETE FROM ai_runs WHERE id = 'run-1'`); err == nil || !strings.Contains(err.Error(), "FOREIGN KEY constraint failed") {
t.Errorf("deleting a referenced ai_run: error %v, want FOREIGN KEY constraint failure", err)
}
for _, status := range []string{"repaired", "bad_output", "provider_error", "ok"} {
if _, err := s.Writer.Exec(`UPDATE ai_runs SET status = ? WHERE id = 'run-1'`, status); err != nil {
t.Errorf("ai_runs.status %s rejected: %v", status, err)
}
}
if tableExists(t, s, "ai_runs_copy") {
t.Error("ai_runs_copy left behind")
}
})
for _, legacy := range []string{"running", "error"} {
t.Run(legacy+" row stops the migration", func(t *testing.T) {
s := openTestStore(t)
seedRun(t, s, legacy)
if err := Migrate(ctx, s.Writer, migrations.FS); err == nil || !strings.Contains(err.Error(), "CHECK constraint failed") {
t.Fatalf("Migrate error = %v, want a CHECK constraint failure", err)
}
var status string
if err := s.Reader.QueryRow(`SELECT status FROM ai_runs WHERE id = 'run-1'`).Scan(&status); err != nil || status != legacy {
t.Errorf("after the failed migration status = %q, %v; want %q kept", status, err, legacy)
}
})
}
}
+2
View File
@@ -307,6 +307,8 @@ func TestSchemaEnumChecksRejectInvalidValues(t *testing.T) {
{"household_settings", "chat_autosend_dow", 3.5},
{"ai_runs", "provider", "gemini"},
{"ai_runs", "status", "done"},
{"ai_runs", "status", "running"},
{"ai_runs", "status", "error"},
{"dinners", "status", "deck"},
{"dinners", "origin", "ai"},
{"dinners", "method", "microwave"},
+47
View File
@@ -0,0 +1,47 @@
-- 0006_ai_runs_status: ai_runs.status becomes the harness run outcome:
-- ok the first reply was usable
-- repaired the first reply was not, the repair turn's was
-- bad_output neither reply was usable, or post-processing failed
-- provider_error the provider failed on either turn
-- A run's row is written once, when it ends, so there is no running state.
-- Nothing wrote ai_runs before the harness did, so no row holds the old
-- running or error values; if one does, the copy back fails the CHECK and
-- the migration stops rather than guess its outcome. created_at gains an
-- index for the 30-day purge. The rebuild is 0005's: copy the rows aside,
-- drop the table, create it again, copy the rows back and drop the copy.
--
-- suggestion_batches.ai_run_id and week_plans.ai_run_id reference ai_runs,
-- so foreign keys are deferred until commit, after the ai_runs rows are
-- back. The pragma lasts only for this migration's transaction.
PRAGMA defer_foreign_keys = ON;
CREATE TABLE ai_runs_copy AS SELECT * FROM ai_runs;
DROP TABLE ai_runs;
CREATE TABLE ai_runs (
id TEXT NOT NULL PRIMARY KEY,
skill TEXT NOT NULL,
skill_version TEXT NOT NULL,
provider TEXT NOT NULL CHECK (provider IN ('openai_compatible', 'anthropic', 'ollama', 'openai', 'openrouter', 'xai')),
model TEXT NOT NULL,
temperature REAL NOT NULL,
status TEXT NOT NULL CHECK (status IN ('ok', 'repaired', 'bad_output', 'provider_error')),
latency_ms INTEGER,
tokens_in INTEGER,
tokens_out INTEGER,
error TEXT,
request_redacted TEXT NOT NULL,
response_redacted TEXT,
created_at TEXT NOT NULL,
updated_at TEXT NOT NULL
);
INSERT INTO ai_runs (id, skill, skill_version, provider, model, temperature, status, latency_ms, tokens_in, tokens_out, error, request_redacted, response_redacted, created_at, updated_at)
SELECT id, skill, skill_version, provider, model, temperature, status, latency_ms, tokens_in, tokens_out, error, request_redacted, response_redacted, created_at, updated_at
FROM ai_runs_copy;
DROP TABLE ai_runs_copy;
CREATE INDEX ai_runs_created_at ON ai_runs (created_at);
+28
View File
@@ -0,0 +1,28 @@
-- name: CreateAIRun :exec
INSERT INTO ai_runs (
id, skill, skill_version, provider, model, temperature, status,
latency_ms, tokens_in, tokens_out, error, request_redacted,
response_redacted, created_at, updated_at
) VALUES (
?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?,
?, ?, ?
);
-- name: ClearSuggestionBatchAIRunsBefore :execrows
-- Drops references to the runs created before the cutoff, so the purge
-- can delete them.
UPDATE suggestion_batches
SET ai_run_id = NULL
WHERE ai_run_id IN (SELECT ai_runs.id FROM ai_runs WHERE ai_runs.created_at < sqlc.arg(cutoff));
-- name: ClearWeekPlanAIRunsBefore :execrows
-- Drops references to the runs created before the cutoff, so the purge
-- can delete them.
UPDATE week_plans
SET ai_run_id = NULL
WHERE ai_run_id IN (SELECT ai_runs.id FROM ai_runs WHERE ai_runs.created_at < sqlc.arg(cutoff));
-- name: DeleteAIRunsBefore :execrows
DELETE FROM ai_runs
WHERE created_at < sqlc.arg(cutoff);