act_runner/act/runner/logger_test.go

// Copyright 2026 The Gitea Authors. All rights reserved.
// SPDX-License-Identifier: MIT

package runner

import (
	"bytes"
	"encoding/base64"
	"encoding/json"
	"errors"
	"io"
	"net/url"
	"strings"
	"testing"

	"gitea.com/gitea/runner/act/common"
	"gitea.com/gitea/runner/act/common/logging"
	"gitea.com/gitea/runner/act/common/logging/logtest"

	"github.com/stretchr/testify/assert"
	"github.com/stretchr/testify/require"
)

func TestValueMasker(t *testing.T) {
	table := []struct {
		name       string
		lines      string
		secrets    map[string]string
		masks      []string
		disallowed []string
	}{
		{
			name:  "Multiline Private Key",
			lines: "cat << EOF > private.key\nPRIVATE_KEY_BEGIN\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\nPRIVATE_KEY_END\nEOF",
			secrets: map[string]string{
				"PRIVATE_KEY": "PRIVATE_KEY_BEGIN\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\nPRIVATE_KEY_END",
			},
			disallowed: []string{"KEY", "dsdfseffefsefes", "PRIVATE_KEY_END"},
		},
		{
			name:       "Multiline Private Key in masks",
			lines:      "cat << EOF > private.key\nPRIVATE_KEY_BEGIN\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\nPRIVATE_KEY_END\nEOF",
			masks:      []string{"PRIVATE_KEY_BEGIN\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\ndsdfseffefsefes\nPRIVATE_KEY_END"},
			disallowed: []string{"KEY", "dsdfseffefsefes", "PRIVATE_KEY_END"},
		},
		{
			name:       "Secret containing a percent sign",
			lines:      "##[error]login failed for pass%25word",
			secrets:    map[string]string{"TOKEN": "pass%word"},
			disallowed: []string{"pass%25word"},
		},
	}
	for _, entry := range table {
		t.Run(entry.name, func(t *testing.T) {
			ctx := WithMasks(t.Context(), &entry.masks)
			masker := valueMasker(false, AppendSecretMaskers(nil, entry.secrets))
			for line := range strings.SplitSeq(entry.lines, "\n") {
				lentry := masker(ctx, logging.Record{Message: line})
				for _, line := range entry.disallowed {
					assert.NotContains(t, lentry.Message, line)
				}
			}
		})
	}
}

// A secret that reaches the log through an encoding — a base64 payload, a JSON body, a
// URL — must be masked as well: masking only the verbatim value leaks it.
func TestValueMaskerEncodedSecrets(t *testing.T) {
	for _, tc := range []struct {
		name, secret string
		encoded      []string
	}{
		{"common encodings", `p@ss w"rd/1`, []string{
			`p@ss w"rd/1`, base64.StdEncoding.EncodeToString([]byte(`p@ss w"rd/1`)),
			jsonStringEscape(`p@ss w"rd/1`), url.PathEscape(`p@ss w"rd/1`),
		}},
		{"XML expression and quotes", `"a'b&c<d>"`, []string{
			`&quot;a&apos;b&amp;c&lt;d&gt;&quot;`, `"a''b&c<d>"`, `a'b&c<d>`,
		}},
		{"URI spaces", "a b", []string{"a%20b", "a+b"}},
	} {
		t.Run(tc.name, func(t *testing.T) {
			masker := valueMasker(false, AppendSecretMaskers(nil, map[string]string{"TOKEN": tc.secret}))
			entry := masker(t.Context(), logging.Record{Message: strings.Join(tc.encoded, " ")})

			assert.Contains(t, entry.Message, "***")
			for _, disallowed := range tc.encoded {
				assert.NotContains(t, entry.Message, disallowed)
			}
		})
	}
}

// A secret containing " together with <, > or & serializes to JSON differently depending
// on the runtime: act's own toJSON (and Go) HTML-escape <>&, while a JavaScript
// (JSON.stringify) or .NET action leaves them literal. The secret must be masked in either
// form, so a JS-serialized JSON body does not leak it.
func TestValueMaskerJSONEscapesBothWays(t *testing.T) {
	secret := `a"<b>&c`
	masker := valueMasker(false, AppendSecretMaskers(nil, map[string]string{"TOKEN": secret}))

	for _, tc := range []struct {
		name string
		form string
	}{
		{"html escaped (act toJSON / Go)", jsonStringEscape(secret)},
		{"literal (JS JSON.stringify / .NET)", jsonStringEscapeNoHTML(secret)},
	} {
		t.Run(tc.name, func(t *testing.T) {
			entry := masker(t.Context(), logging.Record{Message: `{"t":"` + tc.form + `"}`})

			assert.Contains(t, entry.Message, "***")
			assert.NotContains(t, entry.Message, tc.form)
		})
	}
}

// With debug logging on, the job logger writes to stdout, which no reporter masks, so it has
// to hide the values that are not job secrets too.
func TestValueMaskerHidesExtraMasks(t *testing.T) {
	masker := valueMasker(false, (&Config{ExtraMasks: []string{"pr0xypw"}}).maskers())

	entry := masker(t.Context(), logging.Record{Message: "proxy is http://user:pr0xypw@proxy:3128"})

	assert.Equal(t, "proxy is http://user:***@proxy:3128", entry.Message)
}

// ::add-mask:: values go through the same masker, so they get the same treatment.
func TestValueMaskerEncodedMasks(t *testing.T) {
	masks := []string{"s3cr3t value", "first\rsecond", " s3cr3t "}
	masker := valueMasker(false, AppendSecretMaskers(nil, nil))

	for _, tc := range []struct {
		line, want string
	}{
		{"encoded: " + base64.StdEncoding.EncodeToString([]byte("s3cr3t value")), "encoded: ***"},
		{"first and second", "*** and ***"},
		{"encoded: " + base64.StdEncoding.EncodeToString([]byte(" s3cr3t ")), "encoded: ***"},
		{"encoded: " + base64.StdEncoding.EncodeToString([]byte("s3cr3t")), "encoded: ***"},
		{"encoded: " + base64.StdEncoding.EncodeToString([]byte("first")), "encoded: ***"},
	} {
		entry := masker(WithMasks(t.Context(), &masks), logging.Record{Message: tc.line})
		assert.Equal(t, tc.want, entry.Message, tc.line)
	}
}

// A token in a Basic auth header is base64'd together with the user name, so the token's
// own base64 only appears when the prefix length is a multiple of three. The other two
// alignments must be masked as well, or `Authorization: Basic base64("user:token")` leaks
// the token to anyone who can decode the log.
func TestValueMaskerBase64Alignments(t *testing.T) {
	secret := "s3cr3t"
	masker := valueMasker(false, AppendSecretMaskers(nil, map[string]string{"TOKEN": secret}))

	// One prefix per alignment: len%3 of 0, 1 and 2.
	for _, prefix := range []string{"x-access-token:", "user:", "ab:"} {
		t.Run(prefix, func(t *testing.T) {
			encoded := base64.StdEncoding.EncodeToString([]byte(prefix + secret))
			entry := masker(t.Context(), logging.Record{Message: "Authorization: Basic " + encoded})

			assert.Contains(t, entry.Message, "***")
			assert.NotEqual(t, "Authorization: Basic "+encoded, entry.Message)
			decodable := strings.TrimPrefix(entry.Message, "Authorization: Basic ")
			decoded, err := base64.StdEncoding.DecodeString(decodable)
			if err == nil {
				assert.NotContains(t, string(decoded), secret)
			}
		})
	}
}

// The masker caches its replacer, so it has to notice both a mask appended to the same
// slice and a composite action logging with a slice of its own.
func TestValueMaskerCachedReplacerSeesNewMasks(t *testing.T) {
	masker := valueMasker(false, AppendSecretMaskers(nil, map[string]string{"TOKEN": "secret-token"}))
	mask := func(masks *[]string, message string) string {
		return masker(WithMasks(t.Context(), masks), logging.Record{Message: message}).Message
	}

	job := []string{"first mask"}
	assert.Equal(t, "a *** and ***", mask(&job, "a first mask and secret-token"))

	// ::add-mask:: appends to the same slice
	job = append(job, "second mask")
	assert.Equal(t, "*** and ***", mask(&job, "first mask and second mask"))

	// a composite action brings its own slice
	composite := []string{"composite mask"}
	assert.Equal(t, "*** but first mask", mask(&composite, "composite mask but first mask"))

	// and the job's masks still apply once it is back
	assert.Equal(t, "*** and *** but composite mask", mask(&job, "first mask and second mask but composite mask"))
}

func TestAppendSecretMaskerSkipsUselessEncodings(t *testing.T) {
	// A token with no character an escape would touch only gains its base64 forms:
	// JSON, query and path escaping all leave it unchanged.
	pairs := AppendSecretMasker(nil, "plaintoken")
	assert.Equal(t, []string{
		"plaintoken", "***", "cGxhaW50b2tlbg==", "***", "bGFpbnRva2Vu", "***", "YWludG9rZW4=", "***",
		"aW50b2tl", "***", "YWludG9r", "***", "bGFpbnRv", "***",
	}, pairs)

	// Too short to mask.
	assert.Empty(t, AppendSecretMasker(nil, "x"))
	assert.Empty(t, AppendSecretMasker(nil, " \t"))
	assert.NotContains(t, AppendSecretMasker(nil, `"123456"`), "123456")
}

func TestJobLogFormatterDecodesCommandData(t *testing.T) {
	format := func(message string) string {
		line, err := textFormatter{w: io.Discard}.format(logging.Record{Message: message, Attrs: []logging.Attr{{Key: rawOutputField, Value: true}}})
		require.NoError(t, err)
		return string(line)
	}

	assert.Contains(t, format("##[error]deploy 50%25 traffic"), "##[error]deploy 50% traffic")
	// a plain line is not command data and keeps its literal escapes
	assert.Contains(t, format("progress 50%25 done"), "progress 50%25 done")
}

type factoryFunc func() logging.Handler

func (f factoryFunc) WithJobLogger() logging.Handler { return f() }

func TestWithJobLoggerFansOutAndMasksOnlyOutput(t *testing.T) {
	output, hook := logtest.NewWithLevel(logging.LevelTrace), logtest.NewWithLevel(logging.LevelTrace)
	ctx := WithJobLoggerFactory(t.Context(), factoryFunc(func() logging.Handler { return output }))
	ctx = common.WithLoggerHandler(ctx, hook)
	level := logging.LevelInfo
	cfg := &Config{Secrets: map[string]string{"TOKEN": "s3cr3t-value"}, JobLoggerLevel: &level}

	ctx = WithJobLogger(ctx, "j1", "build", cfg, &[]string{}, nil)
	ctx = withStepLogger(ctx, 2, "s2", "step two", "Main")
	ctx = WithCompositeStepLogger(ctx, "inner")
	common.Logger(ctx).Infof("token is %s", "s3cr3t-value")
	common.Logger(ctx).Debugf("below the job logger level")

	// the reporter masks for itself, so its record keeps the original
	require.Len(t, hook.AllRecords(), 1)
	assert.Equal(t, "token is s3cr3t-value", hook.LastRecord().Message)
	require.Len(t, output.AllRecords(), 1)
	assert.Equal(t, "token is ***", output.LastRecord().Message)

	for _, want := range []struct {
		key string
		val any
	}{{"job", "build"}, {"jobID", "j1"}, {"stepNumber", 2}, {"stage", "Main"}, {"stepID", []string{"s2", "inner"}}} {
		got, ok := hook.LastRecord().Attr(want.key)
		assert.True(t, ok, want.key)
		assert.Equal(t, want.val, got, want.key)
	}
}

func TestJobLogJSONHandler(t *testing.T) {
	buf := &bytes.Buffer{}
	rc := &RunContext{Config: &Config{Secrets: map[string]string{"TOKEN": "s3cr3t-value"}}}
	ctx := WithJobLoggerFactory(t.Context(), factoryFunc(func() logging.Handler { return newJobLogJSONHandler(buf) }))
	ctx = WithJobLogger(ctx, "j1", "build", rc.Config, &rc.Masks, nil)
	logger := common.Logger(withStepLogger(ctx, 1, "s1", "deploy s3cr3t-value", StageMain)).
		With("msg", "clash").WithError(errors.New("boom"))
	logger.Warnf("careful %d", 1)

	var got map[string]any
	require.NoError(t, json.Unmarshal(buf.Bytes(), &got))
	assert.Equal(t, "careful 1", got["msg"])
	assert.Equal(t, "warning", got["level"])
	assert.Equal(t, "build", got["job"])
	assert.Equal(t, "deploy ***", got["step"])
	assert.Equal(t, "boom", got["error"])
	assert.Equal(t, "clash", got["fields.msg"])
	assert.NotEmpty(t, got["time"])

	rc.AddMask(ctx, "runtime-value")
	buf.Reset()
	common.Logger(withStepLogger(ctx, 2, "s2", "deploy s3cr3t-value runtime-value", StageMain)).Info("done")

	require.NoError(t, json.Unmarshal(buf.Bytes(), &got))
	assert.Equal(t, "deploy *** ***", got["step"])
}