Skip to content

Commit a4f2c26

Browse files
authored
chore(act): group log lines when running act tests inside gha (#488)
1 parent 3de0393 commit a4f2c26

4 files changed

Lines changed: 84 additions & 21 deletions

File tree

tests/act/internal/act/act.go

Lines changed: 83 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@ import (
1414
"regexp"
1515
"runtime"
1616
"strings"
17+
"sync"
1718
"testing"
1819

1920
"github.com/google/uuid"
@@ -34,6 +35,7 @@ var (
3435
"ubuntu-arm64-xlarge",
3536
"ubuntu-arm64-2xlarge",
3637
}
38+
globalLogMutex sync.Mutex
3739
)
3840

3941
const nektosActRunnerImage = "ghcr.io/catthehacker/ubuntu:act-latest"
@@ -43,6 +45,10 @@ type Runner struct {
4345
// t is the testing.T instance for the current test.
4446
t *testing.T
4547

48+
// name is the name of this Runner, used for logging.
49+
// By default, this is t.Name(), but can be overridden with WithName().
50+
name string
51+
4652
// uuid is a unique identifier for this Runner instance.
4753
uuid uuid.UUID
4854

@@ -77,6 +83,9 @@ type Runner struct {
7783
// By default, act uses the architecture of the host machine.
7884
// This can be useful to force a specific platform when running on ARM Macs.
7985
ContainerArchitecture string
86+
87+
// inGitHubActions indicates whether the runner is executing in a GitHub Actions environment.
88+
inGitHubActions bool
8089
}
8190

8291
// actionsCachePathBase is the base path for the action cache.
@@ -116,6 +125,14 @@ func WithActionsCachePath(cachePath string) RunnerOption {
116125
}
117126
}
118127

128+
// WithName sets the name of the Runner, used for logging.
129+
// By default, the Runner uses t.Name() as its name.
130+
func WithName(name string) RunnerOption {
131+
return func(r *Runner) {
132+
r.name = name
133+
}
134+
}
135+
119136
// NewRunner creates a new Runner instance.
120137
func NewRunner(t *testing.T, opts ...RunnerOption) (*Runner, error) {
121138
// Get GitHub token from environment (GHA) or gh CLI (local)
@@ -129,10 +146,12 @@ func NewRunner(t *testing.T, opts ...RunnerOption) (*Runner, error) {
129146
ghToken = strings.TrimSpace(string(output))
130147
}
131148
r := &Runner{
132-
t: t,
133-
uuid: uuid.New(),
134-
gitHubToken: ghToken,
135-
GCOM: newGCOM(t),
149+
t: t,
150+
name: t.Name(),
151+
uuid: uuid.New(),
152+
gitHubToken: ghToken,
153+
inGitHubActions: os.Getenv("GITHUB_ACTIONS") == "true",
154+
GCOM: newGCOM(t),
136155
Argo: NewHTTPSpy(t, map[string]string{
137156
"uri": "https://mock-argo-workflows.example.com/workflows/grafana-plugins-cd/mock-workflow-id",
138157
}),
@@ -316,28 +335,47 @@ func (r *Runner) Run(workflow workflow.Workflow, event Event) (runResult *RunRes
316335
cmd := exec.Command("sh", "-c", actCmd)
317336
cmd.Env = os.Environ()
318337

319-
// Get stdout pipe to parse act output
338+
// Get stdout and stderr pipes to parse act output
320339
stdout, err := cmd.StdoutPipe()
321340
if err != nil {
322341
return nil, fmt.Errorf("get act stdout pipe: %w", err)
323342
}
343+
stderr, err := cmd.StderrPipe()
344+
if err != nil {
345+
return nil, fmt.Errorf("get act stderr pipe: %w", err)
346+
}
324347

325-
// Just pipe stderr as nothing to parse there
326-
cmd.Stderr = os.Stderr
348+
// Merge stdout and stderr into a single reader so both are grouped in GHA logs
349+
mergedR, mergedW := io.Pipe()
350+
go func() {
351+
var wg sync.WaitGroup
352+
wg.Add(2)
353+
go func() {
354+
defer wg.Done()
355+
_, _ = io.Copy(mergedW, stdout)
356+
}()
357+
go func() {
358+
defer wg.Done()
359+
_, _ = io.Copy(mergedW, stderr)
360+
}()
361+
wg.Wait()
362+
_ = mergedW.Close()
363+
}()
327364

328365
// Run act in the background
329366
if err := cmd.Start(); err != nil {
330367
return nil, fmt.Errorf("start act: %w", err)
331368
}
332369

333-
// Process json logs in stdout stream.
370+
// Process json logs in merged stdout/stderr stream
334371
// This must complete BEFORE cmd.Wait() is called, because cmd.Wait()
335372
// closes the stdout pipe. If the goroutine is still reading when the
336373
// pipe is closed, it will get a "file already closed" error.
337374
errs := make(chan error, 1)
338375
go func() {
339-
if err := r.processStream(stdout, runResult); err != nil {
340-
errs <- fmt.Errorf("process act stdout: %w", err)
376+
if err := r.processStream(mergedR, runResult); err != nil {
377+
errs <- fmt.Errorf("process act output: %w", err)
378+
return
341379
}
342380
errs <- nil
343381
}()
@@ -359,46 +397,73 @@ func (r *Runner) Run(workflow workflow.Workflow, event Event) (runResult *RunRes
359397
return nil, fmt.Errorf("act exit: %w", err)
360398
}
361399
runResult.Success = true
362-
363400
return runResult, nil
364401
}
365402

403+
// logOrBuffer writes a message to the buffer if running in GitHub Actions,
404+
// or prints it immediately to stdout otherwise.
405+
func (r *Runner) logOrBuffer(msg string, logBuffer *strings.Builder) {
406+
if r.inGitHubActions {
407+
logBuffer.WriteString(msg)
408+
logBuffer.WriteString("\n")
409+
} else {
410+
fmt.Println(msg)
411+
}
412+
}
413+
366414
// processStream processes the given reader line by line as JSON log lines generated by act.
415+
// If running in GitHub Actions, it buffers all log lines and prints them in a log group when the process finishes.
416+
// Otherwise, it prints each line immediately to stdout.
367417
func (r *Runner) processStream(reader io.Reader, runResult *RunResult) error {
368418
scanner := bufio.NewScanner(reader)
419+
var logBuffer strings.Builder
420+
369421
for scanner.Scan() {
370422
var data logLine
371423
line := scanner.Bytes()
372424
err := json.Unmarshal(line, &data)
373-
if r.Verbose {
374-
fmt.Println(string(line))
375-
}
376425
if err != nil {
426+
// Preserve plain-text lines (commonly emitted on stderr) in non-verbose mode.
427+
r.logOrBuffer(string(line), &logBuffer)
377428
continue
378429
}
430+
if r.Verbose {
431+
r.logOrBuffer(string(line), &logBuffer)
432+
}
379433

380-
// Print back to stdout in a human-readable format for now
381434
// Clean up uuids from data.Job for cleaner output
382435
data.Job = logUUIDRegex.ReplaceAllString(data.Job, "")
383-
fmt.Printf("%s: [%s] %s\n", r.t.Name(), data.Job, strings.TrimSpace(data.Message))
436+
formattedLog := fmt.Sprintf("%s: [%s] %s", r.name, data.Job, strings.TrimSpace(data.Message))
437+
r.logOrBuffer(formattedLog, &logBuffer)
384438

385439
// Parse GHA commands (outputs, annotations, etc.)
386440
r.parseGHACommand(data, runResult)
387441
}
388442
if err := scanner.Err(); err != nil {
389443
return fmt.Errorf("scanner error: %w", err)
390444
}
445+
446+
// Print all buffered logs in a GitHub Actions log group
447+
if r.inGitHubActions {
448+
globalLogMutex.Lock()
449+
fmt.Printf("::group::%s\n", r.name)
450+
fmt.Print(logBuffer.String())
451+
fmt.Println("::endgroup::")
452+
globalLogMutex.Unlock()
453+
}
454+
391455
return nil
392456
}
393457

394458
// parseGHACommand parses intercepted GHA commands from act log lines and
395459
// updates the RunResult accordingly. If the log line does not contain a
396460
// recognized command, it is ignored.
461+
// Warning and verbose messages are always printed immediately to stdout.
397462
func (r *Runner) parseGHACommand(data logLine, runResult *RunResult) {
398463
switch data.Command {
399464
case "set-output":
400465
if data.Name == "" {
401-
fmt.Printf("%s: [%s]: WARNING: received GHA set-output command without name, ignoring output", r.t.Name(), data.Job)
466+
fmt.Printf("%s: [%s]: WARNING: received GHA set-output command without name, ignoring output\n", r.name, data.Job)
402467
break
403468
}
404469
// Store the output value. StepID can be an array in case of composite actions,
@@ -417,7 +482,7 @@ func (r *Runner) parseGHACommand(data logLine, runResult *RunResult) {
417482
default:
418483
// Nothing special to do
419484
if r.Verbose && data.Command != "" {
420-
fmt.Printf("%s: [%s]: unhandled GHA command %q, ignoring", r.t.Name(), data.Job, data.Command)
485+
fmt.Printf("%s: [%s]: unhandled GHA command %q, ignoring\n", r.name, data.Job, data.Command)
421486
}
422487
}
423488
}

tests/act/main_package_test.go

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -177,8 +177,6 @@ func TestPackage(t *testing.T) {
177177
expBasePluginZipFiles = append(expBasePluginZipFiles, filepath.Join(tc.expPluginID, "go_plugin_build_manifest"))
178178

179179
for _, osArch := range osArchCombos {
180-
t.Logf("checking plugin ZIP for %s", osArch)
181-
182180
// Create a copy of the expected base files for each zip file we check
183181
expPluginZipFiles := make([]string, len(expBasePluginZipFiles))
184182
copy(expPluginZipFiles, expBasePluginZipFiles[:])

tests/act/main_smoke_test.go

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -85,7 +85,6 @@ func TestSmoke(t *testing.T) {
8585
var pluginOutput testAndBuildOutput
8686
rawOutput, ok := r.Outputs.Get("test-and-build", "outputs", "plugin")
8787
require.True(t, ok, "plugin output should be present")
88-
t.Log(rawOutput)
8988
err = json.Unmarshal([]byte(rawOutput), &pluginOutput)
9089
require.NoError(t, err, "unmarshal plugin output JSON")
9190
require.Equal(t, tc.exp, pluginOutput)

tests/act/main_test.go

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -146,6 +146,7 @@ func warmUpCaches(ciWf workflow.BaseWorkflow) error {
146146
warmupRunner, err := act.NewRunner(
147147
&testing.T{},
148148
act.WithActionsCachePath(act.TemplateActionsCachePath),
149+
act.WithName("toolcache-warmup"),
149150
)
150151
if err != nil {
151152
return fmt.Errorf("create warmup runner: %w", err)

0 commit comments

Comments
 (0)