test(executor): commands, matchers, masks, annotations, state and timeouts in node, docker and composite steps
- commit
- 3ee1c676aeab1d79f13c2db01352cd193a41cb5a
- author
- brice · · 2026-10-14 03:27 UTC
- parent
- d930202
- signature
- GPG Verified
CD88F9E564E0102646FB6077A1A07C7C7C3E349D· arch-gpg Verified for the committer email
1 file · +298 -0
A internal/executor/actions_results_test.go +298 -0
| @@ -0,0 +1,298 @@ | |||
| 1 | + | // SPDX-License-Identifier: MIT | |
| 2 | + | ||
| 3 | + | package executor | |
| 4 | + | ||
| 5 | + | import ( | |
| 6 | + | "encoding/base64" | |
| 7 | + | "fmt" | |
| 8 | + | "strings" | |
| 9 | + | "testing" | |
| 10 | + | "time" | |
| 11 | + | ) | |
| 12 | + | ||
| 13 | + | // actionResults runs a workflow of actions with a recorder that keeps the | |
| 14 | + | // results of the steps (annotations, summaries, outcomes). | |
| 15 | + | func actionResults(t *testing.T, tree files, yaml string, tweak func(*Config)) (*resultRecorder, Result) { | |
| 16 | + | t.Helper() | |
| 17 | + | needTools(t, "bash") | |
| 18 | + | rr := newResultRecorder() | |
| 19 | + | _, res := runLocal(t, wfHead+" steps:\n"+yaml, "j", func(c *Config) { | |
| 20 | + | writeFiles(t, c.Layout.Workspace, tree) | |
| 21 | + | c.Actions.ExternalsDir = fakeNode(t) | |
| 22 | + | c.Reporter = rr | |
| 23 | + | c.SendAnnotations, c.SendSummaries = true, true | |
| 24 | + | if tweak != nil { | |
| 25 | + | tweak(c) | |
| 26 | + | } | |
| 27 | + | }) | |
| 28 | + | return rr, res | |
| 29 | + | } | |
| 30 | + | ||
| 31 | + | func countLevel(as []Annotation, l AnnotationLevel) int { | |
| 32 | + | n := 0 | |
| 33 | + | for _, a := range as { | |
| 34 | + | if a.Level == l { | |
| 35 | + | n++ | |
| 36 | + | } | |
| 37 | + | } | |
| 38 | + | return n | |
| 39 | + | } | |
| 40 | + | ||
| 41 | + | // Commands from a node action: annotations, masks, a problem matcher, the step | |
| 42 | + | // summary and the saved state work as in a run step. | |
| 43 | + | func TestNodeActionCommands(t *testing.T) { | |
| 44 | + | tree := files{ | |
| 45 | + | "n/action.yml": "name: n\nruns:\n using: node20\n main: main.sh\n", | |
| 46 | + | "n/main.sh": `echo "::error title=T,file=a.txt,line=3::broken" | |
| 47 | + | echo "::add-mask::hunter2" | |
| 48 | + | echo "the password is hunter2" | |
| 49 | + | echo "::warning::careful" | |
| 50 | + | echo "# Summary hunter2" >> "$GITHUB_STEP_SUMMARY" | |
| 51 | + | echo '{"problemMatcher":[{"owner":"m","pattern":[{"regexp":"^bad: (.+)$","message":1}]}]}' > "$RUNNER_TEMP/m.json" | |
| 52 | + | echo "::add-matcher::$RUNNER_TEMP/m.json" | |
| 53 | + | echo "bad: from the matcher" | |
| 54 | + | `, | |
| 55 | + | } | |
| 56 | + | rr, res := actionResults(t, tree, " - uses: ./n\n", nil) | |
| 57 | + | if res.Conclusion != ConclusionSuccess { | |
| 58 | + | t.Fatalf("%+v\n%s", res, logOf(rr.steps[1])) | |
| 59 | + | } | |
| 60 | + | log := logOf(rr.step(t, "Run ./n")) | |
| 61 | + | if strings.Contains(log, "hunter2") || !strings.Contains(log, "the password is ***") { | |
| 62 | + | t.Errorf("add-mask:\n%s", log) | |
| 63 | + | } | |
| 64 | + | as := rr.results[2].Annotations | |
| 65 | + | if len(as) != 3 || as[0].Level != LevelFailure || as[0].Title != "T" || as[0].File != "a.txt" || as[0].StartLine != 3 || | |
| 66 | + | as[1].Level != LevelWarning || as[2].Level != LevelFailure || as[2].Message != "from the matcher" { | |
| 67 | + | t.Errorf("annotations %+v", as) | |
| 68 | + | } | |
| 69 | + | if got := rr.results[2].Summary; got != "# Summary ***\n" { | |
| 70 | + | t.Errorf("summary %q", got) | |
| 71 | + | } | |
| 72 | + | // An ::error:: fails the step only through its exit code, not by itself, but | |
| 73 | + | // the command result merges: the step succeeds here, as the script exited 0. | |
| 74 | + | if rr.step(t, "Run ./n").Conclusion != ConclusionSuccess { | |
| 75 | + | t.Errorf("conclusion %s", rr.step(t, "Run ./n").Conclusion) | |
| 76 | + | } | |
| 77 | + | } | |
| 78 | + | ||
| 79 | + | // The state of an action is kept under one key for its pre, main and post stages; | |
| 80 | + | // the first spelling of a name wins and entries come in the order they were saved. | |
| 81 | + | // (The runner never runs pre of a local action, so this one is a repository action.) | |
| 82 | + | func TestActionStateKeepsFirstSpellingAndOrder(t *testing.T) { | |
| 83 | + | forge := newForge(t, map[string][]byte{"/tarball/o/p/v1": tarOf(t, "o-p-x", files{ | |
| 84 | + | "action.yml": "name: p\nruns:\n using: node20\n pre: pre.sh\n main: main.sh\n post: post.sh\n", | |
| 85 | + | "pre.sh": "echo \"Zed=1\" >> \"$GITHUB_STATE\"\necho \"alpha=2\" >> \"$GITHUB_STATE\"\n", | |
| 86 | + | "main.sh": "echo \"ZED=3\" >> \"$GITHUB_STATE\"\necho \"main: $(env | grep '^STATE_' | sort | tr '\\n' ' ')\"\n", | |
| 87 | + | "post.sh": "echo \"post: $(env | grep '^STATE_' | sort | tr '\\n' ' ')\"\n", | |
| 88 | + | })}) | |
| 89 | + | rr, res := actionResults(t, files{}, " - uses: o/p@v1\n", func(c *Config) { c.Actions.Resolver = forge.resolver("") }) | |
| 90 | + | if res.Conclusion != ConclusionSuccess { | |
| 91 | + | t.Fatalf("%+v", res) | |
| 92 | + | } | |
| 93 | + | if got := logOf(rr.step(t, "Run o/p@v1")); !strings.Contains(got, "main: STATE_Zed=1 STATE_alpha=2 ") { | |
| 94 | + | t.Errorf("main:\n%s", got) | |
| 95 | + | } | |
| 96 | + | if got := logOf(rr.step(t, "Post Run o/p@v1")); !strings.Contains(got, "post: STATE_Zed=3 STATE_alpha=2 ") { | |
| 97 | + | t.Errorf("post:\n%s", got) | |
| 98 | + | } | |
| 99 | + | } | |
| 100 | + | ||
| 101 | + | // Two uses of one action have two states, and the ::save-state:: command and the | |
| 102 | + | // file end in the same one. | |
| 103 | + | func TestActionStateIsPerStep(t *testing.T) { | |
| 104 | + | forge := newForge(t, map[string][]byte{"/tarball/o/q/v1": tarOf(t, "o-q-x", files{ | |
| 105 | + | "action.yml": "name: q\ninputs:\n v:\n default: d\nruns:\n using: node20\n main: main.sh\n post: post.sh\n", | |
| 106 | + | "main.sh": "echo \"::save-state name=v::$INPUT_V\"\necho \"f=$INPUT_V\" >> \"$GITHUB_STATE\"\n", | |
| 107 | + | "post.sh": "echo \"post sees v=$STATE_v f=$STATE_f\"\n", | |
| 108 | + | })}) | |
| 109 | + | rr, res := actionResults(t, files{}, " - uses: o/q@v1\n with:\n v: one\n - uses: o/q@v1\n with:\n v: two\n", func(c *Config) { c.Actions.Resolver = forge.resolver("") }) | |
| 110 | + | if res.Conclusion != ConclusionSuccess { | |
| 111 | + | t.Fatalf("%+v", res) | |
| 112 | + | } | |
| 113 | + | var posts []string | |
| 114 | + | for _, s := range rr.steps { | |
| 115 | + | if strings.HasPrefix(s.Name, "Post ") { | |
| 116 | + | posts = append(posts, logOf(s)) | |
| 117 | + | } | |
| 118 | + | } | |
| 119 | + | if len(posts) != 2 || !strings.Contains(posts[0], "post sees v=two f=two") || !strings.Contains(posts[1], "post sees v=one f=one") { | |
| 120 | + | t.Errorf("%q", posts) | |
| 121 | + | } | |
| 122 | + | } | |
| 123 | + | ||
| 124 | + | // ::error:: of a node action and of the inner steps of a composite land on the | |
| 125 | + | // step of the workflow; the limit of 10 per level counts every inner step. | |
| 126 | + | func TestCompositeAnnotationsAreCountedOnTheOuterStep(t *testing.T) { | |
| 127 | + | inner := func(n int, level string) string { | |
| 128 | + | return " run: |\n for i in $(seq 1 " + fmt.Sprint(n) + "); do echo \"::" + level + "::" + level + " $i\"; done\n" | |
| 129 | + | } | |
| 130 | + | tree := files{ | |
| 131 | + | "c/action.yml": "name: c\nruns:\n using: composite\n steps:\n - shell: bash\n" + inner(8, "error") + | |
| 132 | + | " - shell: bash\n" + inner(8, "error") + " - shell: bash\n" + inner(3, "warning") + " - uses: ./n\n", | |
| 133 | + | "n/action.yml": "name: n\nruns:\n using: node20\n main: main.sh\n", | |
| 134 | + | "n/main.sh": "echo '::notice::from the node action inside'\n", | |
| 135 | + | } | |
| 136 | + | rr, res := actionResults(t, tree, " - uses: ./c\n - run: echo \"::error::the next step\"\n", nil) | |
| 137 | + | if res.Conclusion != ConclusionSuccess { | |
| 138 | + | t.Fatalf("%+v", res) | |
| 139 | + | } | |
| 140 | + | as := rr.results[2].Annotations | |
| 141 | + | if countLevel(as, LevelFailure) != 10 || countLevel(as, LevelWarning) != 3 || countLevel(as, LevelNotice) != 1 { | |
| 142 | + | t.Errorf("failure %d (want 10 of 16), warning %d, notice %d: %+v", countLevel(as, LevelFailure), countLevel(as, LevelWarning), countLevel(as, LevelNotice), as) | |
| 143 | + | } | |
| 144 | + | if as[0].Message != "error 1" { | |
| 145 | + | t.Errorf("the first ones are kept: %+v", as[0]) | |
| 146 | + | } | |
| 147 | + | // Nothing leaks to the step after, and the inner steps have no number of their own. | |
| 148 | + | if got := rr.results[3].Annotations; len(got) != 1 || got[0].Message != "the next step" { | |
| 149 | + | t.Errorf("next step %+v", got) | |
| 150 | + | } | |
| 151 | + | // A local action inside a composite is assumed to have a post step, so the | |
| 152 | + | // composite has one too (ActionManager.cs:643-654): "Post Run ./c" is empty. | |
| 153 | + | if got := strings.Join(rr.names(), "|"); got != "Set up job|Run ./c|Run echo \"::error::the next step\"|Post Run ./c|Complete job" { | |
| 154 | + | t.Errorf("steps %v", rr.names()) | |
| 155 | + | } | |
| 156 | + | } | |
| 157 | + | ||
| 158 | + | // The outer step's own issues come first: a composite whose inner steps have used | |
| 159 | + | // the 10 slots of "failure" cannot push out the error the runner logs for the | |
| 160 | + | // outer step itself... in the runner's order, which is chronological. | |
| 161 | + | func TestCompositeSummaryAndMaskBelongToTheOuterStep(t *testing.T) { | |
| 162 | + | tree := files{"c/action.yml": `name: c | |
| 163 | + | runs: | |
| 164 | + | using: composite | |
| 165 | + | steps: | |
| 166 | + | - shell: bash | |
| 167 | + | run: | | |
| 168 | + | echo "::add-mask::inner-secret" | |
| 169 | + | echo "first" >> "$GITHUB_STEP_SUMMARY" | |
| 170 | + | - shell: bash | |
| 171 | + | run: | | |
| 172 | + | echo "second inner-secret" >> "$GITHUB_STEP_SUMMARY" | |
| 173 | + | echo "visible: inner-secret" | |
| 174 | + | `} | |
| 175 | + | rr, res := actionResults(t, tree, " - uses: ./c\n - run: echo \"after - inner-secret\"\n", nil) | |
| 176 | + | if res.Conclusion != ConclusionSuccess { | |
| 177 | + | t.Fatalf("%+v", res) | |
| 178 | + | } | |
| 179 | + | if got := rr.results[2].Summary; got != "first\nsecond ***\n" { | |
| 180 | + | t.Errorf("summary %q", got) | |
| 181 | + | } | |
| 182 | + | if got := logOf(rr.steps[1]) + logOf(rr.steps[2]); strings.Contains(got, "inner-secret\n") && !strings.Contains(got, "***") || strings.Contains(strings.ReplaceAll(got, "::add-mask::inner-secret", ""), "visible: inner-secret") || strings.Contains(logOf(rr.steps[2]), "after - inner-secret") { | |
| 183 | + | t.Errorf("a mask added by an inner step must hide the value everywhere:\n%s", got) | |
| 184 | + | } | |
| 185 | + | } | |
| 186 | + | ||
| 187 | + | // The archive token, and its Basic form, are masked wherever they appear. | |
| 188 | + | func TestArchiveTokenAndBasicFormAreMasked(t *testing.T) { | |
| 189 | + | const token = "archive-tok-123" | |
| 190 | + | basic := base64.StdEncoding.EncodeToString([]byte("x-access-token:" + token)) | |
| 191 | + | forge := newForge(t, map[string][]byte{"/tarball/o/t/v1": tarOf(t, "o-t-x", files{ | |
| 192 | + | "action.yml": "name: t\nruns:\n using: node20\n main: main.sh\n", | |
| 193 | + | "main.sh": "echo \"token " + token + " basic " + basic + "\"\n"})}) | |
| 194 | + | rr, res := actionResults(t, files{}, " - uses: o/t@v1\n", func(c *Config) { c.Actions.Resolver = forge.resolver(token) }) | |
| 195 | + | if res.Conclusion != ConclusionSuccess { | |
| 196 | + | t.Fatalf("%+v", res) | |
| 197 | + | } | |
| 198 | + | if got := logOf(rr.step(t, "Run o/t@v1")); !strings.Contains(got, "token *** basic ***") { | |
| 199 | + | t.Errorf("%s", got) | |
| 200 | + | } | |
| 201 | + | } | |
| 202 | + | ||
| 203 | + | // timeout-minutes on an action step, on a docker step and on an inner step of a | |
| 204 | + | // composite: the step fails with the runner's message and the job goes on. | |
| 205 | + | func TestActionStepTimeouts(t *testing.T) { | |
| 206 | + | skew := -(60*time.Second - 1500*time.Millisecond) | |
| 207 | + | tree := files{ | |
| 208 | + | "slow/action.yml": "name: slow\nruns:\n using: node20\n main: main.sh\n", | |
| 209 | + | "slow/main.sh": "sleep 30\n", | |
| 210 | + | "c/action.yml": "name: c\nruns:\n using: composite\n steps:\n - name: inner\n shell: bash\n run: sleep 30\n - shell: bash\n if: always()\n run: echo inner-after\n", | |
| 211 | + | } | |
| 212 | + | start := time.Now() | |
| 213 | + | rr, res := actionResults(t, tree, ` - name: node | |
| 214 | + | timeout-minutes: 1 | |
| 215 | + | uses: ./slow | |
| 216 | + | - name: after | |
| 217 | + | if: always() | |
| 218 | + | run: echo after-ran | |
| 219 | + | `, func(c *Config) { c.StepTimeoutSkew = skew }) | |
| 220 | + | if res.Conclusion != ConclusionFailure { | |
| 221 | + | t.Fatalf("%+v", res) | |
| 222 | + | } | |
| 223 | + | if time.Since(start) > 10*time.Second { | |
| 224 | + | t.Errorf("the timeout did not stop the action: %v", time.Since(start)) | |
| 225 | + | } | |
| 226 | + | n := rr.step(t, "node") | |
| 227 | + | if n.Conclusion != ConclusionFailure || !strings.Contains(logOf(n), "##[error]The action 'node' has timed out after 1 minutes.") || strings.Contains(logOf(n), "The operation was canceled.") { | |
| 228 | + | t.Errorf("%s\n%s", n.Conclusion, logOf(n)) | |
| 229 | + | } | |
| 230 | + | if rr.step(t, "after").Conclusion != ConclusionSuccess { | |
| 231 | + | t.Error("the job is not cancelled by a step timeout") | |
| 232 | + | } | |
| 233 | + | // The inner step of a composite action. | |
| 234 | + | start = time.Now() | |
| 235 | + | rr, res = actionResults(t, tree, " - name: comp\n timeout-minutes: 1\n uses: ./c\n", func(c *Config) { c.StepTimeoutSkew = skew }) | |
| 236 | + | if res.Conclusion != ConclusionFailure || time.Since(start) > 10*time.Second { | |
| 237 | + | t.Fatalf("%+v %v", res, time.Since(start)) | |
| 238 | + | } | |
| 239 | + | log := logOf(rr.step(t, "comp")) | |
| 240 | + | // The inner step has what is left of the timeout of the step that uses the | |
| 241 | + | // action and fails with a message that names no step (the runner's composite | |
| 242 | + | // handler). The time is spent after it: the steps that follow are cancelled at | |
| 243 | + | // once, as the runner's are (their token is cancelled when they are created). | |
| 244 | + | if strings.Count(log, "##[error]The action has timed out.") < 1 || strings.Contains(log, "after 0 minutes") || strings.Contains(log, "The operation was canceled.") { | |
| 245 | + | t.Errorf("%s", log) | |
| 246 | + | } | |
| 247 | + | } | |
| 248 | + | ||
| 249 | + | // A docker action's output goes through the same commands: annotations, masks, | |
| 250 | + | // matchers. | |
| 251 | + | func TestDockerActionCommands(t *testing.T) { | |
| 252 | + | dir := t.TempDir() | |
| 253 | + | script := `#!/bin/sh | |
| 254 | + | case "$1" in | |
| 255 | + | run) | |
| 256 | + | echo "::add-mask::dkr-secret" | |
| 257 | + | echo "value dkr-secret" | |
| 258 | + | echo "::error file=x.go,line=2::from docker" | |
| 259 | + | echo "::group::g" | |
| 260 | + | echo "::endgroup::" | |
| 261 | + | ;; | |
| 262 | + | esac | |
| 263 | + | exit 0 | |
| 264 | + | ` | |
| 265 | + | writeFiles(t, dir, files{"docker": script}) | |
| 266 | + | rr, res := actionResults(t, files{}, " - uses: docker://alpine:3\n", func(c *Config) { c.Actions.DockerPath = dir + "/docker" }) | |
| 267 | + | if res.Conclusion != ConclusionSuccess { | |
| 268 | + | t.Fatalf("%+v", res) | |
| 269 | + | } | |
| 270 | + | log := logOf(rr.step(t, "Run alpine:3")) | |
| 271 | + | if strings.Contains(log, "value dkr-secret") || !strings.Contains(log, "value ***") { | |
| 272 | + | t.Errorf("%s", log) | |
| 273 | + | } | |
| 274 | + | if as := rr.results[3].Annotations; len(as) != 1 || as[0].Message != "from docker" || as[0].File != "x.go" || as[0].StartLine != 2 { | |
| 275 | + | t.Errorf("annotations %+v", rr.results) | |
| 276 | + | } | |
| 277 | + | } | |
| 278 | + | ||
| 279 | + | // The outcome of an action step, before continue-on-error, reaches the reporter. | |
| 280 | + | func TestActionOutcomeIsReported(t *testing.T) { | |
| 281 | + | tree := files{"f/action.yml": "name: f\nruns:\n using: node20\n main: main.sh\n", "f/main.sh": "exit 1\n"} | |
| 282 | + | rr, res := actionResults(t, tree, " - uses: ./f\n continue-on-error: true\n", nil) | |
| 283 | + | if res.Conclusion != ConclusionSuccess { | |
| 284 | + | t.Fatalf("%+v", res) | |
| 285 | + | } | |
| 286 | + | if got := rr.results[2].Outcome; got != ConclusionFailure { | |
| 287 | + | t.Errorf("outcome %q, want failure", got) | |
| 288 | + | } | |
| 289 | + | if rr.step(t, "Run ./f").Conclusion != ConclusionSuccess { | |
| 290 | + | t.Error("continue-on-error") | |
| 291 | + | } | |
| 292 | + | // A failing action says why in an annotation too: the exit code is an error of | |
| 293 | + | // the runner, which GitHub reports as an annotation for run steps; node | |
| 294 | + | // actions only mark the step failed. | |
| 295 | + | if as := rr.results[2].Annotations; len(as) != 0 { | |
| 296 | + | t.Errorf("annotations %+v", as) | |
| 297 | + | } | |
| 298 | + | } | |
| @@ -0,0 +1,298 @@ | |||||
| 1 | + | // SPDX-License-Identifier: MIT | |||
| 2 | + | ||||
| 3 | + | package executor | |||
| 4 | + | ||||
| 5 | + | import ( | |||
| 6 | + | "encoding/base64" | |||
| 7 | + | "fmt" | |||
| 8 | + | "strings" | |||
| 9 | + | "testing" | |||
| 10 | + | "time" | |||
| 11 | + | ) | |||
| 12 | + | ||||
| 13 | + | // actionResults runs a workflow of actions with a recorder that keeps the | |||
| 14 | + | // results of the steps (annotations, summaries, outcomes). | |||
| 15 | + | func actionResults(t *testing.T, tree files, yaml string, tweak func(*Config)) (*resultRecorder, Result) { | |||
| 16 | + | t.Helper() | |||
| 17 | + | needTools(t, "bash") | |||
| 18 | + | rr := newResultRecorder() | |||
| 19 | + | _, res := runLocal(t, wfHead+" steps:\n"+yaml, "j", func(c *Config) { | |||
| 20 | + | writeFiles(t, c.Layout.Workspace, tree) | |||
| 21 | + | c.Actions.ExternalsDir = fakeNode(t) | |||
| 22 | + | c.Reporter = rr | |||
| 23 | + | c.SendAnnotations, c.SendSummaries = true, true | |||
| 24 | + | if tweak != nil { | |||
| 25 | + | tweak(c) | |||
| 26 | + | } | |||
| 27 | + | }) | |||
| 28 | + | return rr, res | |||
| 29 | + | } | |||
| 30 | + | ||||
| 31 | + | func countLevel(as []Annotation, l AnnotationLevel) int { | |||
| 32 | + | n := 0 | |||
| 33 | + | for _, a := range as { | |||
| 34 | + | if a.Level == l { | |||
| 35 | + | n++ | |||
| 36 | + | } | |||
| 37 | + | } | |||
| 38 | + | return n | |||
| 39 | + | } | |||
| 40 | + | ||||
| 41 | + | // Commands from a node action: annotations, masks, a problem matcher, the step | |||
| 42 | + | // summary and the saved state work as in a run step. | |||
| 43 | + | func TestNodeActionCommands(t *testing.T) { | |||
| 44 | + | tree := files{ | |||
| 45 | + | "n/action.yml": "name: n\nruns:\n using: node20\n main: main.sh\n", | |||
| 46 | + | "n/main.sh": `echo "::error title=T,file=a.txt,line=3::broken" | |||
| 47 | + | echo "::add-mask::hunter2" | |||
| 48 | + | echo "the password is hunter2" | |||
| 49 | + | echo "::warning::careful" | |||
| 50 | + | echo "# Summary hunter2" >> "$GITHUB_STEP_SUMMARY" | |||
| 51 | + | echo '{"problemMatcher":[{"owner":"m","pattern":[{"regexp":"^bad: (.+)$","message":1}]}]}' > "$RUNNER_TEMP/m.json" | |||
| 52 | + | echo "::add-matcher::$RUNNER_TEMP/m.json" | |||
| 53 | + | echo "bad: from the matcher" | |||
| 54 | + | `, | |||
| 55 | + | } | |||
| 56 | + | rr, res := actionResults(t, tree, " - uses: ./n\n", nil) | |||
| 57 | + | if res.Conclusion != ConclusionSuccess { | |||
| 58 | + | t.Fatalf("%+v\n%s", res, logOf(rr.steps[1])) | |||
| 59 | + | } | |||
| 60 | + | log := logOf(rr.step(t, "Run ./n")) | |||
| 61 | + | if strings.Contains(log, "hunter2") || !strings.Contains(log, "the password is ***") { | |||
| 62 | + | t.Errorf("add-mask:\n%s", log) | |||
| 63 | + | } | |||
| 64 | + | as := rr.results[2].Annotations | |||
| 65 | + | if len(as) != 3 || as[0].Level != LevelFailure || as[0].Title != "T" || as[0].File != "a.txt" || as[0].StartLine != 3 || | |||
| 66 | + | as[1].Level != LevelWarning || as[2].Level != LevelFailure || as[2].Message != "from the matcher" { | |||
| 67 | + | t.Errorf("annotations %+v", as) | |||
| 68 | + | } | |||
| 69 | + | if got := rr.results[2].Summary; got != "# Summary ***\n" { | |||
| 70 | + | t.Errorf("summary %q", got) | |||
| 71 | + | } | |||
| 72 | + | // An ::error:: fails the step only through its exit code, not by itself, but | |||
| 73 | + | // the command result merges: the step succeeds here, as the script exited 0. | |||
| 74 | + | if rr.step(t, "Run ./n").Conclusion != ConclusionSuccess { | |||
| 75 | + | t.Errorf("conclusion %s", rr.step(t, "Run ./n").Conclusion) | |||
| 76 | + | } | |||
| 77 | + | } | |||
| 78 | + | ||||
| 79 | + | // The state of an action is kept under one key for its pre, main and post stages; | |||
| 80 | + | // the first spelling of a name wins and entries come in the order they were saved. | |||
| 81 | + | // (The runner never runs pre of a local action, so this one is a repository action.) | |||
| 82 | + | func TestActionStateKeepsFirstSpellingAndOrder(t *testing.T) { | |||
| 83 | + | forge := newForge(t, map[string][]byte{"/tarball/o/p/v1": tarOf(t, "o-p-x", files{ | |||
| 84 | + | "action.yml": "name: p\nruns:\n using: node20\n pre: pre.sh\n main: main.sh\n post: post.sh\n", | |||
| 85 | + | "pre.sh": "echo \"Zed=1\" >> \"$GITHUB_STATE\"\necho \"alpha=2\" >> \"$GITHUB_STATE\"\n", | |||
| 86 | + | "main.sh": "echo \"ZED=3\" >> \"$GITHUB_STATE\"\necho \"main: $(env | grep '^STATE_' | sort | tr '\\n' ' ')\"\n", | |||
| 87 | + | "post.sh": "echo \"post: $(env | grep '^STATE_' | sort | tr '\\n' ' ')\"\n", | |||
| 88 | + | })}) | |||
| 89 | + | rr, res := actionResults(t, files{}, " - uses: o/p@v1\n", func(c *Config) { c.Actions.Resolver = forge.resolver("") }) | |||
| 90 | + | if res.Conclusion != ConclusionSuccess { | |||
| 91 | + | t.Fatalf("%+v", res) | |||
| 92 | + | } | |||
| 93 | + | if got := logOf(rr.step(t, "Run o/p@v1")); !strings.Contains(got, "main: STATE_Zed=1 STATE_alpha=2 ") { | |||
| 94 | + | t.Errorf("main:\n%s", got) | |||
| 95 | + | } | |||
| 96 | + | if got := logOf(rr.step(t, "Post Run o/p@v1")); !strings.Contains(got, "post: STATE_Zed=3 STATE_alpha=2 ") { | |||
| 97 | + | t.Errorf("post:\n%s", got) | |||
| 98 | + | } | |||
| 99 | + | } | |||
| 100 | + | ||||
| 101 | + | // Two uses of one action have two states, and the ::save-state:: command and the | |||
| 102 | + | // file end in the same one. | |||
| 103 | + | func TestActionStateIsPerStep(t *testing.T) { | |||
| 104 | + | forge := newForge(t, map[string][]byte{"/tarball/o/q/v1": tarOf(t, "o-q-x", files{ | |||
| 105 | + | "action.yml": "name: q\ninputs:\n v:\n default: d\nruns:\n using: node20\n main: main.sh\n post: post.sh\n", | |||
| 106 | + | "main.sh": "echo \"::save-state name=v::$INPUT_V\"\necho \"f=$INPUT_V\" >> \"$GITHUB_STATE\"\n", | |||
| 107 | + | "post.sh": "echo \"post sees v=$STATE_v f=$STATE_f\"\n", | |||
| 108 | + | })}) | |||
| 109 | + | rr, res := actionResults(t, files{}, " - uses: o/q@v1\n with:\n v: one\n - uses: o/q@v1\n with:\n v: two\n", func(c *Config) { c.Actions.Resolver = forge.resolver("") }) | |||
| 110 | + | if res.Conclusion != ConclusionSuccess { | |||
| 111 | + | t.Fatalf("%+v", res) | |||
| 112 | + | } | |||
| 113 | + | var posts []string | |||
| 114 | + | for _, s := range rr.steps { | |||
| 115 | + | if strings.HasPrefix(s.Name, "Post ") { | |||
| 116 | + | posts = append(posts, logOf(s)) | |||
| 117 | + | } | |||
| 118 | + | } | |||
| 119 | + | if len(posts) != 2 || !strings.Contains(posts[0], "post sees v=two f=two") || !strings.Contains(posts[1], "post sees v=one f=one") { | |||
| 120 | + | t.Errorf("%q", posts) | |||
| 121 | + | } | |||
| 122 | + | } | |||
| 123 | + | ||||
| 124 | + | // ::error:: of a node action and of the inner steps of a composite land on the | |||
| 125 | + | // step of the workflow; the limit of 10 per level counts every inner step. | |||
| 126 | + | func TestCompositeAnnotationsAreCountedOnTheOuterStep(t *testing.T) { | |||
| 127 | + | inner := func(n int, level string) string { | |||
| 128 | + | return " run: |\n for i in $(seq 1 " + fmt.Sprint(n) + "); do echo \"::" + level + "::" + level + " $i\"; done\n" | |||
| 129 | + | } | |||
| 130 | + | tree := files{ | |||
| 131 | + | "c/action.yml": "name: c\nruns:\n using: composite\n steps:\n - shell: bash\n" + inner(8, "error") + | |||
| 132 | + | " - shell: bash\n" + inner(8, "error") + " - shell: bash\n" + inner(3, "warning") + " - uses: ./n\n", | |||
| 133 | + | "n/action.yml": "name: n\nruns:\n using: node20\n main: main.sh\n", | |||
| 134 | + | "n/main.sh": "echo '::notice::from the node action inside'\n", | |||
| 135 | + | } | |||
| 136 | + | rr, res := actionResults(t, tree, " - uses: ./c\n - run: echo \"::error::the next step\"\n", nil) | |||
| 137 | + | if res.Conclusion != ConclusionSuccess { | |||
| 138 | + | t.Fatalf("%+v", res) | |||
| 139 | + | } | |||
| 140 | + | as := rr.results[2].Annotations | |||
| 141 | + | if countLevel(as, LevelFailure) != 10 || countLevel(as, LevelWarning) != 3 || countLevel(as, LevelNotice) != 1 { | |||
| 142 | + | t.Errorf("failure %d (want 10 of 16), warning %d, notice %d: %+v", countLevel(as, LevelFailure), countLevel(as, LevelWarning), countLevel(as, LevelNotice), as) | |||
| 143 | + | } | |||
| 144 | + | if as[0].Message != "error 1" { | |||
| 145 | + | t.Errorf("the first ones are kept: %+v", as[0]) | |||
| 146 | + | } | |||
| 147 | + | // Nothing leaks to the step after, and the inner steps have no number of their own. | |||
| 148 | + | if got := rr.results[3].Annotations; len(got) != 1 || got[0].Message != "the next step" { | |||
| 149 | + | t.Errorf("next step %+v", got) | |||
| 150 | + | } | |||
| 151 | + | // A local action inside a composite is assumed to have a post step, so the | |||
| 152 | + | // composite has one too (ActionManager.cs:643-654): "Post Run ./c" is empty. | |||
| 153 | + | if got := strings.Join(rr.names(), "|"); got != "Set up job|Run ./c|Run echo \"::error::the next step\"|Post Run ./c|Complete job" { | |||
| 154 | + | t.Errorf("steps %v", rr.names()) | |||
| 155 | + | } | |||
| 156 | + | } | |||
| 157 | + | ||||
| 158 | + | // The outer step's own issues come first: a composite whose inner steps have used | |||
| 159 | + | // the 10 slots of "failure" cannot push out the error the runner logs for the | |||
| 160 | + | // outer step itself... in the runner's order, which is chronological. | |||
| 161 | + | func TestCompositeSummaryAndMaskBelongToTheOuterStep(t *testing.T) { | |||
| 162 | + | tree := files{"c/action.yml": `name: c | |||
| 163 | + | runs: | |||
| 164 | + | using: composite | |||
| 165 | + | steps: | |||
| 166 | + | - shell: bash | |||
| 167 | + | run: | | |||
| 168 | + | echo "::add-mask::inner-secret" | |||
| 169 | + | echo "first" >> "$GITHUB_STEP_SUMMARY" | |||
| 170 | + | - shell: bash | |||
| 171 | + | run: | | |||
| 172 | + | echo "second inner-secret" >> "$GITHUB_STEP_SUMMARY" | |||
| 173 | + | echo "visible: inner-secret" | |||
| 174 | + | `} | |||
| 175 | + | rr, res := actionResults(t, tree, " - uses: ./c\n - run: echo \"after - inner-secret\"\n", nil) | |||
| 176 | + | if res.Conclusion != ConclusionSuccess { | |||
| 177 | + | t.Fatalf("%+v", res) | |||
| 178 | + | } | |||
| 179 | + | if got := rr.results[2].Summary; got != "first\nsecond ***\n" { | |||
| 180 | + | t.Errorf("summary %q", got) | |||
| 181 | + | } | |||
| 182 | + | if got := logOf(rr.steps[1]) + logOf(rr.steps[2]); strings.Contains(got, "inner-secret\n") && !strings.Contains(got, "***") || strings.Contains(strings.ReplaceAll(got, "::add-mask::inner-secret", ""), "visible: inner-secret") || strings.Contains(logOf(rr.steps[2]), "after - inner-secret") { | |||
| 183 | + | t.Errorf("a mask added by an inner step must hide the value everywhere:\n%s", got) | |||
| 184 | + | } | |||
| 185 | + | } | |||
| 186 | + | ||||
| 187 | + | // The archive token, and its Basic form, are masked wherever they appear. | |||
| 188 | + | func TestArchiveTokenAndBasicFormAreMasked(t *testing.T) { | |||
| 189 | + | const token = "archive-tok-123" | |||
| 190 | + | basic := base64.StdEncoding.EncodeToString([]byte("x-access-token:" + token)) | |||
| 191 | + | forge := newForge(t, map[string][]byte{"/tarball/o/t/v1": tarOf(t, "o-t-x", files{ | |||
| 192 | + | "action.yml": "name: t\nruns:\n using: node20\n main: main.sh\n", | |||
| 193 | + | "main.sh": "echo \"token " + token + " basic " + basic + "\"\n"})}) | |||
| 194 | + | rr, res := actionResults(t, files{}, " - uses: o/t@v1\n", func(c *Config) { c.Actions.Resolver = forge.resolver(token) }) | |||
| 195 | + | if res.Conclusion != ConclusionSuccess { | |||
| 196 | + | t.Fatalf("%+v", res) | |||
| 197 | + | } | |||
| 198 | + | if got := logOf(rr.step(t, "Run o/t@v1")); !strings.Contains(got, "token *** basic ***") { | |||
| 199 | + | t.Errorf("%s", got) | |||
| 200 | + | } | |||
| 201 | + | } | |||
| 202 | + | ||||
| 203 | + | // timeout-minutes on an action step, on a docker step and on an inner step of a | |||
| 204 | + | // composite: the step fails with the runner's message and the job goes on. | |||
| 205 | + | func TestActionStepTimeouts(t *testing.T) { | |||
| 206 | + | skew := -(60*time.Second - 1500*time.Millisecond) | |||
| 207 | + | tree := files{ | |||
| 208 | + | "slow/action.yml": "name: slow\nruns:\n using: node20\n main: main.sh\n", | |||
| 209 | + | "slow/main.sh": "sleep 30\n", | |||
| 210 | + | "c/action.yml": "name: c\nruns:\n using: composite\n steps:\n - name: inner\n shell: bash\n run: sleep 30\n - shell: bash\n if: always()\n run: echo inner-after\n", | |||
| 211 | + | } | |||
| 212 | + | start := time.Now() | |||
| 213 | + | rr, res := actionResults(t, tree, ` - name: node | |||
| 214 | + | timeout-minutes: 1 | |||
| 215 | + | uses: ./slow | |||
| 216 | + | - name: after | |||
| 217 | + | if: always() | |||
| 218 | + | run: echo after-ran | |||
| 219 | + | `, func(c *Config) { c.StepTimeoutSkew = skew }) | |||
| 220 | + | if res.Conclusion != ConclusionFailure { | |||
| 221 | + | t.Fatalf("%+v", res) | |||
| 222 | + | } | |||
| 223 | + | if time.Since(start) > 10*time.Second { | |||
| 224 | + | t.Errorf("the timeout did not stop the action: %v", time.Since(start)) | |||
| 225 | + | } | |||
| 226 | + | n := rr.step(t, "node") | |||
| 227 | + | if n.Conclusion != ConclusionFailure || !strings.Contains(logOf(n), "##[error]The action 'node' has timed out after 1 minutes.") || strings.Contains(logOf(n), "The operation was canceled.") { | |||
| 228 | + | t.Errorf("%s\n%s", n.Conclusion, logOf(n)) | |||
| 229 | + | } | |||
| 230 | + | if rr.step(t, "after").Conclusion != ConclusionSuccess { | |||
| 231 | + | t.Error("the job is not cancelled by a step timeout") | |||
| 232 | + | } | |||
| 233 | + | // The inner step of a composite action. | |||
| 234 | + | start = time.Now() | |||
| 235 | + | rr, res = actionResults(t, tree, " - name: comp\n timeout-minutes: 1\n uses: ./c\n", func(c *Config) { c.StepTimeoutSkew = skew }) | |||
| 236 | + | if res.Conclusion != ConclusionFailure || time.Since(start) > 10*time.Second { | |||
| 237 | + | t.Fatalf("%+v %v", res, time.Since(start)) | |||
| 238 | + | } | |||
| 239 | + | log := logOf(rr.step(t, "comp")) | |||
| 240 | + | // The inner step has what is left of the timeout of the step that uses the | |||
| 241 | + | // action and fails with a message that names no step (the runner's composite | |||
| 242 | + | // handler). The time is spent after it: the steps that follow are cancelled at | |||
| 243 | + | // once, as the runner's are (their token is cancelled when they are created). | |||
| 244 | + | if strings.Count(log, "##[error]The action has timed out.") < 1 || strings.Contains(log, "after 0 minutes") || strings.Contains(log, "The operation was canceled.") { | |||
| 245 | + | t.Errorf("%s", log) | |||
| 246 | + | } | |||
| 247 | + | } | |||
| 248 | + | ||||
| 249 | + | // A docker action's output goes through the same commands: annotations, masks, | |||
| 250 | + | // matchers. | |||
| 251 | + | func TestDockerActionCommands(t *testing.T) { | |||
| 252 | + | dir := t.TempDir() | |||
| 253 | + | script := `#!/bin/sh | |||
| 254 | + | case "$1" in | |||
| 255 | + | run) | |||
| 256 | + | echo "::add-mask::dkr-secret" | |||
| 257 | + | echo "value dkr-secret" | |||
| 258 | + | echo "::error file=x.go,line=2::from docker" | |||
| 259 | + | echo "::group::g" | |||
| 260 | + | echo "::endgroup::" | |||
| 261 | + | ;; | |||
| 262 | + | esac | |||
| 263 | + | exit 0 | |||
| 264 | + | ` | |||
| 265 | + | writeFiles(t, dir, files{"docker": script}) | |||
| 266 | + | rr, res := actionResults(t, files{}, " - uses: docker://alpine:3\n", func(c *Config) { c.Actions.DockerPath = dir + "/docker" }) | |||
| 267 | + | if res.Conclusion != ConclusionSuccess { | |||
| 268 | + | t.Fatalf("%+v", res) | |||
| 269 | + | } | |||
| 270 | + | log := logOf(rr.step(t, "Run alpine:3")) | |||
| 271 | + | if strings.Contains(log, "value dkr-secret") || !strings.Contains(log, "value ***") { | |||
| 272 | + | t.Errorf("%s", log) | |||
| 273 | + | } | |||
| 274 | + | if as := rr.results[3].Annotations; len(as) != 1 || as[0].Message != "from docker" || as[0].File != "x.go" || as[0].StartLine != 2 { | |||
| 275 | + | t.Errorf("annotations %+v", rr.results) | |||
| 276 | + | } | |||
| 277 | + | } | |||
| 278 | + | ||||
| 279 | + | // The outcome of an action step, before continue-on-error, reaches the reporter. | |||
| 280 | + | func TestActionOutcomeIsReported(t *testing.T) { | |||
| 281 | + | tree := files{"f/action.yml": "name: f\nruns:\n using: node20\n main: main.sh\n", "f/main.sh": "exit 1\n"} | |||
| 282 | + | rr, res := actionResults(t, tree, " - uses: ./f\n continue-on-error: true\n", nil) | |||
| 283 | + | if res.Conclusion != ConclusionSuccess { | |||
| 284 | + | t.Fatalf("%+v", res) | |||
| 285 | + | } | |||
| 286 | + | if got := rr.results[2].Outcome; got != ConclusionFailure { | |||
| 287 | + | t.Errorf("outcome %q, want failure", got) | |||
| 288 | + | } | |||
| 289 | + | if rr.step(t, "Run ./f").Conclusion != ConclusionSuccess { | |||
| 290 | + | t.Error("continue-on-error") | |||
| 291 | + | } | |||
| 292 | + | // A failing action says why in an annotation too: the exit code is an error of | |||
| 293 | + | // the runner, which GitHub reports as an annotation for run steps; node | |||
| 294 | + | // actions only mark the step failed. | |||
| 295 | + | if as := rr.results[2].Annotations; len(as) != 0 { | |||
| 296 | + | t.Errorf("annotations %+v", as) | |||
| 297 | + | } | |||
| 298 | + | } | |||