Sign in

Search issue titles and bodies, change requests and comments. Private repositories you cannot read are not included.

vole
Clone

Read only, no credentials:

https://rodent.software/vole.git

Write over SSH with a registered key:

git clone ssh://git@rodent.software:2222/vole.git

A free and open-source forge that lives in your Git repo.

Phase 4: the runner uploads the log, so the server cannot write it

86fe5bb49ddeeb89a5d58459f27a86a83f82481a · Keenan Nemetz · 17d ago · parent 9cc2f087

Phase 4: the runner uploads the log, so the server cannot write it

Streaming made the server the author of bytes the runner produced. Heartbeats
carried output chunks; the server concatenated them into a SQLite column and, at
finish, hashed the result itself with `LFS.PutBytes`. So the archived object's id was
the server's, not the writer's — the one output in the system that worked that way,
since artifacts are uploaded by the runner through put-object and pages/releases are
pushed by it. Nothing depended on it, which is why it was harmless; a signed run
record could never have bound it, which is why it had to go.

Streaming is dropped. At finish the runner uploads its log through the same
git-lfs-transfer path artifacts use, gets the object id the store computed from the
content, and names it in the finish message. The server's rule is the artifact rule:
the store is the authority on whether the bytes exist, and a claimed size that is not
the object's size is refused. Heartbeats now carry nothing but the lease.

A log is per attempt, not per run. A job that kills a runner is requeued, so one run
can have several logs, and the interesting one is usually the attempt that died:
`run_logs(run_id, attempt, oid, size)` replaces the single column, `AttemptLogs`
reads them oldest first, `/runs/<id>/log` serves the newest and `?attempt=N` picks
one, and `vole gc` treats every attempt's object as a root. Rows written before this
change still have their `log_oid`, which reads keep honouring; `Store.Log` and
`SetLogOID` are gone with the code that used them.

The cost, stated plainly: there is no live tail any more, and an attempt whose runner
was killed leaves no log at all — the attempt that hung is exactly the log somebody
wants. That is the trade: a log that can be shown to be the runner's is worth more
than one that arrives early. It also removes an unbounded text column from the queue,
which was growing into the WAL and every backup until a run finished.

Verified: TestCheckRunLogTrustsTheStore pins the new rule at the boundary (stored log
accepted, size mismatch refused, object absent refused, non-oid refused, no store
refused); TestLogsAreRecordedPerAttempt shows two attempts recorded separately,
`Get` returning the newest, both objects named for the sweep, and a finished run
refusing a log; TestHeartbeatAndFinishNeedTheLease now proves a stranger can neither
heartbeat, nor finish, nor record a log, and that a finished run carries no log text;
and the end-to-end test that runs the real binary now asserts the served log hashes
to the object id in the run row and that the queue kept no copy of it. scripts/ci.sh
green (gofmt, vet, build, markdown links, go test -race ./...).

internal/server/integration_test.go +19−5

@@ -5,6 +5,7 @@ import (
5 5 "bytes"
6 6 "crypto/ed25519"
7 7 "crypto/rand"
8 "crypto/sha256"
8 9 "encoding/pem"
9 10 "errors"
10 11 "fmt"
@@ -2622,13 +2623,22 @@ jobs:
2622 2623 if done.Status != runs.StatusSuccess {
2623 2624 t.Fatalf("run status = %s (exit %d)", done.Status, done.ExitCode)
2624 2625 }
2625 // The log left the queue as a content-addressed object, and the web serves it.
2626 // The log is the runner's own object, not something the queue collected: the id
2627 // in the run is the hash of the bytes the runner uploaded, the queue holds no
2628 // text at all, and the page serves those bytes verbatim.
2626 2629 if done.LogOID == "" {
2627 2630 t.Fatalf("finished run has no archived log: %+v", done)
2628 2631 }
2629 if code, body := f.get("/r/" + f.repo + "/runs/" + done.ID + "/log"); code != 200 || !strings.Contains(body, "hello from the runner") {
2632 if done.Log != "" {
2633 t.Fatalf("the queue kept a copy of the log: %q", done.Log)
2634 }
2635 code, body := f.get("/r/" + f.repo + "/runs/" + done.ID + "/log")
2636 if code != 200 || !strings.Contains(body, "hello from the runner") {
2630 2637 t.Fatalf("run log page = %d, body:\n%s", code, body)
2631 2638 }
2639 if sum := fmt.Sprintf("%x", sha256.Sum256([]byte(body))); sum != done.LogOID {
2640 t.Fatalf("the served log hashes to %s, but the run names %s: the object is not the runner's bytes", sum, done.LogOID)
2641 }
2632 2642 if done.SHA != mustSHA(t, work) {
2633 2643 t.Fatalf("run recorded sha %s, want the pushed commit", done.SHA)
2634 2644 }
@@ -2681,7 +2691,11 @@ jobs:
2681 2691 return r.Status == runs.StatusSuccess || r.Status == runs.StatusFailed
2682 2692 })
2683 2693 if done.Status != runs.StatusSuccess {
2684 t.Fatalf("the retried run did not succeed: %s (exit %d)\n%s", done.Status, done.ExitCode, done.Log)
2694 // The log is an object the finished attempt uploaded; the attempt that was
2695 // killed never uploaded one, which is the cost of not streaming.
2696 _, body := f.get("/r/" + f.repo + "/runs/" + done.ID + "/log")
2697 t.Fatalf("the retried run did not succeed: %s (exit %d, log object %q)\n%s",
2698 done.Status, done.ExitCode, done.LogOID, body)
2685 2699 }
2686 2700 if done.Attempts < 2 {
2687 2701 t.Fatalf("attempts = %d; the job was not actually handed to a second runner", done.Attempts)
@@ -2741,8 +2755,8 @@ jobs:
2741 2755 second := f.waitForRun(t, 30*time.Second, func(r *runs.Run) bool {
2742 2756 return r.SHA == secondSHA && r.Status != runs.StatusQueued && r.Status != runs.StatusRunning
2743 2757 })
2744 // Logs are content-addressed objects once a run finishes, so read them the
2745 // way the web does rather than from the queue row.
2758 // A log is an object the runner uploaded when its attempt ended, so read it the
2759 // way the web does rather than expecting text in the queue row.
2746 2760 logOf := func(r *runs.Run) string {
2747 2761 t.Helper()
2748 2762 code, body := f.get("/r/" + f.repo + "/runs/" + r.ID + "/log")