From a0c4de79f7331189c6ab414d9575bf1187edccd9 Mon Sep 17 00:00:00 2001 From: bircni Date: Fri, 21 Aug 2026 07:25:11 +0000 Subject: [PATCH] feat: add `log.job.dir` (#1165) `log.job.dir` makes the runner write a copy of every task's log to that directory, as `-task-.log`: the rows exactly as Gitea received them, with the same masking and the job's result on the last line. Off by default, and what Gitea shows does not change. `log.job.retention` (default `168h`) and `log.job.max_size` (default `1GB`) bound the directory. Documented in the README. --------- Co-authored-by: silverwind Reviewed-on: https://gitea.com/gitea/runner/pulls/1165 Reviewed-by: silverwind <2021+silverwind@noreply.gitea.com> --- README.md | 6 ++ internal/pkg/config/config.example.yaml | 13 ++- internal/pkg/config/config.go | 13 ++- internal/pkg/config/config_test.go | 22 +++-- internal/pkg/report/joblog.go | 120 ++++++++++++++++++++++++ internal/pkg/report/joblog_test.go | 110 ++++++++++++++++++++++ internal/pkg/report/reporter.go | 48 +++++++--- internal/pkg/report/reporter_test.go | 19 ++-- 8 files changed, 314 insertions(+), 37 deletions(-) create mode 100644 internal/pkg/report/joblog.go create mode 100644 internal/pkg/report/joblog_test.go diff --git a/README.md b/README.md index 01d53d78..4c3ac657 100644 --- a/README.md +++ b/README.md @@ -386,6 +386,12 @@ Both hooks are synchronous and block the job while they run. Either one exiting See **[docs/job-hooks.md](docs/job-hooks.md)** for the execution order, environment, and platform notes. +#### Local job logs (`log.job.dir`) + +Set `log.job.dir` to a path and the runner writes a copy of every task's log there as `-task-.log`: the rows exactly as Gitea received them, with the same secrets masked and the job's result on the last line. Off by default, and what Gitea shows does not change. + +`log.job.retention` (default `168h`) is how long a log is kept, expired ones being deleted as new tasks start, and `log.job.max_size` (default `1GB`) caps one log. Keep `retention` above `runner.timeout` so a long job cannot outlive its own log, and prefer local disk, the file is written while the job runs. Only the runner's own user can read it. + ### Example Deployments Check out the [examples](examples) directory for sample deployment types. diff --git a/internal/pkg/config/config.example.yaml b/internal/pkg/config/config.example.yaml index 8092464f..d63ff81c 100644 --- a/internal/pkg/config/config.example.yaml +++ b/internal/pkg/config/config.example.yaml @@ -1,13 +1,20 @@ # Every option with its default value, all commented out. Read this file, do not copy it. # `./gitea-runner config init` writes a config file to copy the lines you change into. -# Logging for the runner process itself (messages printed to stderr). -# This does not control how workflow step output is streamed to the Gitea UI; -# tune that with runner.log_report_* below. +# Logging for the runner process itself (messages printed to stderr), plus the copy of +# each task's log kept under log.job. Neither controls how workflow step output is streamed +# to the Gitea UI; tune that with runner.log_report_* below. log: # logrus severity: trace, debug, info, warn, error, fatal, panic. # trace and debug turn on caller/file:line in log lines. Default if omitted: info. #level: info + # Write a copy of each task's log to dir as -task-.log, so a job's output + # survives a failure to send it to Gitea. A path turns them on, empty turns them off. + # retention is how long a log is kept (0s keeps all), max_size caps one log (0 is no limit). + #job: + # dir: "" + # retention: 168h + # max_size: 1GB runner: # Where to store the registration result. diff --git a/internal/pkg/config/config.go b/internal/pkg/config/config.go index b2863462..c1ada7d9 100644 --- a/internal/pkg/config/config.go +++ b/internal/pkg/config/config.go @@ -38,9 +38,17 @@ const Minimal = `# Minimal config file. Every option it does not set keeps its d # "gitea-runner config generate" prints all options, "config set " sets one here. ` -// Log represents the configuration for logging. +// Log represents the runner process's own logging, plus the copy of each task's log it keeps. type Log struct { Level string `yaml:"level"` // Level indicates the logging level. + Job LogJob `yaml:"job"` // Job configures the copy of each task's log kept on the runner host. +} + +// LogJob represents the configuration for the copy of each task's log kept on the runner host. +type LogJob struct { + Dir string `yaml:"dir"` // Dir is the directory the runner writes each task's log to. Empty, the default, writes none. + Retention time.Duration `yaml:"retention"` // Retention deletes a task's log directory once it is older than this. Default 168h, 0s keeps them regardless of age. + MaxSize Size `yaml:"max_size"` // MaxSize caps one task's log file. Default 1GB, 0 is no limit. } // Runner represents the configuration for the runner. @@ -202,7 +210,8 @@ type Config struct { // LoadDefault returns the default configuration. // If file is not empty, it will be used to load the configuration. func LoadDefault(file string) (*Config, error) { - cfg := &Config{Cache: DefaultCache()} + // Seeded before the file is read, so a written 0 can mean off. + cfg := &Config{Cache: DefaultCache(), Log: Log{Job: LogJob{Retention: 7 * 24 * time.Hour, MaxSize: 1024 * 1024 * 1024}}} definedRunnerKeys := map[string]bool{} if file != "" { content, err := os.ReadFile(file) diff --git a/internal/pkg/config/config_test.go b/internal/pkg/config/config_test.go index 471ec29b..a0409170 100644 --- a/internal/pkg/config/config_test.go +++ b/internal/pkg/config/config_test.go @@ -186,14 +186,14 @@ runner: assert.Equal(t, 5*time.Minute, cfg.Runner.PostTaskScriptTimeout) } -func TestLoadDefault_LoadsCacheEviction(t *testing.T) { - write := func(t *testing.T, body string) string { - t.Helper() - path := filepath.Join(t.TempDir(), "config.yaml") - require.NoError(t, os.WriteFile(path, []byte(body), 0o600)) - return path - } +func write(t *testing.T, body string) string { + t.Helper() + path := filepath.Join(t.TempDir(), "config.yaml") + require.NoError(t, os.WriteFile(path, []byte(body), 0o600)) + return path +} +func TestLoadDefault_LoadsCacheEviction(t *testing.T) { t.Run("sizes accept any spelling of the unit", func(t *testing.T) { cfg, err := LoadDefault(write(t, "cache:\n retention: 336h\n repo_size_limit: 50gb\n size_limit: 1TiB\n sweep_interval: 15m\n")) require.NoError(t, err) @@ -217,6 +217,14 @@ func TestLoadDefault_LoadsCacheEviction(t *testing.T) { }) } +func TestLoadDefault_LoadsJobLogs(t *testing.T) { + cfg, err := LoadDefault(write(t, "log:\n job:\n dir: /var/log/jobs\n retention: 0s\n max_size: 100MB\n")) + require.NoError(t, err) + assert.Equal(t, "/var/log/jobs", cfg.Log.Job.Dir) + assert.Zero(t, cfg.Log.Job.Retention, "zero keeps every task directory") + assert.Equal(t, Size(100*1024*1024), cfg.Log.Job.MaxSize) +} + func TestLoadDefault_LoadsJobHooks(t *testing.T) { dir := t.TempDir() path := filepath.Join(dir, "config.yaml") diff --git a/internal/pkg/report/joblog.go b/internal/pkg/report/joblog.go new file mode 100644 index 00000000..ce1fb832 --- /dev/null +++ b/internal/pkg/report/joblog.go @@ -0,0 +1,120 @@ +// Copyright 2026 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package report + +import ( + "fmt" + "os" + "path/filepath" + "strings" + "time" + + "gitea.com/gitea/runner/internal/pkg/config" + + log "github.com/sirupsen/logrus" +) + +const ( + jobLogNameLayout = "20060102-150405" + jobLogTimestamp = "2006-01-02T15:04:05.000Z" +) + +// jobLog is this task's copy of the rows sent to Gitea. A nil *jobLog is a no-op, and every +// caller holds Reporter.stateMu, so it needs no lock. +type jobLog struct { + file *os.File + size int64 + max int64 + stopped bool // the cap was reached or a write failed, only the trailer still follows + closed bool +} + +// openJobLog returns nil when the logs are off or cannot be created: a copy must never fail a job. +func openJobLog(cfg config.LogJob, taskID int64, started time.Time) *jobLog { + if cfg.Dir == "" { + return nil + } + + if err := os.MkdirAll(cfg.Dir, 0o700); err != nil { // repository output, readable by this user only + log.Warnf("cannot create job log directory %s: %v", cfg.Dir, err) + return nil + } + pruneJobLogs(cfg.Dir, cfg.Retention, started) + + name := fmt.Sprintf("%s-task-%d.log", started.UTC().Format(jobLogNameLayout), taskID) + file, err := os.OpenFile(filepath.Join(cfg.Dir, name), os.O_WRONLY|os.O_CREATE|os.O_TRUNC, 0o600) + if err != nil { + log.Warnf("cannot create job log: %v", err) + return nil + } + log.Infof("writing the log of task %d to %s", taskID, file.Name()) + return &jobLog{file: file, max: int64(cfg.MaxSize)} +} + +func (j *jobLog) write(t time.Time, content string) { + if j == nil || j.stopped || j.closed { + return + } + line := t.UTC().Format(jobLogTimestamp) + " " + content + if j.max > 0 && j.size+int64(len(line))+1 > j.max { + j.stopped = true + j.line(runnerLine(fmt.Sprintf("truncated: log.job.max_size of %d bytes reached", j.max))) + return + } + j.line(line) +} + +func (j *jobLog) close(trailer string) { + if j == nil || j.closed { + return + } + j.closed = true + j.line(runnerLine(trailer)) // past the cap on purpose: no trailer means the runner died mid-job + if err := j.file.Close(); err != nil { + log.Warnf("cannot close %s: %v", j.file.Name(), err) + } +} + +// line writes unbuffered, so a killed runner keeps what it had written. Only the runner's own +// lines can carry a newline, a row reaching Gitea cannot (see DEVELOPMENT.md). +func (j *jobLog) line(content string) { + n, err := j.file.WriteString(strings.ReplaceAll(content, "\n", `\n`) + "\n") + j.size += int64(n) + if err != nil { + j.stopped = true // reported once, a failing write is a full disk and retrying floods the log + log.Warnf("cannot write %s: %v", j.file.Name(), err) + } +} + +func runnerLine(content string) string { + return time.Now().UTC().Format(jobLogTimestamp) + " [runner] " + content +} + +// pruneJobLogs removes the logs older than retention. The age comes from the name, not the +// mtime, which a reader or a backup tool can move. +func pruneJobLogs(root string, retention time.Duration, now time.Time) { + if retention <= 0 { + return + } + entries, err := os.ReadDir(root) + if err != nil { + log.Warnf("cannot list job log directory %s: %v", root, err) + return + } + + cutoff := now.Add(-retention) + for _, entry := range entries { + stamp, _, isTaskLog := strings.Cut(entry.Name(), "-task-") + if !isTaskLog || entry.IsDir() || !strings.HasSuffix(entry.Name(), ".log") { + continue + } + if started, err := time.Parse(jobLogNameLayout, stamp); err != nil || !started.Before(cutoff) { + continue + } + name := filepath.Join(root, entry.Name()) + if err := os.Remove(name); err != nil { + log.Warnf("cannot remove expired job log %s: %v", name, err) + } + } +} diff --git a/internal/pkg/report/joblog_test.go b/internal/pkg/report/joblog_test.go new file mode 100644 index 00000000..f3d801df --- /dev/null +++ b/internal/pkg/report/joblog_test.go @@ -0,0 +1,110 @@ +// Copyright 2026 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package report + +import ( + "context" + "os" + "path/filepath" + "strings" + "testing" + "time" + + "gitea.com/gitea/runner/internal/pkg/client/mocks" + "gitea.com/gitea/runner/internal/pkg/config" + + connect_go "connectrpc.com/connect" + runnerv1 "gitea.dev/actionslib/runner/v1" + log "github.com/sirupsen/logrus" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/mock" + "github.com/stretchr/testify/require" + "google.golang.org/protobuf/types/known/structpb" +) + +var testStart = time.Date(2026, 8, 14, 9, 12, 3, 0, time.UTC) + +func readJobLog(t *testing.T, joblog *jobLog) string { + t.Helper() + content, err := os.ReadFile(joblog.file.Name()) + require.NoError(t, err) + return string(content) +} + +func TestJobLog_MirrorsUploadedRows(t *testing.T) { + client := mocks.NewClient(t) + client.On("UpdateLog", mock.Anything, mock.Anything).Return(func(_ context.Context, req *connect_go.Request[runnerv1.UpdateLogRequest]) (*connect_go.Response[runnerv1.UpdateLogResponse], error) { + return connect_go.NewResponse(&runnerv1.UpdateLogResponse{AckIndex: req.Msg.Index + int64(len(req.Msg.Rows))}), nil + }) + client.On("UpdateTask", mock.Anything, mock.Anything).Return(connect_go.NewResponse(&runnerv1.UpdateTaskResponse{}), nil) + + cfg, err := config.LoadDefault("") + require.NoError(t, err) + cfg.Log.Job.Dir = t.TempDir() + + ctx, cancel := context.WithCancel(context.Background()) + t.Cleanup(cancel) + task := &runnerv1.Task{Id: 41, Context: &structpb.Struct{}, Secrets: map[string]string{"TOKEN": "s3cret-value"}} + reporter := NewReporter(ctx, cancel, client, task, cfg) + require.NotNil(t, reporter.jobLog) + reporter.RunDaemon() + reporter.ResetSteps(1) + + fire := func(message string) { + require.NoError(t, reporter.Fire(&log.Entry{ + Message: message, + Level: log.InfoLevel, + Data: log.Fields{"stage": "Main", "stepNumber": 0, "raw_output": true}, + })) + } + fire("the token is s3cret-value") + fire("::add-mask::dyn4mic-value") + fire("and dyn4mic-value too") + fire("::debug::suppressed unless ACTIONS_STEP_DEBUG") + require.NoError(t, reporter.Close("")) + + job := readJobLog(t, reporter.jobLog) + assert.Contains(t, job, "the token is ***") + assert.Contains(t, job, "and *** too") + assert.NotContains(t, job, "s3cret-value") + assert.NotContains(t, job, "dyn4mic-value") + assert.NotContains(t, job, "add-mask", "the row carrying the secret never reaches the log") + assert.NotContains(t, job, "suppressed unless", "the file holds only what was sent") + assert.NotRegexp(t, `(?m)^\S+Z ?$`, job, "the empty row Gitea needs is not job output") + assert.Contains(t, job, "[runner] task 41 finished: failure") +} + +func TestJobLog_MaxSize(t *testing.T) { + joblog := openJobLog(config.LogJob{Dir: t.TempDir(), MaxSize: 200}, 1, testStart) + require.NotNil(t, joblog) + + for range 10 { + joblog.write(testStart, strings.Repeat("x", 40)) + } + joblog.close("task 1 finished: success") + joblog.write(testStart, "after the close") // a container goroutine can outlive the step + + job := readJobLog(t, joblog) + assert.Equal(t, 1, strings.Count(job, "log.job.max_size"), "the cap is reported once") + assert.NotContains(t, job, "after the close") + assert.Contains(t, job, "[runner] task 1 finished: success", "the trailer is written past the cap") +} + +func TestPruneJobLogs(t *testing.T) { + root := t.TempDir() + expired := filepath.Join(root, "20200101-000000-task-1.log") + fresh := filepath.Join(root, testStart.Format(jobLogNameLayout)+"-task-2.log") + unrelated := filepath.Join(root, "20200101-000000-task-3.txt") + for _, name := range []string{expired, fresh, unrelated} { + require.NoError(t, os.WriteFile(name, []byte("log"), 0o600)) + } + + pruneJobLogs(root, 0, testStart) + assert.FileExists(t, expired, "retention 0 keeps every log") + + pruneJobLogs(root, 24*time.Hour, testStart) + assert.NoFileExists(t, expired) + assert.FileExists(t, fresh) + assert.FileExists(t, unrelated) +} diff --git a/internal/pkg/report/reporter.go b/internal/pkg/report/reporter.go index 133b5f07..dd44881e 100644 --- a/internal/pkg/report/reporter.go +++ b/internal/pkg/report/reporter.go @@ -94,6 +94,8 @@ type Reporter struct { debugOutputEnabled bool stopCommandEndToken string + + jobLog *jobLog // this task's rows on the runner's own disk, nil when log.job.dir is unset } // extraMasks are values known before the job starts that are not among its secrets, such as @@ -132,6 +134,7 @@ func NewReporter(ctx context.Context, cancel context.CancelFunc, client client.C reportFailing: map[string]bool{}, daemon: make(chan struct{}), heartbeatStop: make(chan struct{}), + jobLog: openJobLog(cfg.Log.Job, task.Id, time.Now()), } rv.daemonWait = 6 * rv.effectiveCloseTimeout() @@ -164,11 +167,14 @@ func (r *Reporter) Levels() []log.Level { return log.AllLevels } -func appendIfNotNil[T any](s []*T, v *T) []*T { - if v != nil { - return append(s, v) +// appendLogRow buffers a row for the uploader and mirrors it into job.log. A nil row is one +// the command handler dropped, such as ::add-mask::. Caller holds stateMu. +func (r *Reporter) appendLogRow(row *runnerv1.LogRow) { + if row == nil { + return } - return s + r.logRows = append(r.logRows, row) + r.jobLog.write(row.Time.AsTime(), row.Content) } // isJobStepEntry is used to not report composite step results incorrectly as step result @@ -245,7 +251,7 @@ func (r *Reporter) Fire(entry *log.Entry) error { } } if r.shouldAppendLogRow(entry) { - r.logRows = appendIfNotNil(r.logRows, r.parseLogRow(entry)) + r.appendLogRow(r.parseLogRow(entry)) } r.unlockAndNotify(urgentState) return nil @@ -259,7 +265,7 @@ func (r *Reporter) Fire(entry *log.Entry) error { } if step == nil { if r.shouldAppendLogRow(entry) { - r.logRows = appendIfNotNil(r.logRows, r.parseLogRow(entry)) + r.appendLogRow(r.parseLogRow(entry)) } r.unlockAndNotify(false) return nil @@ -285,11 +291,11 @@ func (r *Reporter) Fire(entry *log.Entry) error { step.LogIndex = int64(r.logOffset + len(r.logRows)) } step.LogLength++ - r.logRows = append(r.logRows, row) + r.appendLogRow(row) } } } else if r.shouldAppendLogRow(entry) { - r.logRows = appendIfNotNil(r.logRows, r.parseLogRow(entry)) + r.appendLogRow(r.parseLogRow(entry)) } if v, ok := entry.Data["stepResult"]; ok && isJobStepEntry(entry) { if stepResult, ok := r.parseResult(v); ok { @@ -428,7 +434,7 @@ func (r *Reporter) logf(format string, a ...any) { if !r.duringSteps() { // Masked like any other row: these bypass parseLogRow, but a caller can still // interpolate a secret, such as a configured URL carrying credentials. - r.logRows = append(r.logRows, r.newLogRow(timestamppb.Now(), fmt.Sprintf(format, a...))) + r.appendLogRow(r.newLogRow(timestamppb.Now(), fmt.Sprintf(format, a...))) } } @@ -479,13 +485,13 @@ func (r *Reporter) Close(lastWords string) error { } } r.state.Result = result - r.logRows = append(r.logRows, &runnerv1.LogRow{ + r.appendLogRow(&runnerv1.LogRow{ Time: timestamppb.Now(), Content: lastWords, }) r.state.StoppedAt = timestamppb.Now() } else if lastWords != "" { - r.logRows = append(r.logRows, &runnerv1.LogRow{ + r.appendLogRow(&runnerv1.LogRow{ Time: timestamppb.Now(), Content: lastWords, }) @@ -510,6 +516,7 @@ func (r *Reporter) Close(lastWords string) error { // supported branches, e.g. v1.28+. r.stateMu.Lock() if len(r.logRows) == 0 { + // Not appendLogRow: the sentinel is not job output and has no place in job.log. r.logRows = append(r.logRows, &runnerv1.LogRow{ Time: timestamppb.Now(), Content: "", @@ -519,10 +526,21 @@ func (r *Reporter) Close(lastWords string) error { // Separate budgets so a slow ReportLog can't starve the ReportState that // carries the cancel acknowledgement. - return errors.Join( + err := errors.Join( r.flushFinal(func() error { return r.ReportLog(true) }), r.flushFinal(func() error { return r.ReportState(true) }), ) + + // After the flush so a failed handover is in the file too, under stateMu so a late entry cannot race. + r.stateMu.Lock() + trailer := fmt.Sprintf("task %d finished: %s", r.state.Id, metrics.ResultToStatusLabel(r.state.Result)) + if err != nil { + trailer += fmt.Sprintf(", the final flush to Gitea failed: %v", err) + } + r.jobLog.close(r.mask(trailer)) + r.stateMu.Unlock() + + return err } // flushFinal retries fn on a detached, bounded context so a cancelled r.ctx @@ -851,10 +869,14 @@ func (r *Reporter) parseLogRow(entry *log.Entry) *runnerv1.LogRow { func (r *Reporter) newLogRow(t *timestamppb.Timestamp, content string) *runnerv1.LogRow { return &runnerv1.LogRow{ Time: t, - Content: strings.ToValidUTF8(r.logReplacer.Replace(content), "?"), + Content: r.mask(content), } } +func (r *Reporter) mask(content string) string { + return strings.ToValidUTF8(r.logReplacer.Replace(content), "?") +} + func (r *Reporter) addMask(msg string) { r.oldnew = runner.AppendSecretMasker(r.oldnew, msg) r.logReplacer = strings.NewReplacer(r.oldnew...) diff --git a/internal/pkg/report/reporter_test.go b/internal/pkg/report/reporter_test.go index cec0dd23..0462a4e1 100644 --- a/internal/pkg/report/reporter_test.go +++ b/internal/pkg/report/reporter_test.go @@ -1041,18 +1041,13 @@ func TestReporter_StopHeartbeats(t *testing.T) { "Close() must still send a final UpdateTask after StopHeartbeats") } -func TestAppendIfNotNil(t *testing.T) { - var s []*int - s = appendIfNotNil(s, nil) - assert.Empty(t, s) - - v := 7 - s = appendIfNotNil(s, &v) - require.Len(t, s, 1) - assert.Equal(t, &v, s[0]) - - s = appendIfNotNil(s, nil) - require.Len(t, s, 1) +func TestAppendLogRow(t *testing.T) { + r := &Reporter{} + row := &runnerv1.LogRow{Time: timestamppb.Now(), Content: "hello"} + r.appendLogRow(nil) + r.appendLogRow(row) + r.appendLogRow(nil) + assert.Equal(t, []*runnerv1.LogRow{row}, r.logRows) } func TestReporter_Levels(t *testing.T) {