1// SPDX-License-Identifier: MIT
2
3package executor
4
5import (
6 "fmt"
7 "math"
8 "math/rand/v2"
9 "os"
10 "strings"
11 "time"
12)
13
14// healthBackoff is BackoffTimerHelper.GetExponentialBackoff(retry, 2 s, 32 s,
15// 2 s) (BackoffTimerHelper.cs:27-36).
16func healthBackoff(attempt int) time.Duration {
17 random := 1600 + rand.Float64()*800 // Random.Next(1600, 2400) ms
18 add := (math.Pow(2, float64(attempt)) - 1) * random
19 ms := math.Min(2000+add, 32000)
20 return time.Duration(ms * float64(time.Millisecond))
21}
22
23// containerHealth is ContainerHealthcheck (ContainerOperationProvider.cs:
24// 372-392): a container without a HEALTHCHECK is healthy; while docker says
25// "starting" the check waits with an exponential back off.
26func (j *job) containerHealth(s *stepRun, c *container, cancel <-chan struct{}) (bool, error) {
27 inspect := func() (string, error) {
28 cmd := j.newDockerCmd("inspect",
29 eqOpt("--format", "{{if .Config.Healthcheck}}{{print .State.Health.Status}}{{end}}"), raw(c.id))
30 l, err := j.dockerList(s, cmd, cancel)
31 if err != nil || len(l) == 0 {
32 return "", err
33 }
34 return l[0], nil
35 }
36 h, err := inspect()
37 if err != nil {
38 return false, err
39 }
40 if h == "" {
41 return true, nil
42 }
43 for retry := 0; strings.EqualFold(h, "starting"); retry++ {
44 d := healthBackoff(retry)
45 if f := j.cfg.Actions.Backoff; f != nil {
46 d = f()
47 }
48 // TimeSpan.Seconds is the seconds component, not the total.
49 j.out(s.num, fmt.Sprintf("%s service is starting, waiting %d seconds before checking again.", c.alias, int(d.Seconds())%60))
50 if !j.sleepOrCancel(d, cancel) {
51 return false, errCancelled
52 }
53 if h, err = inspect(); err != nil {
54 return false, err
55 }
56 }
57 return strings.EqualFold(h, "healthy"), nil
58}
59
60// healthchecks is RunContainersHealthcheck (:105-139).
61func (j *job) healthchecks(s *stepRun, all []*container, cancel <-chan struct{}) error {
62 num := s.num
63 j.out(num, "##[group]Waiting for all services to be ready")
64 var bad []*container
65 for _, c := range all {
66 if c.isJob {
67 continue
68 }
69 ok, err := j.containerHealth(s, c, cancel)
70 if err != nil {
71 return err
72 }
73 if !ok {
74 bad = append(bad, c)
75 continue
76 }
77 j.out(num, c.alias+" service is healthy.")
78 }
79 j.out(num, "##[endgroup]")
80 if len(bad) == 0 {
81 return nil
82 }
83 for _, c := range bad {
84 j.out(num, "##[group]Service container "+c.alias+" failed.")
85 if _, err := j.dockerCode(s, j.newDockerCmd("logs", raw("--details", c.id)), cancel); err != nil {
86 return err
87 }
88 j.errorf(num, "Failed to initialize container %s", c.image)
89 c.failedInit = true
90 j.out(num, "##[endgroup]")
91 }
92 return ghErrorf("One or more containers failed to start.")
93}
94
95// stopContainers is "Stop containers" (StopContainersAsync, :105-124 and
96// StopContainerAsync, :328-351). It is registered with the condition always(),
97// so it runs after a failure, a cancellation and a timeout alike; its commands
98// run on a budget of their own (they do not end with the job's cancellation,
99// and a stalled daemon does not hold them forever).
100func (j *job) stopContainers(s *stepRun, _ <-chan struct{}) stepResult {
101 if j.cs == nil {
102 return resSucceeded
103 }
104 errs := j.cleanupContainers(s)
105 for _, e := range errs {
106 j.errorf(s.num, "%s", e.Error())
107 }
108 if len(errs) > 0 {
109 return resFailed
110 }
111 return resSucceeded
112}
113
114// fallbackCleanup is the cleanup of the job when "Stop containers" did not (or
115// not completely) run: a panic, a runner shutdown that skips the queued post
116// steps, a budget that ran out. It does only what is left; with nothing left
117// it runs no docker command. Its messages go to the diagnostics of the runner,
118// the job log being closed.
119func (j *job) fallbackCleanup() {
120 if j.cs == nil || !j.cs.pending() {
121 return
122 }
123 for _, e := range j.cleanupContainers(nil) {
124 j.cfg.Log.Warn().Err(e).Msg("fallback cleanup of the job containers")
125 }
126}
127
128// pending reports whether something created by the job is still to be removed.
129func (cs *containerSet) pending() bool {
130 cs.mu.Lock()
131 defer cs.mu.Unlock()
132 if cs.networkTry != "" && !cs.netRemoved || len(cs.dirs) > 0 {
133 return true
134 }
135 for _, c := range cs.all() {
136 if c.createTried && !c.removed {
137 return true
138 }
139 }
140 return false
141}
142
143// cleanupContainers removes what the job created: every container, then the
144// network, then the credentials directories left behind. It attempts all of
145// them whatever fails, within CleanupBudget, each command within
146// CleanupCommand, and returns the errors. Logs of a service are best effort and
147// never stand in the way of its removal. s, when set, gets the runner's lines.
148// It is idempotent: what is gone is not tried again.
149func (j *job) cleanupContainers(s *stepRun) (errs []error) {
150 cs := j.cs
151 cs.cleanupMu.Lock()
152 defer cs.cleanupMu.Unlock()
153 t := j.timeouts()
154 cs.mu.Lock()
155 if cs.deadline.IsZero() {
156 cs.deadline = time.Now().Add(t.CleanupBudget)
157 }
158 remaining := time.Until(cs.deadline)
159 cs.mu.Unlock()
160 budget, budgetOut, stop := bound(nil, max(remaining, time.Nanosecond))
161 defer stop()
162 defer func() { errs = dedupeErrors(errs) }()
163 out := func(line string) {
164 if s != nil {
165 j.out(s.num, line)
166 }
167 }
168 run := func(c dockerCmd) (int, error) {
169 _, code, err := j.dockerDoCleanup(c, s, budget, budgetOut, t, t.CleanupCommand)
170 return code, err
171 }
172 // rm runs `docker rm --force target`. It reports whether the target is
173 // gone: removed, or docker says it does not exist. Any other failure leaves
174 // it pending, for the fallback of the job to try again.
175 rm := func(kind string, c dockerCmd) (gone bool) {
176 lines, code, err := j.dockerDoCleanup(c, s, budget, budgetOut, t, t.CleanupCommand)
177 switch {
178 case err != nil:
179 errs = append(errs, err)
180 return false
181 case code == 0:
182 return true
183 case absent(lines):
184 return true
185 }
186 j.warnTo(s, fmt.Sprintf("Docker %s fail with exit code %d", kind, code))
187 return false
188 }
189 // A container whose create did not finish is not known by its id, and its
190 // name may not be ours (options: can set another --name): it is found by
191 // the label every container of the job carries (DockerCreate adds it).
192 var unresolved []*container
193 for _, c := range cs.all() {
194 if c.createTried && !c.removed && c.id == "" {
195 unresolved = append(unresolved, c)
196 }
197 }
198 if len(unresolved) > 0 {
199 ok := true
200 ids, code, err := j.dockerDoCleanup(j.newDockerCmd("ps", raw("--all", "--quiet", "--no-trunc"), quotedOpt("--filter", "label="+j.dockerLabel())), nil, budget, budgetOut, t, t.CleanupCommand)
201 switch {
202 case err != nil:
203 errs, ok = append(errs, err), false
204 case code != 0:
205 j.warnTo(s, fmt.Sprintf("Docker ps fail with exit code %d", code))
206 ok = false
207 }
208 known := map[string]bool{}
209 for _, c := range cs.all() {
210 if c.id != "" {
211 known[c.id] = true // those are removed below, after their logs
212 }
213 }
214 for _, id := range ids {
215 if containerIDRe.MatchString(id) && !known[id] && !rm("rm", j.newDockerCmd("rm", raw("--force", id))) {
216 ok = false
217 }
218 }
219 if ok { // listed, and everything listed is gone: nothing of the job is left
220 for _, c := range unresolved {
221 c.removed = true
222 }
223 }
224 }
225 for _, c := range cs.all() {
226 if !c.createTried || c.removed || c.id == "" {
227 continue
228 }
229 if !c.isJob && !c.failedInit {
230 out("Print service container logs: " + c.name)
231 code, err := run(j.newDockerCmd("logs", raw("--details", c.id)))
232 switch {
233 case err != nil:
234 // Best effort, as the runner's warning for a failed logs: it
235 // neither fails the step nor stops the removal.
236 j.warnTo(s, "Docker logs failed: "+err.Error())
237 case code != 0:
238 j.warnTo(s, fmt.Sprintf("Docker logs fail with exit code %d", code))
239 }
240 }
241 out("Stop and remove container: " + c.name)
242 if rm("rm", j.newDockerCmd("rm", raw("--force", c.id))) {
243 c.removed = true
244 }
245 }
246 cs.mu.Lock()
247 network, gone := cs.networkTry, cs.netRemoved
248 cs.mu.Unlock()
249 if network != "" && !gone {
250 out("Remove container network: " + network)
251 if rm("network rm", j.newDockerCmd("network", raw("rm", network))) {
252 cs.mu.Lock()
253 cs.netRemoved = true
254 cs.mu.Unlock()
255 }
256 }
257 cs.mu.Lock()
258 dirs := cs.dirs
259 cs.dirs = nil
260 cs.mu.Unlock()
261 for _, d := range dirs {
262 if err := os.RemoveAll(d); err != nil {
263 cs.addDir(d)
264 errs = append(errs, ghErrorf("Failed to remove directory containing Docker client credentials: %v", err))
265 }
266 }
267 return errs
268}
269
270// warnTo logs a warning to the step, or to the diagnostics without one.
271func (j *job) warnTo(s *stepRun, msg string) {
272 if s != nil {
273 j.tagged(s.num, "##[warning]", msg)
274 return
275 }
276 j.cfg.Log.Warn().Msg(msg)
277}
278
279// absent reports whether docker's answer to a removal says the object does not
280// exist: that is the state the cleanup wants.
281func absent(lines []string) bool {
282 for _, l := range lines {
283 l = strings.ToLower(l)
284 if strings.Contains(l, "no such container") || strings.Contains(l, "no such network") ||
285 strings.Contains(l, "no such object") || strings.Contains(l, "network") && strings.Contains(l, "not found") {
286 return true
287 }
288 }
289 return false
290}
291
292// dockerDoCleanup runs a command of the cleanup: bounded by its own limit and
293// by the budget of the whole cleanup, its output (stdout and stderr) returned,
294// logged to s if any. The budget is checked here, before every command: once
295// it is spent nothing is started (a command started with a closed cancel would
296// still cost a signal escalation) and the object stays pending.
297func (j *job) dockerDoCleanup(c dockerCmd, s *stepRun, budget <-chan struct{}, budgetOut func() bool, t ContainerTimeouts, limit time.Duration) ([]string, int, error) {
298 spent := func() error {
299 return ghErrorf("The cleanup of the containers ran out of time (%s): not run: docker %s", t.CleanupBudget, j.dockerArgString(c))
300 }
301 select {
302 case <-budget:
303 return nil, 0, spent()
304 default:
305 }
306 lines, code, err := j.dockerDo(c, dockerOpts{s: s, cancel: budget, all: true, timeout: limit, errToOut: true})
307 if err == errCancelled && budgetOut() {
308 return lines, code, ghErrorf("The cleanup of the containers ran out of time (%s): stopped: docker %s", t.CleanupBudget, j.dockerArgString(c))
309 }
310 return lines, code, err
311}
312
313// dedupeErrors keeps the first of the errors that read the same.
314func dedupeErrors(errs []error) []error {
315 seen := map[string]bool{}
316 var out []error
317 for _, e := range errs {
318 if !seen[e.Error()] {
319 seen[e.Error()] = true
320 out = append(out, e)
321 }
322 }
323 return out
324}