1// SPDX-License-Identifier: MIT
2
3package executor
4
5import (
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).
15func 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
31func 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.
43func 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"
47echo "::add-mask::hunter2"
48echo "the password is hunter2"
49echo "::warning::careful"
50echo "# Summary hunter2" >> "$GITHUB_STEP_SUMMARY"
51echo '{"problemMatcher":[{"owner":"m","pattern":[{"regexp":"^bad: (.+)$","message":1}]}]}' > "$RUNNER_TEMP/m.json"
52echo "::add-matcher::$RUNNER_TEMP/m.json"
53echo "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.)
82func 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.
103func 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.
126func 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.
161func TestCompositeSummaryAndMaskBelongToTheOuterStep(t *testing.T) {
162 tree := files{"c/action.yml": `name: c
163runs:
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.
188func 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.
205func 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.
251func TestDockerActionCommands(t *testing.T) {
252 dir := t.TempDir()
253 script := `#!/bin/sh
254case "$1" in
255run)
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 ;;
262esac
263exit 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.
280func 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}