textmachine/backend/cmd/tmctl/stoppedaccount_test.go

151 lines
6.9 KiB
Go

package main
import (
"bytes"
"fmt"
"net/http"
"net/http/httptest"
"os"
"os/exec"
"regexp"
"strings"
"sync"
"sync/atomic"
"syscall"
"testing"
"time"
"textmachine/backend/internal/pipeline"
"textmachine/backend/internal/store"
)
// stoppedaccount_test.go: what a person is told after they stop a run (backlog row 389).
//
// It drives the REAL binary for the reason exitcontract_test.go does: the subject is what reaches a
// human's terminal, and that is only observable at the shell. Until this landed, a stopped run printed
// one line of error text — the operator learned that it had stopped and nothing about what it had bought
// or what the resume would re-do, which under D39.240 («правильно возобновить») is the surface the
// invariant is about.
// arrivingProvider answers the first `free` requests at once and then ANNOUNCES the next one and holds
// it. The announcement is what makes the signal land while a call is really in flight: waiting for the
// journal's handshake — which is what the neighbouring stop test does — waits for a line the run writes
// BEFORE it calls anybody, and a fixture keyed on that stops a run that has bought nothing. Measured
// here: every number in the account printed as zero, and the assertions below passed over it.
func arrivingProvider(t *testing.T, free int, arrived chan<- struct{}, hold time.Duration) *httptest.Server {
t.Helper()
var seen atomic.Int32
var once sync.Once
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
if int(seen.Add(1)) > free {
once.Do(func() { close(arrived) })
time.Sleep(hold)
}
fmt.Fprint(w, `{"id":"fake","model":"fake-model","choices":[{"message":{"content":"ПЕРЕВОД"},"finish_reason":"stop"}],
"usage":{"prompt_tokens":100,"completion_tokens":50}}`)
}))
t.Cleanup(srv.Close)
return srv
}
var accountNumbers = regexp.MustCompile(`positions with a verdict: (\d+); positions the next run re-does: (\d+)`)
func TestAStoppedRunTellsTheOperatorWhatItBought(t *testing.T) {
if testing.Short() {
t.Skip("builds and runs the binary")
}
bin := buildTmctl(t)
// One chunk is answered and settled; the NEXT one is still on the wire when the signal lands. Both
// halves of the account are then about something: work that was bought, and work that was cut.
arrived := make(chan struct{})
// The hold is long enough for the signal to land on the call and no longer: httptest.Server.Close
// waits for outstanding handlers, so a generous sleep here is paid twice — once by the test and once
// by its teardown, which says so in the log ("blocked in Close after 5 seconds").
srv := arrivingProvider(t, 1, arrived, 3*time.Second)
bookPath := setupCLIProjectMulti(t, srv.URL)
var out bytes.Buffer
cmd := exec.Command(bin, "translate", "--config", bookPath)
cmd.Stdout = &out
cmd.Stderr = os.Stderr
if err := cmd.Start(); err != nil {
t.Fatal(err)
}
select {
case <-arrived:
case <-time.After(60 * time.Second):
_ = cmd.Process.Kill()
t.Fatal("the run never reached its second call — the fixture cannot put a call in flight")
}
if err := cmd.Process.Signal(syscall.SIGTERM); err != nil {
t.Fatal(err)
}
if got := exitCodeOf(t, cmd.Wait()); got != 5 {
t.Fatalf("a caught SIGTERM exited %d, want 5", got)
}
printed := out.String()
t.Logf("what the operator saw on stdout:\n%s", printed)
for _, want := range []string{
"RUN STOPPED", // which exit this was
"book ledger: committed=$", // what it spent, read from the store rather than from a result
"positions with a verdict:", // what it finished
"positions the next run re-does:", // what the resume will buy again
} {
if !strings.Contains(printed, want) {
t.Fatalf("the stopped run said nothing about %q.\nWhat it printed:\n%s", want, printed)
}
}
// ⛔ AND THE NUMBERS ARE NOT ZERO. The first version of this test asserted the WORDS alone and passed
// over a run that had bought nothing at all — the signal landed before the first call, every figure
// printed as 0, and a counter that was broken in any direction would have been just as green.
m := accountNumbers.FindStringSubmatch(printed)
if m == nil {
t.Fatalf("the account does not carry its two counts in the shape this test reads:\n%s", printed)
}
resolved, cut := m[1], m[2]
if resolved == "0" {
t.Fatalf("the account says NOTHING was finished (%q), so the fixture stopped a run that had bought nothing", printed)
}
if cut == "0" {
t.Fatalf("the account says nothing was cut mid-call (%q), so the signal did not land on a call in flight", printed)
}
if strings.Contains(printed, "committed=$0.000000") {
t.Fatalf("the ledger reports zero spend for a run that finished a position:\n%s", printed)
}
t.Logf("non-vacuous: %s position(s) with a verdict, %s cut mid-call", resolved, cut)
}
// TestTheStoppedAccountCountsEveryPositionTheNextRunRedoes is the account's SPLIT, asked of the rows
// directly — the run above cannot produce the second cause at all, and the split was keyed on the first.
//
// ⛔ THE DEFECT IT PINS WAS ONE EDIT OLD. The split read `FlagReason == FlagCancelled`, which is a second
// copy of «is this row an answer the next run serves» (pipeline.ResolvedForResume). The day a second
// non-resolved reason existed — a retry whose money ran out — the copy counted a position the next run
// re-does among the ones WITH a verdict, and the operator was told the rest is served for $0.
func TestTheStoppedAccountCountsEveryPositionTheNextRunRedoes(t *testing.T) {
rows := []store.ChunkStatus{
{Chapter: 1, ChunkIdx: 0, Stage: "draft", Disposition: "ok"},
{Chapter: 1, ChunkIdx: 1, Stage: "draft", Disposition: "flagged", FlagReason: string(pipeline.FlagCancelled)},
{Chapter: 1, ChunkIdx: 2, Stage: "draft", Disposition: "flagged", FlagReason: string(pipeline.FlagRetryUnaffordable)},
// A real verdict: a flag the next run does NOT re-do, so the split has something on both sides and
// «everything is re-done» cannot pass either.
{Chapter: 1, ChunkIdx: 3, Stage: "draft", Disposition: "flagged", FlagReason: string(pipeline.FlagHardRefusal)},
}
var out bytes.Buffer
renderStoppedRun(&out, "test-book",
func() (float64, float64, error) { return 0.004, 0, nil },
func() ([]store.ChunkStatus, error) { return rows, nil })
printed := out.String()
t.Logf("what the operator saw:\n%s", printed)
m := accountNumbers.FindStringSubmatch(printed)
if m == nil {
t.Fatalf("the account does not carry its two counts in the shape this file reads:\n%s", printed)
}
// Two of the four rows are answers (ok + the refusal); two are positions the next run re-does (the
// stop's mark and the money mark).
if m[1] != "2" || m[2] != "2" {
t.Fatalf("the account says %s position(s) with a verdict and %s the next run re-does, want 2 and 2: "+
"a row whose money ran out is NOT an answer — the next run re-attacks it, and counting it as "+
"resolved tells an operator the rest is served for $0", m[1], m[2])
}
}