diff --git a/backend/cmd/tmctl/main.go b/backend/cmd/tmctl/main.go index 9997d29d..78f1f564 100644 --- a/backend/cmd/tmctl/main.go +++ b/backend/cmd/tmctl/main.go @@ -306,6 +306,15 @@ func translate(ctx context.Context, cfgPath string, resnapshot bool, acceptRebil // is not decoration — the operator reading the ceiling line otherwise learns that the run stopped // and nothing about what it produced on the way, which reads as «nothing happened» and is the // state this pack exists to end. + // …and a run somebody STOPPED gets its own account, because it is the one exit with nothing to + // print: the driver returns no result on a cancellation, every renderer here takes one, and the + // operator was left with a line of error text about a run that may have translated half a book + // (backlog row 389). What is printed comes from the STORE — see renderStoppedRun. + if errors.Is(err, context.Canceled) { + renderStoppedRun(os.Stdout, r.Book.BookID, + func() (float64, float64, error) { return r.Store.SpentUSD(r.Book.BookID) }, + func() ([]store.ChunkStatus, error) { return r.Store.ChunkStatusesForBook(r.Book.BookID) }) + } var ceiling *pipeline.CeilingHalt if errors.As(err, &ceiling) && res != nil { if rerr := renderTranslate(os.Stdout, res, func() (float64, float64, error) { diff --git a/backend/cmd/tmctl/render.go b/backend/cmd/tmctl/render.go index f27606c2..5adee477 100644 --- a/backend/cmd/tmctl/render.go +++ b/backend/cmd/tmctl/render.go @@ -68,6 +68,44 @@ func gapMarker(dropped int, reason string) string { // renderTranslate prints the per-chunk translation report and returns the // CompletedWithFlags sentinel when chunks were flagged (exit 2). +// renderStoppedRun is what a person is told after they stop a run, and it exists because until backlog +// row 389 they were told NOTHING: a stopped run returns no result, every renderer here takes one, and the +// operator was left with a single line of error text about a run that may have translated half a book. +// +// ⛔ IT REPORTS THE STORE, NOT A RESULT, and that is the whole of its honesty. The run was cut; there is +// no assembled BookResult to print and inventing one would mean describing work nobody verified. What the +// store holds is durable and true whatever the run did next — the ledger it committed, the positions that +// reached a verdict, and the ones a cut left marked for re-doing. Those are the two questions a person +// has after pressing the button: what do I have, and what will be bought again. +// +// A read that fails is SAID, not swallowed: the alternative is a confident zero, and «nothing was bought» +// is the most expensive wrong sentence this surface can print. +func renderStoppedRun(w io.Writer, bookID string, ledger func() (committed, reserved float64, err error), + rows func() ([]store.ChunkStatus, error)) { + fmt.Fprintf(w, "=== RUN STOPPED — %s ===\n", bookID) + if committed, reserved, err := ledger(); err != nil { + fmt.Fprintf(w, " the book's ledger could not be read, so what this run spent is UNKNOWN here (it is in the project database): %v\n", err) + } else { + fmt.Fprintf(w, " book ledger: committed=$%.6f reserved=$%.6f\n", committed, reserved) + } + cs, err := rows() + if err != nil { + fmt.Fprintf(w, " the stored dispositions could not be read, so how far the book got is UNKNOWN here: %v\n", err) + return + } + resolved, stopped := 0, 0 + for _, row := range cs { + if pipeline.FlagReason(row.FlagReason) == pipeline.FlagCancelled { + stopped++ + continue + } + resolved++ + } + fmt.Fprintf(w, " positions with a verdict: %d; positions the stop cut mid-call: %d (the resume re-does those and serves the rest for $0)\n", + resolved, stopped) + fmt.Fprintln(w, " `tmctl status --json` reports the same numbers in full, and `tmctl export` ships what is finished.") +} + func renderTranslate(w io.Writer, res *pipeline.BookResult, ledger func() (committed, reserved float64, err error)) error { for _, ch := range res.Chunks { fmt.Fprintf(w, "=== CHAPTER %d CHUNK %d — %s%s ===\n", ch.Chapter, ch.ChunkIdx, ch.Disposition, flagSuffix(ch.FlagReason)) diff --git a/backend/cmd/tmctl/stoppedaccount_test.go b/backend/cmd/tmctl/stoppedaccount_test.go new file mode 100644 index 00000000..bc9c534a --- /dev/null +++ b/backend/cmd/tmctl/stoppedaccount_test.go @@ -0,0 +1,113 @@ +package main + +import ( + "bytes" + "fmt" + "net/http" + "net/http/httptest" + "os" + "os/exec" + "regexp" + "strings" + "sync" + "sync/atomic" + "syscall" + "testing" + "time" +) + +// 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 stop cut mid-call: (\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 stop cut mid-call:", // 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) +} diff --git a/backend/cmd/tmmutate/mutations.json b/backend/cmd/tmmutate/mutations.json index 97079a8e..1c3885ef 100644 --- a/backend/cmd/tmmutate/mutations.json +++ b/backend/cmd/tmmutate/mutations.json @@ -4704,5 +4704,47 @@ "replace": "" } ] + }, + { + "id": "STOP-cut-does-not-blind-an-earlier-verdict", + "why": "chunk_status is keyed (book, chapter, chunk, stage) and the stop mark is an UPSERT, so a run cut over a position that ALREADY held a verdict replaced it with flagged(cancelled) and an EMPTY final_hash — the only pointer to text a previous run bought and the export ships. Measured before the guard: ok / final_hash=770e5563 / $0.001820 became cancelled / \"\" / $0 while the checkpoint holding the prose stayed on disk, and the export shipped an empty chapter where it had shipped text (backlog row 375). Reachable through the re-pin route; the redrive route cannot reach it, because ResetChunkStages deletes the row and its checkpoints first", + "package": "./internal/pipeline/", + "battery": true, + "run": "TestACutOverAPositionThatAlreadyShippedTextKeepsIt|TestACutOverAVirginPositionStillMarksIt", + "edits": [ + { + "file": "internal/pipeline/cutcall.go", + "find": "\t} else if prev != nil && resolvedForResume(prev) {", + "replace": "\t} else if prev != nil && resolvedForResume(prev) && false {" + } + ] + }, + { + "id": "STOP-a-cut-by-a-person-is-not-a-failed-job", + "why": "a call a person cut was healthy when they cut it and the resume re-does it at the same budget, so `failed` — the read-model's word for a position that BROKE — sends whoever reads the jobs table hunting for a defect that is not there (backlog row 389; this is the site a stop actually travels through, and not one of the two the row names). The control pinned beside it keeps the word where it is true: a socket that dies on its own still records `failed`", + "package": "./internal/pipeline/", + "battery": true, + "run": "TestAStoppedPositionIsNotRecordedAsFailed|TestABrokenSocketIsStillRecordedAsFailed", + "edits": [ + { + "file": "internal/pipeline/stagerun.go", + "find": "\tif errors.Is(cause, context.Canceled) {\n\t\treturn\n\t}\n\tr.setJobStatus(ctx, jobID, \"failed\")", + "replace": "\tr.setJobStatus(ctx, jobID, \"failed\")" + } + ] + }, + { + "id": "STOP-the-spend-line-closure-cannot-reach-the-emitter", + "why": "the spend-line closure runs INSIDE the store's write transaction while the emitter's mutex is held ACROSS store writes, so taking that mutex from the closure closes a lock cycle — and it does not look like a deadlock from outside: the store's 10-second op timeout breaks it, and the symptom is `ensure job: context deadline exceeded` in tests that have nothing to do with the change (measured at thirteen, backlog row 387). The closure captures values so the receiver is not in scope at all; this plant puts it back", + "package": "./internal/pipeline/", + "battery": true, + "run": "TestTheSpendLineClosureCannotReachTheEmitter", + "edits": [ + { + "file": "internal/pipeline/events.go", + "find": "\t\t\tlog.Error(\"could not render the spend event; the settle proceeds without it (the counter is cumulative — the next one carries the total again)\", \"err\", err)", + "replace": "\t\t\tlog.Error(\"could not render the spend event; the settle proceeds without it (the counter is cumulative — the next one carries the total again)\", \"err\", err, \"run\", e.runID)" + } + ] } ] diff --git a/backend/internal/pipeline/cutcall.go b/backend/internal/pipeline/cutcall.go index 3671585a..129f30a4 100644 --- a/backend/internal/pipeline/cutcall.go +++ b/backend/internal/pipeline/cutcall.go @@ -148,7 +148,12 @@ func (r *Runner) settleCutCall(ctx context.Context, c cutCall, cut *llm.AttemptC } // A stopped run and a dead socket both end this stage. The money above is recorded either way; the // error travels so the run pauses instead of walking the rest of the book against a dead provider. - r.setJobStatus(ctx, c.job.ID, "failed") + // + // ⛔ BUT THE TWO DO NOT GET THE SAME WORD (backlog row 389, and this site is not one of the two the row + // names — it is the one a stop actually goes through). A call a person cut was healthy when they cut + // it; a dead socket IS a failure and keeps the word. The question is asked once, for the whole family + // — see noteJobFailed. + r.noteJobFailed(ctx, c.job.ID, err) return att, fmt.Errorf("pipeline: stage %s call (ch%d/chunk%d, model %s): %w", c.stage.Name, c.chunk.Chapter, c.chunk.ChunkIdx, c.model, err) } @@ -200,6 +205,40 @@ func (r *Runner) recordCancelledStage(ctx context.Context, p cancelledPosition, if !errors.Is(err, context.Canceled) || !errors.As(err, &cut) { return } + // ⛔ A CUT MUST NOT BLIND A VERDICT IT DID NOT PRODUCE, and this row is an UPSERT: chunk_status is + // keyed (book, chapter, chunk, stage), so the write below REPLACES whatever the position already held + // — including `final_hash`, which is the only pointer to the text a previous run bought and the + // export ships. + // + // ⚠ IT IS REACHABLE, and it was measured rather than argued (backlog row 375, the ⛔ half): a prompt + // edit moves both the rendered content and the snapshot, so the resume fast-path above refuses the + // stored row and the position is re-attacked; cut the run there and the row went from + // `ok / final_hash=770e5563 / cost=$0.001820` to `flagged(cancelled) / final_hash="" / cost=$0`, the + // checkpoint holding the text stayed on disk with nothing addressing it, and the export shipped an + // empty chapter where it had shipped prose. The run made the book WORSE than it found it, which is + // what D39.240 forbids of a stop: it may cost money, it may not leave rubbish. + // + // So the mark is written only where it was meant to be written — over a position that has no verdict + // of its own — and a position that already holds one keeps it. Nothing is hidden by that: the resume + // re-attacks this position anyway (its stored content hash no longer matches, which is why it was + // re-attacked in the first place), the cut call's money is on the ledger through its checkpoint and + // its request_log row, and the line below says out loud what was kept and why. + // + // ⚠ THE REDRIVE ROUTE CANNOT REACH THIS: ResetChunkStages deletes the row and its checkpoints in one + // transaction before re-attacking, so there is nothing to protect and this guard is a no-op there. + if prev, perr := r.Store.GetChunkStatus(r.Book.BookID, p.chunk.Chapter, p.chunk.ChunkIdx, p.stage.Name); perr != nil { + // Not fatal and not silent: the caller is already returning the error that stopped the run, and a + // failed read here only means the guard cannot answer — so it does not, and the mark is written as + // it always was. + r.Log.WarnContext(ctx, "could not read the position's stored disposition before marking it stopped; the mark is written and may replace an earlier verdict", + "stage", p.stage.Name, "chapter", p.chunk.Chapter, "chunk", p.chunk.ChunkIdx, "err", perr) + } else if prev != nil && resolvedForResume(prev) { + r.Log.WarnContext(ctx, "the run was stopped over a position that ALREADY held a verdict from an earlier run; that verdict and its text are kept rather than overwritten by the stop mark (the resume re-does this position, and the stopped call's money is on the ledger)", + "stage", p.stage.Name, "chapter", p.chunk.Chapter, "chunk", p.chunk.ChunkIdx, + "kept_disposition", prev.Disposition, "kept_flag_reason", prev.FlagReason, + "stopped_call_cost_usd", fmt.Sprintf("%.6f", p.cumCostUSD)) + return + } if uerr := r.Store.UpsertChunkStatus(store.ChunkStatus{ BookID: r.Book.BookID, Chapter: p.chunk.Chapter, ChunkIdx: p.chunk.ChunkIdx, Stage: p.stage.Name, SnapshotID: p.snapshotID, ContentHash: p.contentHash, diff --git a/backend/internal/pipeline/cutoververdict_test.go b/backend/internal/pipeline/cutoververdict_test.go new file mode 100644 index 00000000..45db0335 --- /dev/null +++ b/backend/internal/pipeline/cutoververdict_test.go @@ -0,0 +1,308 @@ +package pipeline + +import ( + "context" + "encoding/json" + "fmt" + "io" + "net/http" + "net/http/httptest" + "path/filepath" + "sync" + "sync/atomic" + "testing" + + "textmachine/backend/internal/obs" +) + +// cutoververdict_test.go asks ONE question, and it is a question rather than a fix: when a run is cut +// over a position that ALREADY HAD a verdict, what is left behind? +// +// The suspicion (backlog row 375, the ⛔ half) is that the mark a cut writes REPLACES that verdict — +// `chunk_status` is keyed (book, chapter, chunk, stage) and the write is an upsert — and that it writes +// an EMPTY final_hash, so the position loses the pointer to text whose checkpoint is still on disk. The +// book would then be WORSE after an interrupted run than it was before it started, which is exactly what +// the ratified invariant (D39.240) forbids: a stop may cost money, and may not leave rubbish. +// +// ⛔ THE STATE IS REACHED THROUGH PRODUCTION PATHS ONLY. Nothing here writes a chunk_status row by hand: +// the first verdict is written by a real run, the re-attack is caused by a real prompt edit plus +// --resnapshot, and the cut is a real cancellation over a real request the server is holding open. A +// fixture that assembled the state directly would prove the upsert overwrites — which nobody doubts — +// while saying nothing about whether a run can GET there. +// +// ⚠ ONE OF THE THREE ROUTES THE ROW NAMES IS ALREADY OUT, and it was eliminated by reading rather than +// here: a REDRIVE cannot produce this state, because ResetChunkStages deletes the chunk_status row AND +// its checkpoints in one transaction before anything re-attacks the position (store/chunkstatus.go), so +// there is no verdict left to overwrite. What remains, and what this file drives, is the re-pin. + +// holdWhenArmed answers like the ordinary fake provider, except that while `armed` is set it ANNOUNCES +// the request's arrival and then holds it until `release` is closed. One server serves both runs, so the +// fixture never has to re-point a book at a second URL mid-way. +// +// ⛔ THE ARRIVAL SIGNAL IS WHAT MAKES THE TEST ABOUT ITS SUBJECT, and the first version of this file had +// none. Cancelling as soon as the money gate reports a call «in flight» cancels somewhere between the +// reservation and the request actually being WRITTEN — and a request that never went out is not a +// delivered cut, so the engine released the reservation, wrote no mark, and the assertion below read +// «the row is untouched» as if the suspicion had been refuted. It had not been tested. Announcing from +// inside the handler makes delivery a fact: the bytes are in the server's hands before anything cancels. +func holdWhenArmed(rec *reqRec, armed *atomic.Bool, arrived chan<- struct{}, release <-chan struct{}) *httptest.Server { + var once sync.Once + return httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + body, _ := io.ReadAll(r.Body) + rec.record(string(body)) + if armed.Load() { + once.Do(func() { close(arrived) }) + // Deliberately NOT selecting on the request's own context: the subject is what the ENGINE + // records when its call is cut, so the server must not answer early just because somebody + // cancelled it (the same rule gatedProvider states next door). + <-release + } + text, finish := draftEdit(string(body)) + tb, _ := json.Marshal(text) + fmt.Fprintf(w, `{"id":"fake","model":"fake-model","choices":[{"message":{"content":%s},"finish_reason":%q}], + "usage":{"prompt_tokens":1000,"completion_tokens":500,"prompt_tokens_details":{"cached_tokens":200}}}`, + tb, finish) + })) +} + +func TestACutOverAPositionThatAlreadyShippedTextKeepsIt(t *testing.T) { + rec := &reqRec{} + var armed atomic.Bool + release := make(chan struct{}) + arrived := make(chan struct{}) + srv := holdWhenArmed(rec, &armed, arrived, release) + // ⚠ THE ORDER OF THESE TWO DEFERS IS THE TEST, NOT ITS TIDINESS. Defers run LIFO, and + // httptest.Server.Close() BLOCKS until every outstanding handler returns — so registering the server's + // close last parks it on a handler waiting for a channel closed by the defer behind it, and the test + // hangs until the package timeout with no failure to read. Measured here: 300 s and a kill. + defer srv.Close() + defer close(release) + + // A draft-only pipeline, one chunk: the draft IS the shipping row, so the position under test and the + // row the export reads are the same row — no edit wave between the subject and the assertion. + bookPath := setupProjectOpts(t, srv.URL, projectOpts{draftOnly: true, bookUSD: 100, rebillConsentUSD: 1}) + + // --- run 1: an ordinary run. It leaves a verdict and shippable text. --- + r1 := newRunner(t, bookPath) + if _, err := r1.TranslateBook(tracedCtx()); err != nil { + r1.Close() + t.Fatalf("the first run must finish: %v", err) + } + before, err := r1.Export(false) + if err != nil { + r1.Close() + t.Fatal(err) + } + if len(before.Chunks) != 1 || before.Chunks[0].FinalText == "" { + r1.Close() + t.Fatalf("the first run shipped nothing — there is no text for the second run to endanger (%d position(s))", len(before.Chunks)) + } + shipped := before.Chunks[0].FinalText + cs, err := r1.Store.GetChunkStatus(r1.Book.BookID, 1, 0, "draft") + if err != nil || cs == nil { + r1.Close() + t.Fatalf("no verdict after the first run: %v", err) + } + oldHash, oldDisposition, oldCost := cs.FinalHash, cs.Disposition, cs.CostUSD + if oldHash == "" { + r1.Close() + t.Fatal("the first run left no final_hash, so there is no pointer for a cut to erase") + } + r1.Close() + t.Logf("after run 1: disposition=%q final_hash=%.12s cost_usd=%.6f text=%q", oldDisposition, oldHash, oldCost, shipped) + + // --- the prompt moves. Both guards that would have served the stored row now refuse it: the rendered + // messages change (content_hash) and so does the snapshot, and repinnable answers false for a move + // that is not bank-only. This is the re-pin route, driven by an ordinary file edit. --- + writeFile(t, filepath.Join(filepath.Dir(bookPath), "prompts", "translator.md"), + "Переводи с {{source_lang}} на {{target_lang}}. Второй вариант промта.\n---USER---\n{{text}}") + + // --- run 2: re-attacks the position, and is cut while its call is out. --- + armed.Store(true) + r2 := newRunner(t, bookPath) + defer r2.Close() + r2.Resnapshot = true + + ctx, cancel := context.WithCancel(obs.WithReqInfo(context.Background(), obs.ReqInfo{TraceID: obs.NewTraceID()})) + go func() { + // Cancel only once the PROVIDER HAS THE REQUEST. The money gate's counter says a reservation was + // taken, which is a moment earlier and a different fact: a cancellation in that window kills a + // request that never went out, the engine owes nothing and marks nothing, and this test would then + // read «the row is untouched» as proof of a guard that never ran. Measured: the first version of + // this fixture did exactly that. + <-arrived + cancel() + }() + _, err = r2.TranslateBook(ctx) + if rec.count() < 2 { + t.Fatalf("the second run made no provider call of its own (%d call(s) in total) — the position was served from the store and nothing was cut", rec.count()) + } + if err == nil { + t.Fatal("a cancelled run must not report success") + } + + // --- what is left behind: the verdict this run did not produce, exactly as it was --- + after, err := r2.Store.GetChunkStatus(r2.Book.BookID, 1, 0, "draft") + if err != nil || after == nil { + t.Fatalf("the position lost its row entirely: %v", err) + } + t.Logf("after the cut: disposition=%q flag_reason=%q final_hash=%.12s cost_usd=%.6f", + after.Disposition, after.FlagReason, after.FinalHash, after.CostUSD) + + if FlagReason(after.FlagReason) == FlagCancelled { + t.Fatal("the cut REPLACED a verdict it did not produce: the position now reads `cancelled`, and the text the earlier run bought is unreachable") + } + if after.FinalHash != oldHash { + t.Fatalf("the pointer to the earlier run's text moved (%.12s → %q) — the checkpoint is still on disk with nothing addressing it", oldHash, after.FinalHash) + } + if after.CostUSD != oldCost { + t.Fatalf("the position's recorded spend was rewritten by the cut: $%.6f → $%.6f", oldCost, after.CostUSD) + } + // The text really is still reachable, end to end — not merely a hash that looks right. + cp, err := r2.Store.GetCheckpoint(after.FinalHash) + if err != nil { + t.Fatal(err) + } + if cp == nil || cp.ResponseText == "" { + t.Fatal("the row points at a checkpoint that is gone or empty") + } + afterExp, err := r2.Export(false) + if err != nil { + t.Fatal(err) + } + if len(afterExp.Chunks) != 1 { + t.Fatalf("export projected %d positions, want 1", len(afterExp.Chunks)) + } + t.Logf("export after the cut: disposition=%q final_text=%q", afterExp.Chunks[0].Disposition, afterExp.Chunks[0].FinalText) + if afterExp.Chunks[0].FinalText != shipped { + t.Fatalf("the reader lost a finished chapter to an interrupted run: shipped %q before, %q after", + shipped, afterExp.Chunks[0].FinalText) + } +} + +// TestACutOverAVirginPositionStillMarksIt is the CONTROL, and without it the test above is satisfied by +// deleting the mark altogether. +// +// The mark exists for the position that has NO verdict: a run cut over its first attempt would otherwise +// leave the money booked and the position reading «never started», which is the invisible hole +// recordCancelledStage was written for. The guard added for the row above must not have eaten it. +func TestACutOverAVirginPositionStillMarksIt(t *testing.T) { + rec := &reqRec{} + var armed atomic.Bool + armed.Store(true) // hold from the very first call: this position has never been translated + release := make(chan struct{}) + arrived := make(chan struct{}) + srv := holdWhenArmed(rec, &armed, arrived, release) + defer srv.Close() + defer close(release) + + bookPath := setupProjectOpts(t, srv.URL, projectOpts{draftOnly: true, bookUSD: 100}) + r := newRunner(t, bookPath) + defer r.Close() + + ctx, cancel := context.WithCancel(obs.WithReqInfo(context.Background(), obs.ReqInfo{TraceID: obs.NewTraceID()})) + go func() { + <-arrived + cancel() + }() + if _, err := r.TranslateBook(ctx); err == nil { + t.Fatal("a cancelled run must not report success") + } + cs, err := r.Store.GetChunkStatus(r.Book.BookID, 1, 0, "draft") + if err != nil { + t.Fatal(err) + } + if cs == nil { + t.Fatal("the stopped position has NO row at all: its money is on the ledger and the export will read it as never started — the invisible hole the mark exists to close") + } + t.Logf("virgin position after the cut: disposition=%q flag_reason=%q attempts=%d", cs.Disposition, cs.FlagReason, cs.Attempts) + if FlagReason(cs.FlagReason) != FlagCancelled { + t.Fatalf("a stopped virgin position must be marked `cancelled`, got %q", cs.FlagReason) + } +} + +// TestAStoppedPositionIsNotRecordedAsFailed is backlog row 389's second half, at the site a stop actually +// travels through: a call a person CUT was healthy when they cut it, and the resume re-does it at the +// same budget. `failed` is the read-model's word for a position that broke, and a reader who finds it +// there goes looking for a defect that is not there. +// +// ⚠ THE CONTROL IS IN THE SAME TEST, and without it this pin is satisfied by never writing the word at +// all: a socket that dies on its own IS a failure and must keep it. Both halves run over the same +// fixture, so the difference asserted is the CAUSE and nothing else. +func TestAStoppedPositionIsNotRecordedAsFailed(t *testing.T) { + rec := &reqRec{} + var armed atomic.Bool + armed.Store(true) + release := make(chan struct{}) + arrived := make(chan struct{}) + srv := holdWhenArmed(rec, &armed, arrived, release) + defer srv.Close() + defer close(release) + + bookPath := setupProjectOpts(t, srv.URL, projectOpts{draftOnly: true, bookUSD: 100}) + r := newRunner(t, bookPath) + defer r.Close() + + ctx, cancel := context.WithCancel(obs.WithReqInfo(context.Background(), obs.ReqInfo{TraceID: obs.NewTraceID()})) + go func() { + <-arrived + cancel() + }() + if _, err := r.TranslateBook(ctx); err == nil { + t.Fatal("a cancelled run must not report success") + } + job, err := r.Store.EnsureJob(r.Book.BookID, 1, "draft", "") + if err != nil { + t.Fatal(err) + } + if job == nil { + t.Fatal("the position has no job row — this pin would then be asserting about nothing") + } + t.Logf("job status after the human's cut: %q", job.Status) + if job.Status == "failed" { + t.Fatal("the position a person stopped is recorded as a FAILURE; the resume re-does it and nothing broke") + } +} + +// TestABrokenSocketIsStillRecordedAsFailed is the control for the pin above: the word must still be +// written where it is true. Same shape, different cause — the server hangs up mid-request instead of the +// operator stopping the run. +func TestABrokenSocketIsStillRecordedAsFailed(t *testing.T) { + rec := &reqRec{} + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + body, _ := io.ReadAll(r.Body) + rec.record(string(body)) + // Hijack and close: the request was delivered, the answer never arrives, and the socket dies — + // llm.CutByConnection rather than a cancellation. + hj, ok := w.(http.Hijacker) + if !ok { + t.Error("the test server cannot hijack; this control cannot build its cause") + return + } + conn, _, err := hj.Hijack() + if err != nil { + t.Errorf("hijack: %v", err) + return + } + conn.Close() + })) + defer srv.Close() + + bookPath := setupProjectOpts(t, srv.URL, projectOpts{draftOnly: true, bookUSD: 100}) + r := newRunner(t, bookPath) + defer r.Close() + if _, err := r.TranslateBook(tracedCtx()); err == nil { + t.Fatal("a run against a provider that hangs up must fail") + } + job, err := r.Store.EnsureJob(r.Book.BookID, 1, "draft", "") + if err != nil { + t.Fatal(err) + } + if job == nil { + t.Fatal("no job row") + } + t.Logf("job status after a broken socket: %q", job.Status) + if job.Status != "failed" { + t.Fatalf("a position whose provider died must keep the word for it, got %q — the pin above would then be green over a word nobody writes any more", job.Status) + } +} diff --git a/backend/internal/pipeline/events.go b/backend/internal/pipeline/events.go index 672bac66..6c8fb515 100644 --- a/backend/internal/pipeline/events.go +++ b/backend/internal/pipeline/events.go @@ -37,6 +37,14 @@ import ( // in sequence order, so it appends a dense prefix even when two workers commit concurrently (the write // pool is single-connection, so a transaction sees MAX(seq)=N only after N's transaction committed). type emitter struct { + // mu guards everything below, INCLUDING the projection — the waves emit from N workers and a reader + // cannot survive seq N+1 appearing above seq N. + // + // ⛔ IT IS ALSO ONE HALF OF A LOCK ORDER, and the other half is the store's write connection: this + // mutex is held ACROSS store writes (project → the journal and MarkAnnounced; enqueue → EnqueueEvent), + // so it is always taken BEFORE the connection and must never be taken after one. The one place that + // runs while the connection is held is the spend-line closure — see spendLine, which is written so + // that it cannot reach this struct at all. mu sync.Mutex store *store.Store journal *runevents.Journal @@ -231,16 +239,34 @@ func (e *emitter) degrade(what string, err error) { // It never fails the settle. A render failure returns "no event" rather than an error, because the // alternative is a rolled-back settle for a call the provider has already billed — losing a paid // checkpoint to protect an indicator is the wrong way round. +// +// ⛔ THE CLOSURE DELIBERATELY CAPTURES VALUES AND NOT THE EMITTER, AND THAT IS A LOCK ORDER, NOT A STYLE. +// This function's body runs INSIDE the store's single write transaction, so whoever executes it holds the +// write connection; `mu` meanwhile is held across project(), which itself WRITES to the store (the outbox +// cursor, the announce-once ledger). The order is therefore fixed — the emitter's mutex is taken BEFORE +// the write connection, never after — and anything that takes `mu` from in here closes the cycle: the +// settle holds the connection and waits for the mutex while an emit holds the mutex and waits for the +// connection. +// +// ⚠ AND THE CYCLE DOES NOT LOOK LIKE A DEADLOCK FROM OUTSIDE, which is why this is written down rather +// than left to be noticed. The store's 10-second op timeout breaks it, so the symptom is +// `pipeline: ensure job …: context deadline exceeded` — in tests that have nothing to do with the change +// that caused it. It was measured that way once (backlog row 387): thirteen unrelated tests red, and the +// reading «the store is wedged». +// +// Capturing `at`, `log` and `runID` by value is what makes the rule structural instead of advisory: with +// no `e` in scope, taking the mutex from here is not a slip, it is an edit that has to put the receiver +// back — and TestTheSpendLineClosureCannotReachTheEmitter reds when it does. func (e *emitter) spendLine() *store.SpendLine { if e == nil { return nil } - at := e.now() + at, log := e.now(), e.log return &store.SpendLine{RunID: e.runID, Line: func(seq int64, committedUSD float64) ([]byte, error) { line, err := runevents.Line(seq, runevents.TypeSpend, at, runevents.Spend{CommittedMicroUSD: runevents.MicroUSD(committedUSD)}) if err != nil { - e.log.Error("could not render the spend event; the settle proceeds without it (the counter is cumulative — the next one carries the total again)", "err", err) + log.Error("could not render the spend event; the settle proceeds without it (the counter is cumulative — the next one carries the total again)", "err", err) return nil, nil } return line, nil diff --git a/backend/internal/pipeline/spendlineorder_test.go b/backend/internal/pipeline/spendlineorder_test.go new file mode 100644 index 00000000..243fd9c7 --- /dev/null +++ b/backend/internal/pipeline/spendlineorder_test.go @@ -0,0 +1,79 @@ +package pipeline + +import ( + "go/ast" + "go/parser" + "go/token" + "testing" +) + +// spendlineorder_test.go pins ONE lock order, and it pins it in the only place where breaking it is +// invisible: the source. +// +// The order is stated at both of its ends (emitter.mu, spendLine): the emitter's mutex is taken BEFORE +// the store's write connection and never after one, because the mutex is held across store writes. The +// spend-line closure is the single piece of this package's code that executes while the write connection +// is held, so it is the single place the order can be violated — and the violation does not look like a +// deadlock: the store's op timeout breaks the cycle ten seconds later, and the failure surfaces as +// `context deadline exceeded` in whatever unrelated tests happen to be running (backlog row 387, +// measured at thirteen). +// +// A comment cannot hold that. What holds it is the closure having no `e` in scope — and what tells the +// next person they have just put it back is this test. +func TestTheSpendLineClosureCannotReachTheEmitter(t *testing.T) { + fset := token.NewFileSet() + file, err := parser.ParseFile(fset, "events.go", nil, 0) + if err != nil { + t.Fatalf("parse events.go: %v", err) + } + var fn *ast.FuncDecl + for _, d := range file.Decls { + f, ok := d.(*ast.FuncDecl) + if ok && f.Name.Name == "spendLine" && f.Recv != nil { + fn = f + break + } + } + if fn == nil { + t.Fatal("spendLine is not in events.go any more — this pin is looking at the wrong place and is asserting nothing") + } + // The receiver's own name, read from the declaration rather than assumed: renaming it must not turn + // this guard off. + if len(fn.Recv.List) != 1 || len(fn.Recv.List[0].Names) != 1 { + t.Fatal("spendLine's receiver has no name — a nameless receiver cannot be captured, but this pin can no longer tell") + } + recv := fn.Recv.List[0].Names[0].Name + + // The closure handed to the store: the FuncLit under the `Line:` key. + var closure *ast.FuncLit + ast.Inspect(fn, func(n ast.Node) bool { + kv, ok := n.(*ast.KeyValueExpr) + if !ok { + return true + } + if key, ok := kv.Key.(*ast.Ident); ok && key.Name == "Line" { + if lit, ok := kv.Value.(*ast.FuncLit); ok { + closure = lit + } + } + return true + }) + if closure == nil { + t.Fatal("spendLine no longer hands a function literal to store.SpendLine.Line — the shape this pin reads is gone, so it proves nothing") + } + + var used []string + ast.Inspect(closure, func(n ast.Node) bool { + if id, ok := n.(*ast.Ident); ok && id.Name == recv { + used = append(used, fset.Position(id.Pos()).String()) + } + return true + }) + if len(used) > 0 { + t.Fatalf("the spend-line closure reaches the emitter (%q) at %v.\n"+ + "That closure runs INSIDE the store's write transaction, and the emitter's mutex is held across store writes — "+ + "so any method taken on it from here closes a lock cycle that the store's timeout breaks ten seconds later, "+ + "in whatever tests happen to be running (backlog row 387). Capture what you need by value before the closure instead.", + recv, used) + } +} diff --git a/backend/internal/pipeline/stagerun.go b/backend/internal/pipeline/stagerun.go index 4b56141f..7a8ba2de 100644 --- a/backend/internal/pipeline/stagerun.go +++ b/backend/internal/pipeline/stagerun.go @@ -622,7 +622,7 @@ func (r *Runner) runAttempt(ctx context.Context, st config.Stage, model, snapID // for one a sibling's infra failure cancelled — and the platform, which lets that event // survive any exit code, would record `paused` and tell a person to add money that would // change nothing. The context's own error is the truth and it travels instead. - r.setJobStatus(ctx, job.ID, "failed") + r.noteJobFailed(ctx, job.ID, ctx.Err()) return att, fmt.Errorf("pipeline: reserve $%.6f for %s/ch%d/chunk%d/%s: the run ended while waiting for headroom: %w", estimate, r.Book.BookID, ch.Chapter, ch.ChunkIdx, st.Name, ctx.Err()) } @@ -641,7 +641,12 @@ func (r *Runner) runAttempt(ctx context.Context, st config.Stage, model, snapID // that event survive any exit code, so it would record `paused` and ask for money that would // change nothing. if ctx.Err() != nil { - r.setJobStatus(ctx, job.ID, "failed") + // Same as the aborted wait above, and through the SAME contract: nothing was called and nothing + // broke, so a cancelled run leaves this position resumable rather than recording it as a failure + // (backlog row 389). It is ROUTED rather than simply omitted so the family can be counted: every + // site that might write the word goes through one function, and a reader enumerating them finds + // no exceptions to explain. + r.noteJobFailed(ctx, job.ID, ctx.Err()) return att, fmt.Errorf("pipeline: reserve $%.6f for %s/ch%d/chunk%d/%s: the run ended before the reservation was granted: %w", estimate, r.Book.BookID, ch.Chapter, ch.ChunkIdx, st.Name, ctx.Err()) } @@ -677,7 +682,7 @@ func (r *Runner) runAttempt(ctx context.Context, st config.Stage, model, snapID relGuard, err := r.rateGuard(model).acquire(ctx) if err != nil { r.releaseReservation(ctx, resv) - r.setJobStatus(ctx, job.ID, "failed") + r.noteJobFailed(ctx, job.ID, err) return att, fmt.Errorf("pipeline: rate-guard acquire for %s/ch%d/chunk%d/%s (model %s): %w", r.Book.BookID, ch.Chapter, ch.ChunkIdx, st.Name, model, err) } defer relGuard() @@ -756,7 +761,7 @@ func (r *Runner) runAttempt(ctx context.Context, st config.Stage, model, snapID rl := r.baseRequestLog(st, ch, model, reqHash) rl.LatencyMS, rl.Err, rl.OK = att.latency, err.Error(), false r.Store.LogRequest(ctx, r.Log, rl) - r.setJobStatus(ctx, job.ID, "failed") + r.noteJobFailed(ctx, job.ID, err) // The full axis in the LAST line the operator reads: a lone "stage draft // call: …" does not say WHICH chunk died on which model (smoke-run pain). return att, fmt.Errorf("pipeline: stage %s call (ch%d/chunk%d, model %s): %w", st.Name, ch.Chapter, ch.ChunkIdx, model, err) @@ -884,6 +889,24 @@ func (r *Runner) setJobStatus(ctx context.Context, jobID int64, status string) { } } +// noteJobFailed is setJobStatus("failed") for every site where the cause might be a STOP, and it is one +// function rather than a condition repeated at each of them because the family is one question: +// «did this position break, or did the run end while it was waiting?». +// +// ⛔ `failed` IS THE READ-MODEL'S WORD FOR A POSITION THAT BROKE. Writing it for a run somebody stopped +// sends whoever reads the jobs table hunting for a defect that is not there, which the flag vocabulary +// forbids in its own right (D39.93 п.2) — and the position is perfectly resumable: nothing was called, or +// what was called was healthy when the person cut it. Backlog row 389 named two of these sites; counting +// them found FIVE, and a per-site `if` would have closed three of them and left the count wrong again. +// +// A cancelled run leaves the job as it stands — pending, or running — exactly as a spend ceiling does. +func (r *Runner) noteJobFailed(ctx context.Context, jobID int64, cause error) { + if errors.Is(cause, context.Canceled) { + return + } + r.setJobStatus(ctx, jobID, "failed") +} + // releaseReservation releases an unspent reservation, logging an ERROR on failure // (the level the one non-swallowing site already used): a leaked reserved_usd // silently tightens the book/day ceiling until the next process restart recovers diff --git a/backend/internal/pipeline/terminologist.go b/backend/internal/pipeline/terminologist.go index a54c8984..84ae7e44 100644 --- a/backend/internal/pipeline/terminologist.go +++ b/backend/internal/pipeline/terminologist.go @@ -403,14 +403,25 @@ func (r *Runner) runTerminologist(ctx context.Context, snapID string, cands []te // conformance (re-scored here), primes the wire block, and is returned so the caller stamps it as the // banked type. Off (or unanswered) → the heuristic draft type stands. classified, gendered, crun, cerr := r.runClassifier(ctx, snapID, paid) - if cerr != nil { - return nil, nil, nil, res, cerr - } - res.Gendered = len(gendered) + // ⛔ THE MONEY IS RECORDED BEFORE THE VERDICT, and the order is the same one runStage keeps for the + // same reason: what a pass BOUGHT is a fact about what happened, not about whether it succeeded. Read + // after the error check, these two fields reported ZERO for a pass that had paid for batches and then + // met a broken provider — a struct lying about money to whoever reads it next. + // + // ⚠ WHAT THIS IS AND IS NOT. Today nothing reads it on that path: an error here ends the run, the + // driver returns no result, and the money is on the LEDGER either way (the batch settles through + // SettleWithCheckpoint like any call, RoleSpentUSD sums it from the durable checkpoints, and + // TestKillMinus9LosesAtMostOneCall pins that a settled checkpoint's money survives even a SIGKILL). + // So this is insurance against the next reader, not the repair of a live loss — backlog row 388 claimed + // more than that, and the claim was mine. res.ClassifyCostUSD = crun.costUSD // The classify pass has its OWN budget (classify_budget_usd), so it has its own cut — and the cold // run's incident was on THIS pass, not the render one. res.ClassifyBatchesDropped = crun.dropped + if cerr != nil { + return nil, nil, nil, res, cerr + } + res.Gendered = len(gendered) if len(classified) > 0 { res.Reclassified = applyTypes(cands, classified) opts := r.scoreOpts() @@ -465,11 +476,13 @@ func (r *Runner) runTerminologist(ctx context.Context, snapID string, cands []te run, rerr := r.runBankRoleBatches(ctx, snapID, plan, batches, "render") // The CUT is a property of the pass, and it has to reach the report: a bank that is partially // consolidated because the money ran out is a different object from one the role fully considered. + // The SPEND is recorded here for the same reason and in the same breath as the classifier's above: it + // is what happened, whatever the verdict turns out to be. res.BatchesDropped = run.dropped + res.EstimateUSD, res.CostUSD, res.CumUSD, res.Fresh = run.estimateUSD, run.costUSD, run.cumUSD, run.fresh if rerr != nil { return nil, nil, nil, res, rerr } - res.EstimateUSD, res.CostUSD, res.CumUSD, res.Fresh = run.estimateUSD, run.costUSD, run.cumUSD, run.fresh // ⚠ THE ONE-TIME COST OF THE ALREADY-BANKED FILTER. It needs BOTH halves and each is knowable at only // one moment: that the book had paid BEFORE this run (paidBefore, taken above the passes) and that this // run paid ANYWAY (run.fresh, knowable only now). Either half alone is a lie that has already been told diff --git a/backend/internal/pipeline/testdata/operator-messages.txt b/backend/internal/pipeline/testdata/operator-messages.txt index af0fab8c..e87aea1b 100644 --- a/backend/internal/pipeline/testdata/operator-messages.txt +++ b/backend/internal/pipeline/testdata/operator-messages.txt @@ -21,7 +21,9 @@ bookbuild.go staleUnits "build: the stale check could not run; whether the sourc bookrun.go translateBook "the run ended before its VOLUME grant was used up — the stop below is NOT the volume ceiling" chunkrun.go reportEvicted "memory: the injection token budget DROPPED bank rows before the model saw them — these terms had no canon on the wire for those units" cutcall.go recordCancelledStage "could not mark the stopped position; its money is recorded but the chunk will read as never started" +cutcall.go recordCancelledStage "could not read the position's stored disposition before marking it stopped; the mark is written and may replace an earlier verdict" cutcall.go recordCancelledStage "the run was stopped over a call that had already gone out; the position is marked cancelled and the resume re-does it on the same budget" +cutcall.go recordCancelledStage "the run was stopped over a position that ALREADY held a verdict from an earlier run; that verdict and its text are kept rather than overwritten by the stop mark (the resume re-does this position, and the stopped call's money is on the ledger)" cutcall.go settleCutCall "we cut a delivered call; the reservation estimate is charged as an ESTIMATE only when the provider had acknowledged it with a reply" escalation.go maybeEscalate "escalation hop denied by a USD ceiling; keeping the primary flag" escalation.go maybeEscalate "stage escalated to a fallback model" diff --git a/docs/PROGRESS.md b/docs/PROGRESS.md index 6301d33d..ab1dc9e3 100644 --- a/docs/PROGRESS.md +++ b/docs/PROGRESS.md @@ -186,6 +186,220 @@ ## Бэкенд +#### ДОРАБОТКА ПОСЛЕ ОТМЕНЫ (11.09, вход HEAD `d61469f`, инвариант `D39.240`). ⏳ В РАБОТЕ — НЕ КОММИЧУ + +> **Инвариант владельца, под которым всё ниже:** остановка ЖЁСТКАЯ, **деньги терять допустимо**, но без +> гонок, без половинчатых состояний, с верным возобновлением. ⛔ **Предмет отменённого пака НЕ +> возвращается:** мягкой остановки, латча в транспорте, прогонного источника, кадра `Stop`, минора словаря +> потока и реестра летящих вызовов здесь нет и не будет. +> +> ⭐ **Что надо знать до правок (пере-снято оркестратором, принимаю):** ЯДРО гарантии уже запинено +> настоящим убийством — `TestKillMinus9LosesAtMostOneCall` и +> `TestASigkillMidWaveLeavesAReadableJournalThatMatchesTheDatabase` зелёные в батарее (скипаются только их +> хелперы-подпроцессы, и это ДРУГИЕ имена). Значит резервации восстанавливаются, списанное равно сумме +> чекпойнтов, журнал не утверждает больше, чем в базе. **Пять предметов ниже — про КРАЯ, не про ядро.** + +**BASELINE НА ВХОДЕ — снят СВОИМ прогоном ДО первой правки, дерево чистое на `d61469f`.** +`make battery` → **MAKE-EXIT=0** · **19 `ok`** · **0 FAIL** · **4 «no test files»** · **4 скипа**, названы: +`TestMinerFullBookParity` · `TestCorpusBankKeyConflicts` · `TestHelperEventsRun` · `TestHelperKillLoop`. +`python3 docs/scripts/counts.py --check` → «Литералы сходятся с пере-счётом (8 проверок)», exit 0. +⭐ **Утверждение оркестратора про ЯДРО пере-снято СВОЕЙ рукой, а не принято на слово** (батарея печатает +только `ok` по пакетам, зелень отдельных имён из неё не читается): +`go test ./internal/store/ -run '^TestKillMinus9LosesAtMostOneCall$' -v` → **PASS**, и печатает пять +раундов настоящего SIGKILL: «round 4: +190 checkpoints (3060 total), committed=$3.060000 — a confirmed +commit survived SIGKILL and the ledger matches»; +`go test ./internal/pipeline/ -run '^TestASigkillMidWave…$' -v` → **PASS**. Ядро действительно стоит. + +**ПОРЯДОК И РАЗМЕТКА (по убыванию цены ошибки, как в наряде).** + +**1. Строка 375, ⛔-половина — СНАЧАЛА ФИКСТУРА, потом решение. ПРЕДЪЯВИТЬ ИЛИ ОПРОВЕРГНУТЬ.** +Подозрение: апсерт по ключу позиции ЗАМЕЩАЕТ строку, отмена кладёт `final_hash: ""`, и прогон, +пере-атаковавший ГОТОВУЮ позицию и оборванный, теряет указатель на текст, чекпойнт которого лежит на диске. +⚠ **Один из трёх названных маршрутов уже опровергнут ЧТЕНИЕМ, до всякой фикстуры: РЕДРАЙВ.** +`ResetChunkStages` (`backend/internal/store/chunkstatus.go:169-196`) в одной транзакции делает +`DELETE FROM checkpoints` И `DELETE FROM chunk_status` для сбрасываемых стадий — то есть к моменту +пере-атаки замещать НЕЧЕГО, прежнего вердикта уже нет. Это же говорят своими словами +`volume.go:605` и `status.go:1087`. ⇒ у сценария остаются ДВА маршрута: **пере-пин `--resnapshot`** (снапшот +уехал, `repinnable` ложно) и **правка исходника/промта** (не сходится `content_hash`). Оба обходят +быстрый путь резюма в `stagerun.go` и попадают в петлю попыток с ЖИВОЙ прежней строкой. +Фикстура обязана показать ЧЕТЫРЕ вещи разом, иначе она ничего не доказывает: (а) до второго прогона +позиция экспортировала текст; (б) после обрыва строка `flagged/cancelled` с пустым `final_hash`; +(в) СТАРЫЙ чекпойнт всё ещё в базе; (г) экспорт теперь отдаёт дыру. Если хоть одна не сходится — +пишу «недостижимо» и НЕ чиню. + +**2. Строка 387 — инверсия блокировок. МЕХАНИЗМ, но НЕ тот, что был.** +⚠ **Лечение из отменённого пака вернуть НЕЛЬЗЯ буквально: там отдельный мьютекс защищал ПОЛЕ, которого +теперь нет** (счётчик оценочных строк уехал вместе с паком). Мьютекс без охраняемого — это конструкция +ради галочки. ⇒ инвариант формулирую как ПОРЯДОК: *мьютекс эмиттера стоит ПЕРЕД пишущим соединением +стора, поэтому ничто, держащее пишущее соединение, не смеет брать мьютекс эмиттера.* Единственное место, +исполняемое под пишущим соединением, — замыкание строки расхода в `spendLine`. Лечение СТРУКТУРНОЕ и +дешёвое: замыкание не должно захватывать `e` ВООБЩЕ (сегодня оно трогает `e.log`) — забрать нужное в +локальные переменные ДО замыкания, и тогда взять метод эмиттера оттуда нельзя, не вернув `e` в захват +видимой правкой. Плюс правило словами на обоих концах. ⚠ И плюс ПИН, потому что правило в комментарии +механизмом не является: тест разбирает СВОЙ пакет (идиома уже есть — `operatormessages_test.go` парсит +пакет через `go/parser`) и краснеет, если замыкание снова ссылается на приёмник эмиттера. + +**3. Строка 388 — деньги банкового паса. МЕХАНИЗМ.** +Оборванный внутри паса прогон недосчитывает свой расход. ⚠ **Прямолинейная правка «присвоить +`r.lastTerminology` до проверки ошибки» — НЕВЕРНА:** у поля есть второй читатель, для которого `nil` +значит «пас НЕ ХОДИЛ» (`runner.go`, ⛔-абзац про пять границ и `bankexport.go`), и частичный результат +опубликовал бы счётчики консолидации о пасе, который оборвали. ⇒ деньги повезёт СВОЙ носитель, не +делящий смысл с вердиктом о пасе; одно определение, один сумматор, без двойного счёта на обычном пути. + +**4. Строка 389 — что видит человек после остановки. МЕХАНИЗМ, две половины.** +(а) На отмене движок возвращает `(nil, err)` — результата нет, печатать нечего. ⇒ печатаю НЕ выдуманный +результат, а то, что достоверно есть в СТОРЕ: леджер книги и сколько позиций разрешено. Это не +конструкция и не возврат отменённого §4.4. +(б) `jobs.status = failed` за остановленную человеком позицию: на отмене статус не трогать вовсе — +`failed` там слово о поломке, которой не было. + +**5. Строка 391 — третья ступень. ⚠ ВОПРОС О ГРАНИЦЕ, ЗАДАН ДО КОДА.** +Приёмка строки написана как «выход, оставляющий ТЕРМИНАЛЬНЫЙ КАДР». Но дешёвое лечение (`signal.Stop` + +`signal.Reset` ⇒ вернуть дефолтную диспозицию) даёт ровно ОБРАТНОЕ: второй сигнал убивает процесс +диспозицией по умолчанию, и кадра НЕ будет — это тот же SIGKILL, только вызванный вежливее. Кадр +оставляет лишь путь «второй сигнал ⇒ записать терминальную строку и выйти самим», а это уже не двадцать +строк и близко к отменённой лестнице. ⇒ спрашиваю оркестратора, ЧТО из двух заказано, и до ответа пункт +не трогаю. + +**ЧТО СЧИТАЮ РИСКОВАННЫМ В ЭТОЙ ДОРАБОТКЕ — названо до работы.** +1. Пункт 1 может оказаться НЕДОСТИЖИМЫМ, и это законный исход. Опасность — «доказать» его фикстурой, + которая ставит позицию в состояние, недостижимое боевым путём (например, руками пишет строку в + `chunk_status`). Фикстура обязана дойти до состояния ТОЛЬКО боевыми вызовами. +2. Пункт 3 трогает деньги на пути, где `nil` уже несёт смысл. Двойной счёт на ОБЫЧНОМ пути — главный + риск правки; пин обязан считать итог на прогоне, где пас отработал ЦЕЛИКОМ, а не только на оборванном. +3. Пункт 4(б): ветвь прерванного ожидания служит ДВУМ причинам (человек и упавший сосед). Снимая `failed`, + я обязана не потерять слово о позиции, которую действительно сломал сосед. + + +### ОТЧЁТ ПО ДОРАБОТКЕ — четыре предмета, каждый с командой и её выводом + +**375 — ⛔ ПРЕДЪЯВЛЕНО ФИКСТУРОЙ, потом починено. И один из трёх маршрутов снят ДО фикстуры.** +Замер ДО починки, боевыми путями (прогон → правка промта → `--resnapshot` → обрыв на летящем вызове): +позиция шла `disposition="ok" final_hash=770e5563de7f cost_usd=0.001820 text="ЧЕРНОВИК ПЕРЕВОДА"`, после +обрыва стала `disposition="flagged" flag_reason="cancelled" final_hash="" cost_usd=0.000000`, чекпойнт с +текстом остался в базе, а выгрузка стала отдавать пустоту. **Прогон сделал книгу ХУЖЕ, чем застал.** +⇒ Починка: пометка остановки пишется только туда, где своего вердикта нет; позиция, у которой вердикт уже +был, его сохраняет (`cutcall.go`, `recordCancelledStage`). Пины: `TestACutOverAPositionThatAlreadyShippedTextKeepsIt` +(после починки: строка и текст на месте, выгрузка отдаёт то же, что до обрыва) и КОНТРОЛЬ +`TestACutOverAVirginPositionStillMarksIt` (девственная позиция всё ещё помечается `cancelled`, attempts=1) — +без контроля первый пин удовлетворялся бы удалением пометки вообще. +⚠ **Маршрут «редрайв» из строки снят ЧТЕНИЕМ:** `ResetChunkStages` (`store/chunkstatus.go:169-196`) в одной +транзакции делает `DELETE FROM checkpoints` и `DELETE FROM chunk_status` — к моменту пере-атаки замещать +нечего. Прежняя формулировка строки вела сценарий именно через редрайв; она была моей, и опровергла её я. + +**387 — МЕХАНИЗМ, но не тот, что был в отменённом паке.** Вернуть «отдельный мьютекс» буквально было +нельзя: он охранял ПОЛЕ, которого больше нет. Инвариант переформулирован как ПОРЯДОК — мьютекс эмиттера +берётся ПЕРЕД пишущим соединением стора и никогда после, — и закрыт СТРУКТУРНО: замыкание строки расхода +больше не захватывает приёмник вовсе (`at`, `log` берутся в локальные до замыкания), так что взять оттуда +метод эмиттера нельзя, не вернув `e` видимой правкой. Правило записано на обоих концах (`emitter.mu`, +`spendLine`). Пин — `TestTheSpendLineClosureCannotReachTheEmitter`, разбирает СВОЙ исходник. +**Мутация снята рукой и засчитана ПО ТЕКСТУ:** первый посаженный мутант дал красное ОТ КОМПИЛЯТОРА +(`declared and not used: log`) — правый вердикт по неправой причине, не засчитан; пере-посажен так, чтобы +пакет собирался, и пин покраснел своим текстом: «the spend-line closure reaches the emitter ("e") at +[events.go:269:170]». Дерево после мутации восстановлено и сверено `diff` — IDENTICAL. + +**388 — ⚠ МОЯ СОБСТВЕННАЯ НАХОДКА ОКАЗАЛАСЬ ЗАВЫШЕННОЙ, и я это говорю до того, как на ней что-то +построят.** Строка утверждает, что оборванный внутри банкового паса прогон «недосчитывает свой расход на +той единственной строке, которую читает оператор». Проверила: **деньги не теряются.** Партия садится через +тот же `SettleWithCheckpoint`, `RoleSpentUSD` (`store/ledger.go:109`) суммирует их из ДОЛГОВЕЧНЫХ +чекпойнтов, они входят в `committed_usd`, в проекцию (`bankRoleCommittedUSD`) и в `status --json` +следующего прогона; а «строка, которую читает оператор», на этом пути НЕ ПЕЧАТАЕТСЯ ВООБЩЕ — драйвер +возвращает `(nil, err)`. То есть недосчёт ненаблюдаем, а наблюдаемая дыра — это строка **389**(а). +⇒ Сделано только узкое и честное: обе фазы паса записывают свой расход ДО проверки ошибки +(`terminologist.go`), чтобы структура не врала о деньгах СЛЕДУЮЩЕМУ читателю. Это страховка, а не ремонт +живой потери, и так и помечено в коде. **Диспозиция по строке — твоя: закрыть как слитую в 389 или +оставить узкой.** + +**389 — МЕХАНИЗМ, две половины, и найден ТРЕТИЙ носитель, которого в строке нет.** +(а) Остановленный прогон теперь печатает счёт ИЗ СТОРА, а не из результата, которого на этом пути нет: +`renderStoppedRun` (`cmd/tmctl/render.go`) — леджер книги, сколько позиций с вердиктом, сколько оборвано на +летящем вызове. Пин гоняет НАСТОЯЩИЙ бинарь: `TestAStoppedRunTellsTheOperatorWhatItBought`. +⚠ **Первая редакция пина была ЗЕЛЁНОЙ НА ПУСТОМ СЦЕНАРИИ:** она ждала журнального рукопожатия, а его +пишут ДО первого вызова, поэтому сигнал приходил в прогон, который ничего не купил, и счёт печатался как +`committed=$0.000000 · verdict: 0 · cut: 0` — все четыре подстроки на месте, числа пустые. Перестроена: +провайдер САМ объявляет приход второго запроса, и пин требует ненулевых чисел. После перестройки: +`committed=$0.000200 · positions with a verdict: 1 · cut mid-call: 1`. +(б) `jobs.status = failed` за остановленную человеком позицию снят в ДВУХ ветвях, которые называет строка +(`stagerun.go`), **и в ТРЕТЬЕЙ, которой в строке нет и через которую остановка как раз и ходит** — +`settleCutCall` (`cutcall.go`) писал `failed` для всякого обрыва, включая `CutByParent`. Теперь слово +пишется по ПРИЧИНЕ. Пины: `TestAStoppedPositionIsNotRecordedAsFailed` (обрыв человеком → `"running"`) и +КОНТРОЛЬ `TestABrokenSocketIsStillRecordedAsFailed` (сокет умер сам → `"failed"`); без контроля первый пин +удовлетворялся бы тем, что слово не пишут никогда. + +**391 — НЕ ТРОГАЛА** (снята из доработки по ответу оркестратора: дешёвое лечение кадра не оставляет, а +выход с кадром — отдельный предмет с ценой). + +**⛔ ПОПРАВКА К СОБСТВЕННОМУ ОТЧЁТУ ПО 389(б): носителей ПЯТЬ, а не два и не три.** +Счёт знаменателем (`grep` по всем `setJobStatus(…, "failed")` в пайплайне — **семь** мест, разобрано +каждое): отменой достижимы ПЯТЬ — путь оборванного вызова (`cutcall.go`), ветвь `waitAborted`, охранник +`ctx.Err() != nil` после впуска, **рейт-гард** (`acquire(ctx)` возвращает `ctx.Err()` на отмене) и +**транспортный отказ** («запрос не ушёл» — именно сюда падает Ctrl-C по началу вызова). Последние два не +названы ни строкой, ни моим письмом. Оставшиеся два (`clientFor`, маршалинг usage) — настоящие поломки, +слово остаётся. +⚠ **И одна из двух ветвей, о которых я отчиталась как о починенных, починена НЕ БЫЛА:** скрипт правки упал +на ассерте второго замещения и не записал файл вовсе, а отчёт был написан по намерению. Поймано счётом, +не памятью. +⇒ Починено ОДНИМ контрактом: `noteJobFailed(ctx, jobID, cause)` рядом с сеттером, который он сужает — +«отменённый прогон оставляет джоб как есть, ровно как это делает денежный потолок». Пять `if`-ов закрыли +бы три и оставили счёт неверным опять. +⚠ Пины ловят класс через путь оборванного вызова; **на рейт-гард и транспортный отказ отдельных пинов +НЕТ** — покрытие уже, чем починка, и это сказано, чтобы никто не записал его шире. + +### ЧТО НЕ УДАЛОСЬ И ЧЕГО Я НЕ ПРОВЕРЯЛА + +1. **Три моих прибора с первого раза мерили не то, и все три я нашла сама — но НАШЛА, а не предусмотрела.** + Фикстура 375 отменяла по счётчику гейта (растёт на резервации, до ухода запроса) и читала «строка цела» + как опровержение — я была в шаге от того, чтобы записать «сценарий недостижим». Пин 389(а) был зелен на + прогоне, который ничего не купил. Мутант 387 с первого раза дал красное от компилятора. +2. **Отчёт по 389(б) был написан по намерению, а не по дереву** (см. поправку выше). Это не прибор — это я. +3. **Рейт-гард и транспортный отказ починены без своих пинов.** Класс закрыт одним контрактом, но + покрытие тестами уже, чем починка. +4. **Строка 388 — узкая страховка, а не ремонт;** и её я не гоняла на живом банковом пасе: утверждение + «деньги паса долговечны» опирается на чтение (`RoleSpentUSD` суммирует чекпойнты) плюс уже зелёный + `TestKillMinus9LosesAtMostOneCall`, а не на собственную банковую фикстуру. +5. **Строка 391 не тронута** — снята из доработки по решению оркестратора. +6. **Половина строки 375 остаётся открытой:** позиция с прежним вердиктом теперь читается статусом как + «сделана», хотя её пере-делают, и исходная половина строки (выгрузка читает `cancelled` как выпавший + кусок текста) в этот заход не входила. +7. **Процессная оплошность:** правку комментария я внесла, пока шла батарея, чем обесценила её числа — + пришлось перезапускать. Прогон, чьи числа идут в отчёт, обязан стартовать ПОСЛЕ последней правки. + +**ОСТАТОК, КОТОРЫЙ НАЗЫВАЮ САМА (375).** Позиция, сохранившая прежний вердикт, сохраняет и прежний +`cost_usd`: деньги ОБОРВАННОЙ попытки в эту проекцию не добавляются (для обрыва до заголовков это $0, для +оборванного после 2xx — оценка). До починки было не лучше, а хуже: строка замещалась и теряла ПРЕЖНЮЮ +сумму целиком. Настоящий носитель денег на обоих путях — леджер (`checkpoints` + `spend` + `request_log`), +и он полон; неполна именно попозиционная проекция. Названо, чтобы никто не прочитал «вердикт сохранён» как +«и деньги посчитаны». + +### ЧИСЛА — снято своей рукой, командами + +**Батарея на ФИНАЛЬНОМ дереве** (прогон стартовал ПОСЛЕ последней правки; два предыдущих прогона убиты +именно потому, что я успевала тронуть дерево под ними): +`make battery` → **MAKE-EXIT=0** · **19 `ok`** · **0 FAIL** · **4 «no test files»** · **4 скипа**, названы: +`TestMinerFullBookParity` · `TestCorpusBankKeyConflicts` · `TestHelperEventsRun` · `TestHelperKillLoop`. +Сходится со строкой на входе — доработка не сдвинула ни одного пакета. + +`python3 docs/scripts/counts.py --check` → «Литералы сходятся с пере-счётом (8 проверок)», exit 0. + +**Мутационный прогон:** `make mutations` идёт; число и состав впишу сюда же по окончании. В каталог +добавлены ТРИ записи под новые гарантии (`STOP-cut-does-not-blind-an-earlier-verdict` · +`STOP-a-cut-by-a-person-is-not-a-failed-job` · `STOP-the-spend-line-closure-cannot-reach-the-emitter`), +все три в батарейном подмножестве; каталог 360 → 363, подмножество 149 → 152. ⚠ Одна из трёх после +рефактора «одного контракта» указывала на исчезнувший якорь — пере-наведена на `noteJobFailed`, и все три +проверены на совпадение `find` с живым деревом (по 1 хиту каждая). + +**Дерево:** 11 путей — 8 правленых (+204/−12) и 3 новых теста. Вне `backend/` тронут только журнал. + +**СОСТАВ ПРАВКИ.** `internal/pipeline/cutcall.go` (страж вердикта · слово джоба по причине) · +`internal/pipeline/stagerun.go` (контракт `noteJobFailed` и пять сайтов через него) · +`internal/pipeline/events.go` (замыкание строки расхода не захватывает эмиттер; порядок замков назван на +обоих концах) · `internal/pipeline/terminologist.go` (расход паса пишется до вердикта) · +`cmd/tmctl/render.go` + `cmd/tmctl/main.go` (счёт остановленного прогона из стора) · +`internal/pipeline/testdata/operator-messages.txt` (две строки каталога сообщений) · +`cmd/tmmutate/mutations.json` (три записи) · новые тесты: +`internal/pipeline/cutoververdict_test.go` · `internal/pipeline/spendlineorder_test.go` · +`cmd/tmctl/stoppedaccount_test.go`. + #### Пак «ДВЕ ОСТАНОВКИ» (10.09, промт `docs/BACKEND_SOFT_STOP_SESSION_PROMPT.md`, вход HEAD `121c3c7`). ⛔ **ОТМЕНЁН ВЛАДЕЛЬЦЕМ 10.09, код зоны откатывается к HEAD** > ⛔ **Слово владельца:** пак отменён не по качеству, а по РАЗМАХУ — восемнадцать файлов движка ради двух