From b8abadb4f0f91a7837925ff2e71970bf0c4ed68d Mon Sep 17 00:00:00 2001 From: Valentin Maerten Date: Wed, 22 Apr 2026 17:22:54 +0200 Subject: [PATCH] =?UTF-8?q?=F0=9F=90=9B=20fix(output):=20wrap=20gitlab=20s?= =?UTF-8?q?ections=20at=20task=20level=20(#2806)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Previously the gitlab output wrapped each command individually, causing two visible bugs in real GitLab pipelines: - every section displayed a duration of 00:00, because start and end markers were emitted microseconds apart for instant commands - the `task: [NAME] CMD` announcement lines were rendered outside the sections, because Logger.Errf bypassed the cmd-level wrapper Fix by wrapping output at the task level via a new optional [output.TaskWrapper] interface that GitLab implements. Task-scoped writers are threaded via ctx so nested `task:` invocations produce properly nested sections (GitLab supports this natively), and deps running in parallel each get their own buffer with mutex-protected flushes into the parent's buffer. - `internal/output/output.go`: add TaskWrapper interface - `internal/output/gitlab.go`: logic moved from WrapWriter to WrapTask; WrapWriter becomes passthrough; sync.Mutex around the buffer for concurrent flushes from parallel sub-task sections - `task_output.go` (new): ctx plumbing + helpers kept out of task.go - `task.go`: 7 lines of surgical edits — name the lambda's error return, wrap before the cmd loop, defer the closer with the final error, and swap the cmd announcement to `printCmdAnnouncement` which writes into the task-scoped stderr --- internal/output/gitlab.go | 21 ++++- internal/output/output.go | 8 ++ internal/output/output_test.go | 137 +++++++++++++++++++++++++++++++-- task.go | 12 ++- task_output.go | 70 +++++++++++++++++ 5 files changed, 237 insertions(+), 11 deletions(-) create mode 100644 task_output.go diff --git a/internal/output/gitlab.go b/internal/output/gitlab.go index 030dd3b0..92560712 100644 --- a/internal/output/gitlab.go +++ b/internal/output/gitlab.go @@ -5,6 +5,7 @@ import ( "fmt" "io" "regexp" + "sync" "time" "github.com/google/uuid" @@ -16,13 +17,25 @@ import ( // section markers]. Section IDs are generated automatically so that // start and end markers always match and stay unique per invocation. // +// GitLab wraps output at the task level via the [TaskWrapper] interface, +// so each task (including its command announcements and all its cmds) +// appears inside a single collapsible section. Nested task invocations +// produce nested sections. +// // [GitLab CI collapsible section markers]: https://docs.gitlab.com/ci/jobs/job_logs/#create-custom-collapsible-sections type GitLab struct { Collapsed bool ErrorOnly bool } -func (g GitLab) WrapWriter(stdOut, _ io.Writer, _ string, cache *templater.Cache) (io.Writer, io.Writer, CloseFunc) { +// WrapWriter is a passthrough for GitLab: wrapping happens at the task +// level via WrapTask, not per command. +func (g GitLab) WrapWriter(stdOut, stdErr io.Writer, _ string, _ *templater.Cache) (io.Writer, io.Writer, CloseFunc) { + return stdOut, stdErr, func(error) error { return nil } +} + +// WrapTask wraps an entire task's output in a single collapsible section. +func (g GitLab) WrapTask(stdOut, _ io.Writer, cache *templater.Cache) (io.Writer, io.Writer, CloseFunc) { header := "" if cache != nil { header = templater.Replace("{{.TASK}}", cache) @@ -50,6 +63,7 @@ func (g GitLab) WrapWriter(stdOut, _ io.Writer, _ string, cache *templater.Cache } type gitlabWriter struct { + mu sync.Mutex writer io.Writer buff bytes.Buffer id string @@ -59,10 +73,15 @@ type gitlabWriter struct { } func (gw *gitlabWriter) Write(p []byte) (int, error) { + gw.mu.Lock() + defer gw.mu.Unlock() return gw.buff.Write(p) } func (gw *gitlabWriter) close() error { + gw.mu.Lock() + defer gw.mu.Unlock() + if gw.buff.Len() == 0 { return nil } diff --git a/internal/output/output.go b/internal/output/output.go index 1201f4ee..03d899e8 100644 --- a/internal/output/output.go +++ b/internal/output/output.go @@ -13,6 +13,14 @@ type Output interface { WrapWriter(stdOut, stdErr io.Writer, prefix string, cache *templater.Cache) (io.Writer, io.Writer, CloseFunc) } +// TaskWrapper is an optional interface that Output implementations can satisfy +// to wrap an entire task's execution in a single enclosing block — including +// the task's command announcements and all its commands' output — instead of +// wrapping each command individually via WrapWriter. +type TaskWrapper interface { + WrapTask(stdOut, stdErr io.Writer, cache *templater.Cache) (io.Writer, io.Writer, CloseFunc) +} + type CloseFunc func(err error) error // Build the Output for the requested ast.Output. diff --git a/internal/output/output_test.go b/internal/output/output_test.go index 47d72bad..7c97d929 100644 --- a/internal/output/output_test.go +++ b/internal/output/output_test.go @@ -6,7 +6,11 @@ import ( "fmt" "io" "regexp" + "strconv" + "strings" + "sync" "testing" + "time" "github.com/fatih/color" "github.com/stretchr/testify/assert" @@ -144,7 +148,7 @@ func TestGitLab(t *testing.T) { var b bytes.Buffer o := output.GitLab{} - w, _, cleanup := o.WrapWriter(&b, io.Discard, "", gitlabTaskCache("build")) + w, _, cleanup := o.WrapTask(&b, io.Discard, gitlabTaskCache("build")) fmt.Fprintln(w, "hello") assert.Equal(t, "", b.String(), "output must be buffered until close") @@ -167,7 +171,7 @@ func TestGitLabUniqueSectionIDs(t *testing.T) { ids := make([]string, 3) for i := range ids { var b bytes.Buffer - w, _, cleanup := o.WrapWriter(&b, io.Discard, "", gitlabTaskCache("build")) + w, _, cleanup := o.WrapTask(&b, io.Discard, gitlabTaskCache("build")) fmt.Fprintln(w, "x") require.NoError(t, cleanup(nil)) m := gitlabMarkerPattern.FindStringSubmatch(b.String()) @@ -185,7 +189,7 @@ func TestGitLabCollapsed(t *testing.T) { var b bytes.Buffer o := output.GitLab{Collapsed: true} - w, _, cleanup := o.WrapWriter(&b, io.Discard, "", gitlabTaskCache("build")) + w, _, cleanup := o.WrapTask(&b, io.Discard, gitlabTaskCache("build")) fmt.Fprintln(w, "x") require.NoError(t, cleanup(nil)) @@ -199,7 +203,7 @@ func TestGitLabErrorOnlySwallowsOutputOnNoError(t *testing.T) { var b bytes.Buffer o := output.GitLab{ErrorOnly: true} - w, _, cleanup := o.WrapWriter(&b, io.Discard, "", gitlabTaskCache("build")) + w, _, cleanup := o.WrapTask(&b, io.Discard, gitlabTaskCache("build")) fmt.Fprintln(w, "hello") require.NoError(t, cleanup(nil)) assert.Empty(t, b.String()) @@ -210,7 +214,7 @@ func TestGitLabErrorOnlyShowsOutputOnError(t *testing.T) { var b bytes.Buffer o := output.GitLab{ErrorOnly: true} - w, _, cleanup := o.WrapWriter(&b, io.Discard, "", gitlabTaskCache("build")) + w, _, cleanup := o.WrapTask(&b, io.Discard, gitlabTaskCache("build")) fmt.Fprintln(w, "hello") require.NoError(t, cleanup(errors.New("boom"))) @@ -224,7 +228,7 @@ func TestGitLabSlugSanitizesTaskName(t *testing.T) { var b bytes.Buffer o := output.GitLab{} - w, _, cleanup := o.WrapWriter(&b, io.Discard, "", gitlabTaskCache("my task:with spaces")) + w, _, cleanup := o.WrapTask(&b, io.Discard, gitlabTaskCache("my task:with spaces")) fmt.Fprintln(w, "x") require.NoError(t, cleanup(nil)) @@ -233,6 +237,127 @@ func TestGitLabSlugSanitizesTaskName(t *testing.T) { assert.Regexp(t, `^[a-zA-Z0-9_.-]+$`, m[2], "section ID must only contain GitLab-allowed chars") } +func TestGitLabWrapWriterIsPassthrough(t *testing.T) { + t.Parallel() + + var b bytes.Buffer + o := output.GitLab{} + w, _, cleanup := o.WrapWriter(&b, io.Discard, "", nil) + + fmt.Fprintln(w, "hello") + assert.Equal(t, "hello\n", b.String(), "WrapWriter must be a passthrough for GitLab") + assert.NoError(t, cleanup(nil)) + assert.Equal(t, "hello\n", b.String(), "closer must be a no-op") +} + +func TestGitLabWrapTaskSingleSection(t *testing.T) { + t.Parallel() + + var b bytes.Buffer + o := output.GitLab{} + w, _, cleanup := o.WrapTask(&b, io.Discard, gitlabTaskCache("build")) + + // Simulate multiple cmd outputs being written during a task's execution. + fmt.Fprintln(w, "cmd 1 output") + fmt.Fprintln(w, "cmd 2 output") + fmt.Fprintln(w, "cmd 3 output") + require.NoError(t, cleanup(nil)) + + // There must be exactly one section_start and one section_end. + assert.Equal(t, 1, strings.Count(b.String(), "section_start:")) + assert.Equal(t, 1, strings.Count(b.String(), "section_end:")) + + m := gitlabMarkerPattern.FindStringSubmatch(b.String()) + require.NotNil(t, m) + assert.Equal(t, "cmd 1 output\ncmd 2 output\ncmd 3 output\n", m[5]) +} + +func TestGitLabWrapTaskDurationElapsed(t *testing.T) { + t.Parallel() + + var b bytes.Buffer + o := output.GitLab{} + w, _, cleanup := o.WrapTask(&b, io.Discard, gitlabTaskCache("slow")) + + fmt.Fprintln(w, "started") + time.Sleep(1100 * time.Millisecond) + fmt.Fprintln(w, "done") + require.NoError(t, cleanup(nil)) + + m := gitlabMarkerPattern.FindStringSubmatch(b.String()) + require.NotNil(t, m) + startTS, err := strconv.ParseInt(m[1], 10, 64) + require.NoError(t, err) + endTS, err := strconv.ParseInt(m[6], 10, 64) + require.NoError(t, err) + assert.GreaterOrEqual(t, endTS-startTS, int64(1), + "end TS must be at least 1 second after start TS when task takes >1s") +} + +func TestGitLabWrapTaskNested(t *testing.T) { + t.Parallel() + + var root bytes.Buffer + parent := output.GitLab{} + parentW, _, parentClose := parent.WrapTask(&root, io.Discard, gitlabTaskCache("parent")) + + fmt.Fprintln(parentW, "before child") + + child := output.GitLab{} + childW, _, childClose := child.WrapTask(parentW, io.Discard, gitlabTaskCache("child")) + fmt.Fprintln(childW, "inside child") + require.NoError(t, childClose(nil)) + + fmt.Fprintln(parentW, "after child") + require.NoError(t, parentClose(nil)) + + out := root.String() + // Two section_start and two section_end + assert.Equal(t, 2, strings.Count(out, "section_start:")) + assert.Equal(t, 2, strings.Count(out, "section_end:")) + + // Order: parent start → child start → child end → parent end + parentStart := strings.Index(out, "section_start:") // first + childStart := strings.Index(out[parentStart+1:], "section_start:") + parentStart + 1 + childEnd := strings.Index(out, "section_end:") + parentEnd := strings.LastIndex(out, "section_end:") + assert.Less(t, parentStart, childStart, "child_start must come after parent_start") + assert.Less(t, childStart, childEnd, "child_end must come after child_start") + assert.Less(t, childEnd, parentEnd, "parent_end must come after child_end") +} + +func TestGitLabWrapTaskConcurrentWrites(t *testing.T) { + t.Parallel() + + var root bytes.Buffer + parent := output.GitLab{} + parentW, _, parentClose := parent.WrapTask(&root, io.Discard, gitlabTaskCache("parent")) + + const numChildren = 10 + var wg sync.WaitGroup + for i := 0; i < numChildren; i++ { + wg.Add(1) + go func(i int) { + defer wg.Done() + child := output.GitLab{} + childW, _, childClose := child.WrapTask(parentW, io.Discard, gitlabTaskCache(fmt.Sprintf("child%d", i))) + fmt.Fprintf(childW, "child %d output\n", i) + _ = childClose(nil) + }(i) + } + wg.Wait() + require.NoError(t, parentClose(nil)) + + out := root.String() + // 1 parent + 10 children = 11 section_start and 11 section_end + assert.Equal(t, 11, strings.Count(out, "section_start:")) + assert.Equal(t, 11, strings.Count(out, "section_end:")) + // All 10 child outputs present + for i := 0; i < numChildren; i++ { + assert.Contains(t, out, fmt.Sprintf("child %d output", i)) + } +} + func TestPrefixed(t *testing.T) { //nolint:paralleltest // cannot run in parallel var b bytes.Buffer l := &logger.Logger{ diff --git a/task.go b/task.go index 54cda927..9a5b3b0d 100644 --- a/task.go +++ b/task.go @@ -204,9 +204,9 @@ func (e *Executor) RunTask(ctx context.Context, call *Call) error { release := e.acquireConcurrencyLimit() defer release() - if err = e.startExecution(ctx, t, func(ctx context.Context) error { + if err = e.startExecution(ctx, t, func(ctx context.Context) (err error) { e.Logger.VerboseErrf(logger.Magenta, "task: %q started\n", call.Task) - if err := e.runDeps(ctx, t); err != nil { + if err = e.runDeps(ctx, t); err != nil { return err } @@ -266,6 +266,9 @@ func (e *Executor) RunTask(ctx context.Context, call *Call) error { var deferredExitCode uint8 + ctx, taskOutCloser := e.wrapTaskOutput(ctx, t, call) + defer func() { taskOutCloser(err) }() + for i := range t.Cmds { if t.Cmds[i].Defer { defer e.runDeferred(t, call, i, t.Vars, &deferredExitCode) @@ -393,7 +396,7 @@ func (e *Executor) runCommand(ctx context.Context, t *ast.Task, call *Call, i in } if e.Verbose || (!call.Silent && !cmd.Silent && !t.IsSilent() && !e.Taskfile.Silent && !e.Silent) { - e.Logger.Errf(logger.Green, "task: [%s] %s\n", t.Name(), cmd.Cmd) + e.printCmdAnnouncement(ctx, t, cmd.Cmd) } if e.Dry { @@ -409,7 +412,8 @@ func (e *Executor) runCommand(ctx context.Context, t *ast.Task, call *Call, i in if err != nil { return fmt.Errorf("task: failed to get variables: %w", err) } - stdOut, stdErr, closer := outputWrapper.WrapWriter(e.Stdout, e.Stderr, t.Prefix, outputTemplater) + taskStdOut, taskStdErr := e.writersFromCtx(ctx) + stdOut, stdErr, closer := outputWrapper.WrapWriter(taskStdOut, taskStdErr, t.Prefix, outputTemplater) err = execext.RunCommand(ctx, &execext.RunCommandOptions{ Command: cmd.Cmd, diff --git a/task_output.go b/task_output.go new file mode 100644 index 00000000..976952eb --- /dev/null +++ b/task_output.go @@ -0,0 +1,70 @@ +package task + +import ( + "context" + "io" + + "github.com/fatih/color" + + "github.com/go-task/task/v3/internal/logger" + "github.com/go-task/task/v3/internal/output" + "github.com/go-task/task/v3/internal/templater" + "github.com/go-task/task/v3/taskfile/ast" +) + +type taskWritersKey struct{} + +type taskWriters struct { + stdout, stderr io.Writer +} + +// writersFromCtx returns the task-scoped writers if set, otherwise the +// Executor's own stdout/stderr. +func (e *Executor) writersFromCtx(ctx context.Context) (io.Writer, io.Writer) { + if tw, ok := ctx.Value(taskWritersKey{}).(*taskWriters); ok && tw != nil { + return tw.stdout, tw.stderr + } + return e.Stdout, e.Stderr +} + +// wrapTaskOutput wraps a task's output in a task-scoped block if e.Output +// implements [output.TaskWrapper] and the task is not interactive. Returns +// the (possibly updated) ctx and a closer that flushes the block. The closer +// is always safe to call — it is a no-op when no wrapping took place. +func (e *Executor) wrapTaskOutput(ctx context.Context, t *ast.Task, call *Call) (context.Context, func(error)) { + noop := func(error) {} + if t.Interactive { + return ctx, noop + } + tw, ok := e.Output.(output.TaskWrapper) + if !ok { + return ctx, noop + } + stdOut, stdErr := e.writersFromCtx(ctx) + vars, err := e.Compiler.FastGetVariables(t, call) + if err != nil { + e.Logger.VerboseErrf(logger.Yellow, "task: output setup: %v\n", err) + return ctx, noop + } + wOut, wErr, closer := tw.WrapTask(stdOut, stdErr, &templater.Cache{Vars: vars}) + ctx = context.WithValue(ctx, taskWritersKey{}, &taskWriters{stdout: wOut, stderr: wErr}) + return ctx, func(loopErr error) { + if err := closer(loopErr); err != nil { + e.Logger.Errf(logger.Red, "task: output close: %v\n", err) + } + } +} + +// printCmdAnnouncement prints the "task: [NAME] CMD" line using the +// task-scoped stderr if available, so the announcement ends up inside the +// task's output block. +func (e *Executor) printCmdAnnouncement(ctx context.Context, t *ast.Task, cmdStr string) { + _, stdErr := e.writersFromCtx(ctx) + if stdErr == e.Stderr { + // No task-scoped writer — fall back to the Logger to preserve existing + // behavior (respects Logger's color config, etc.). + e.Logger.Errf(logger.Green, "task: [%s] %s\n", t.Name(), cmdStr) + return + } + _, _ = color.New(color.FgGreen).Fprintf(stdErr, "task: [%s] %s\n", t.Name(), cmdStr) +}