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/git/vole.git

Write over SSH with a registered key:

git clone ssh://git@0.0.0.0:2222/vole.git

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

Stream run logs over the runner's SSH channel

5ece70a50ebda392626b92bdf29d28bc9b444954 · Keenan Nemetz · 10d ago · parent fdf2340f

Stream run logs over the runner's SSH channel

The runner wrote the log to a temp file and uploaded it as one LFS object
when the job ended, so a running job had no log to read and a log was stored
like a shared artifact even though it belongs to one attempt.

The runner sends 128 KiB chunks over the same runner channel that holds the
lease. The server appends them to data/logs/<repo>/<run>/<attempt>.log and
records the size while the run is still running. The finish record carries
the final size; the server checks the file length, syncs it, and stores the
result. A partial or failed stream leaves no log on the record.

Logs are no longer LFS objects: they are not shared, not content-addressed,
and the web serves the file directly, with range and step slices. GC no
longer treats them as LFS roots.

server/ssh/runner.go +89−5

@@ -105,6 +105,16 @@ type runnerRequest struct {
105 105 // publishes it to Git: this channel is where the server receives it, checks it
106 106 // against the lease, and stores it.
107 107 Record *runs.Record `json:"record,omitempty"`
108 // Log is one chunk of the attempt's log, sent while the job runs.
109 Log *runnerLogChunk `json:"log,omitempty"`
110 }
111
112 // runnerLogChunk is one piece of an attempt's log. Offset is where it starts in
113 // the attempt's file, so the server can refuse a gap or a duplicate.
114 type runnerLogChunk struct {
115 Attempt int `json:"attempt"`
116 Offset int64 `json:"offset"`
117 Data []byte `json:"data"`
108 118 }
109 119
110 120 type runnerStep struct {
@@ -174,6 +184,8 @@ type runnerReply struct {
174 184 // nothing — a typo it would otherwise discover as a permanently idle runner —
175 185 // instead of after the first build that never arrived.
176 186 Repos []string `json:"repos,omitempty"`
187 // LogSize is how much of the log the server has after a log chunk.
188 LogSize int64 `json:"log_size,omitempty"`
177 189 }
178 190
179 191 // serveRunner answers one runner session until it disconnects.
@@ -298,6 +310,53 @@ func (s *Server) serveRunner(ch xssh.Channel, user string) {
298 310 _ = cfg.Runs.SessionWorking(sessionID, run.Repo, run.ID, time.Now().UTC())
299 311 _ = enc.Encode(runnerReply{Op: "lease", OK: true, Run: job, Lease: int(cfg.Lease.Seconds())})
300 312
313 case "log":
314 if req.Log == nil {
315 _ = enc.Encode(runnerReply{Op: "log", Error: "a log request carries no chunk"})
316 continue
317 }
318 run, err := cfg.Runs.Get(req.Run)
319 if err != nil {
320 _ = enc.Encode(runnerReply{Op: "log", Error: err.Error()})
321 continue
322 }
323 if run == nil {
324 _ = enc.Encode(runnerReply{Op: "log", Error: fmt.Sprintf("no run %s", req.Run)})
325 continue
326 }
327 if req.Log.Attempt != run.Attempts {
328 _ = enc.Encode(runnerReply{Op: "log", Error: fmt.Sprintf(
329 "%s: the log is attempt %d but this runner holds attempt %d",
330 req.Run, req.Log.Attempt, run.Attempts)})
331 continue
332 }
333 held, err := cfg.Runs.Held(run.ID, owner)
334 if err != nil {
335 _ = enc.Encode(runnerReply{Op: "log", Error: err.Error()})
336 continue
337 }
338 if !held {
339 _ = enc.Encode(runnerReply{Op: "log", OK: false})
340 continue
341 }
342 if cfg.Logs == nil {
343 _ = enc.Encode(runnerReply{Op: "log", Error: "this instance has no log directory"})
344 continue
345 }
346 size, err := cfg.Logs.Append(run.Repo, run.ID, req.Log.Attempt, req.Log.Offset, req.Log.Data)
347 if err != nil {
348 _ = enc.Encode(runnerReply{Op: "log", Error: err.Error()})
349 continue
350 }
351 if ok, err := cfg.Runs.RecordLogSize(run.ID, owner, req.Log.Attempt, size, time.Now().UTC()); err != nil {
352 _ = enc.Encode(runnerReply{Op: "log", Error: err.Error()})
353 continue
354 } else if !ok {
355 _ = enc.Encode(runnerReply{Op: "log", OK: false})
356 continue
357 }
358 _ = enc.Encode(runnerReply{Op: "log", OK: true, LogSize: size})
359
301 360 case "heartbeat":
302 361 // Liveness only: the lease is what a heartbeat buys. Presence is refreshed
303 362 // here too, so a long build does not make its runner look gone.
@@ -344,6 +403,36 @@ func (s *Server) serveRunner(ch xssh.Channel, user string) {
344 403 _ = enc.Encode(runnerReply{Op: "finish", Error: err.Error()})
345 404 continue
346 405 }
406 if req.Record.LogSize == 0 {
407 // A failed stream leaves a partial file, and an attempt that produced
408 // no output leaves none. Either way the result names no log.
409 if cfg.Logs != nil {
410 if err := cfg.Logs.Remove(run.Repo, run.ID, req.Record.Attempt); err != nil {
411 _ = enc.Encode(runnerReply{Op: "finish", Error: err.Error()})
412 continue
413 }
414 }
415 } else {
416 if cfg.Logs == nil {
417 _ = enc.Encode(runnerReply{Op: "finish", Error: "this instance has no log directory"})
418 continue
419 }
420 size, err := cfg.Logs.Size(run.Repo, run.ID, req.Record.Attempt)
421 if err != nil {
422 _ = enc.Encode(runnerReply{Op: "finish", Error: err.Error()})
423 continue
424 }
425 if size != req.Record.LogSize {
426 _ = enc.Encode(runnerReply{Op: "finish", Error: fmt.Sprintf(
427 "%s: the log is %d bytes but the record says %d",
428 req.Run, size, req.Record.LogSize)})
429 continue
430 }
431 if err := cfg.Logs.Sync(run.Repo, run.ID, req.Record.Attempt); err != nil {
432 _ = enc.Encode(runnerReply{Op: "finish", Error: err.Error()})
433 continue
434 }
435 }
347 436 ok, err := cfg.Runs.RecordAttempt(run.ID, owner, *req.Record, time.Now().UTC())
348 437 if err != nil {
349 438 _ = enc.Encode(runnerReply{Op: "finish", Error: err.Error()})
@@ -374,11 +463,6 @@ func (s *Server) serveRunner(ch xssh.Channel, user string) {
374 463 // the object store. A push used to be checked for pointer hygiene at the boundary;
375 464 // the finish channel is the boundary now.
376 465 func checkRecordPointers(objects *lfs.Store, repoName string, rec runs.Record) error {
377 if rec.Log != nil {
378 if err := checkPointer(objects, repoName, *rec.Log); err != nil {
379 return fmt.Errorf("log: %w", err)
380 }
381 }
382 466 for _, a := range rec.Artifacts {
383 467 if err := checkPointer(objects, repoName, lfs.Pointer{OID: a.OID, Size: a.Size}); err != nil {
384 468 return fmt.Errorf("artifact %s: %w", a.Name, err)