fix: align runner behaviours (#1338)

Contains a number of small bug fixes where jobs behaved differently from GitHub or failed silently.

1. Hooks fail on a refused `::set-env::` or `::add-path::` and no longer inherit the last step's identity
1. Docker build, exec and wait errors are returned instead of swallowed, token-only registry credentials work, logs of `--tty` services decode
1. Env files split lines like GitHub on each OS, so a carriage return is kept on Linux and CRLF ends a line on Windows, empty heredoc names or delimiters are rejected
1. Post steps run after their pre step even when main was skipped, composites see undeclared inputs, `runs.args` wins without `with.args` being parsed
1. Docker actions skip evaluating defaults of inputs given in `with` and read `entryPoint` and `args` in any case, a lowercase `dockerfile` is found, undeclared inputs get GitHub's warning
1. A user-set `CI` is kept, `GITHUB_REPOSITORY_ID` and the other missing `GITHUB_*` variables are exported
1. `timeout-minutes` can read the step's own `env`, a step-level `ACTIONS_ALLOW_UNSECURE_COMMANDS: false` beats a job-level `true` while the runner's own opt-in still wins, `pwsh` quotes the script path
1. A step `env:` given as one expression such as `${{ fromJSON(matrix.env) }}` is applied, `hashFiles` fails with GitHub's messages on script errors and after 120 seconds, a job image without node still gets an empty hash
1. A step whose command files cannot be reset fails instead of importing stale ones, a timeout between steps fails the job instead of reporting success
1. One named volume can be mounted at several paths, host-mode PTY steps keep their last output when they fail, host scratch directories are removed when job setup fails
1. Cancelling a step right after it starts kills its whole process tree
1. Cache prefix restores pick the newest entry created within the same second, also on S3, cache commits with a wrong size are rejected
1. Artifact chunks are written at their offset, download URLs are escaped, listing a run without artifacts no longer crashes
1. Poll backoff reaches `fetch_interval_max`, proxy passwords are masked in more forms, secrets are also masked in step names and in their quoted form in the runner log, a failed final report is logged
1. On Windows hosts a differently cased unsecure-commands opt-in or proxy variable counts, and an early cancel no longer leaks a job object handle
1. Interactive `register` prompts for a missing token and stops on SIGTERM, `exec --list --detect-event` no longer panics without events, `config set` works on `cache.s3` keys

Reviewed-on: https://gitea.com/gitea/runner/pulls/1338
Reviewed-by: bircni <[email protected]>
Co-authored-by: silverwind <[email protected]>

internal/pkg/report/globalmask.go

@@ -4,6 +4,8 @@
 package report
 
 import (
+	"slices"
+	"strconv"
 	"strings"
 	"sync"
 	"sync/atomic"
@@ -22,7 +24,13 @@ var (
 func registerGlobalMasks(r *Reporter) {
 	globalMu.Lock()
 	defer globalMu.Unlock()
-	globalMasks[r] = r.oldnew
+	masks := slices.Clip(r.oldnew)
+	for i := 0; i < len(r.oldnew); i += 2 { // the console handler Go-quotes values with special characters
+		if quoted := strconv.Quote(r.oldnew[i]); quoted[1:len(quoted)-1] != r.oldnew[i] {
+			masks = append(masks, quoted[1:len(quoted)-1], r.oldnew[i+1])
+		}
+	}
+	globalMasks[r] = masks
 	rebuildGlobalReplacer()
 }
 

internal/pkg/report/globalmask_test.go

@@ -9,6 +9,7 @@ import (
 	"testing"
 
 	"gitea.com/gitea/runner/act/common/logging"
+	"gitea.com/gitea/runner/act/runner"
 
 	"github.com/stretchr/testify/assert"
 )
@@ -61,4 +62,10 @@ func TestGlobalMasks(t *testing.T) {
 	writers.Wait()
 	assert.Contains(t, format("saw runtime-secret"), "runtime-secret")
 	assert.Equal(t, "saw *** ***", third.mask("saw runtime-secret another-secret"))
+
+	secret := "pass\a\v\x1b\u00a0word"
+	register(runner.AppendSecretMasker(nil, secret)...)
+	out.Reset()
+	logging.With("token", secret).Info(secret)
+	assert.Equal(t, "level=info msg=\"***\" token=\"***\"\n", out.String())
 }

internal/pkg/report/reporter.go

@@ -279,6 +279,9 @@ func (r *Reporter) enterReportedStep(step *runnerv1.StepState, timestamp time.Ti
 // cleanup is left running unless closing, as it still logs after the job result. Caller holds stateMu.
 func (r *Reporter) finishReportedSteps(jobResult runnerv1.Result, timestamp time.Time, closing bool) {
 	for _, v := range r.state.ReportedSteps {
+		if closing && v.StartedAt != nil && v.StoppedAt == nil {
+			v.StoppedAt = timestamppb.New(timestamp)
+		}
 		if v.Result != runnerv1.Result_RESULT_UNSPECIFIED || !closing && v.StartedAt != nil && v.Stage == runnerv1.StepStage_STEP_STAGE_CLEANUP {
 			continue
 		}
@@ -716,6 +719,7 @@ func (r *Reporter) Close(lastWords string) error {
 	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)
+		err = errors.New(r.mask(err.Error())) // the caller logs it after this task's masks leave the global masker
 	}
 	r.jobLog.close(r.mask(trailer))
 	r.stateMu.Unlock()

internal/pkg/report/reporter_test.go

@@ -1197,6 +1197,18 @@ func TestReporter_ReportedSteps(t *testing.T) {
 		assert.Equal(t, []runnerv1.Result{failure, skipped, success}, []runnerv1.Result{got[0].result, got[1].result, got[2].result})
 	})
 
+	t.Run("cleanup failure gets a stop timestamp", func(t *testing.T) {
+		reporter, _ := newReporter(t, newTestSteps(1))
+		send(t, reporter, logging.LevelError, "##[error]job completed hook failed", map[string]any{"stage": runner.StageComplete})
+		send(t, reporter, logging.LevelInfo, "Job failed", map[string]any{"stage": runner.StageComplete, "jobResult": model.StepStatusFailure})
+		require.NoError(t, reporter.Close(""))
+
+		step := reporter.state.ReportedSteps[len(reporter.state.ReportedSteps)-1]
+		assert.Equal(t, failure, step.Result)
+		require.NotNil(t, step.StartedAt)
+		assert.NotNil(t, step.StoppedAt)
+	})
+
 	t.Run("step not reached in a succeeding job", func(t *testing.T) {
 		reporter, _ := newReporter(t, newTestSteps(1))
 		send(t, reporter, logging.LevelInfo, "Job succeeded", map[string]any{"stage": runner.StageComplete, "jobResult": model.StepStatusSuccess})