feat: add --profile and OpenTelemetry tracing · XXXDelirious/taskgraph@f9de73f · GitHub
Skip to content

Commit f9de73f

Browse files
committed
feat: add --profile and OpenTelemetry tracing
The executor now records spans for each task run, dependency waits, up-to-date checks, commands, and waits for a concurrency slot or for a `run: once` task started elsewhere. With tracing off the tracer is nil and nothing is recorded. --profile <file> writes the run as a Chrome trace (for ui.perfetto.dev, chrome://tracing or speedscope), with parallel work on separate lanes, and prints the total time, the critical path (following the task that finished last at each level) and the tasks with the most self time. When OTEL_EXPORTER_OTLP_ENDPOINT or OTEL_EXPORTER_OTLP_TRACES_ENDPOINT is set, spans are exported over OTLP (http/protobuf, or grpc via the protocol variables), with the usual OTEL_* configuration. An incoming TRACEPARENT becomes the parent of the run, and each command gets a TRACEPARENT for its own span so nested tools can join the trace. Tracing is off in watch mode. Also fixes the signals tests, which still looked for a `task` binary, and makes `test:all` build bin/taskgraph for them. Implements the upstream feature request go-task#2948. Claude-Session: https://claude.ai/code/session_01Mq67Dn7CYxFfKStHX6jMSE
1 parent 297a384 commit f9de73f

21 files changed

Lines changed: 1337 additions & 29 deletions

File tree

‎CHANGELOG.md‎

Lines changed: 9 additions & 0 deletions

‎README.md‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@ safe, well-described tools, and monorepos where CI time matters.
1818
| [`--graph`](docs/graph-and-explain.md#--graph-see-what-runs-what) | Prints the task graph as a tree, Mermaid, Graphviz DOT or JSON, and flags missing tasks and cycles. |
1919
| [`--explain`](docs/graph-and-explain.md#--explain-why-will-this-run) | Says whether each task would run and why, down to which source files were added, modified or removed. Add `--json` for machine-readable output. |
2020
| [`--affected`](docs/affected.md) | Runs only the tasks affected by what changed in git (`--since origin/main` for pull requests), following sources, Taskfile edits and the dependency graph. With no task names, lists them, optionally as JSON for CI. |
21+
| [`--profile` and OpenTelemetry](docs/tracing.md) | `--profile trace.json` writes a Perfetto/Chrome timeline and prints the critical path and slowest tasks. Setting `OTEL_EXPORTER_OTLP_ENDPOINT` exports spans for every task and command to any OpenTelemetry backend, with `TRACEPARENT` passed through to commands. |
2122
| [Cycle detection](docs/graph-and-explain.md#cycle-detection) | Stops at the first cyclic call and names it (`a -> b -> a`), instead of failing after 1,000 calls or hanging. |
2223

2324
## Install

‎Taskfile.yml‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -144,6 +144,8 @@ tasks:
144144
desc: Runs test suite with signals and watch tests included
145145
deps: [sleepit:build, gotestsum:install]
146146
cmds:
147+
# The signals tests run the taskgraph binary from bin/.
148+
- go build -o {{.BIN}}/taskgraph{{exeExt}} ./cmd/taskgraph
147149
- gotestsum -f '{{.GOTESTSUM_FORMAT}}' -tags 'signals watch' ./...
148150

149151
goreleaser:test:

‎cmd/taskgraph/main.go‎

Lines changed: 84 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -10,8 +10,10 @@ import (
1010
"strconv"
1111
"strings"
1212
"syscall"
13+
"time"
1314

1415
"github.com/spf13/pflag"
16+
"go.opentelemetry.io/otel/trace"
1517

1618
task "github.com/XXXDelirious/taskgraph"
1719
"github.com/XXXDelirious/taskgraph/args"
@@ -20,6 +22,7 @@ import (
2022
"github.com/XXXDelirious/taskgraph/internal/filepathext"
2123
"github.com/XXXDelirious/taskgraph/internal/flags"
2224
"github.com/XXXDelirious/taskgraph/internal/logger"
25+
"github.com/XXXDelirious/taskgraph/internal/tracing"
2326
"github.com/XXXDelirious/taskgraph/internal/version"
2427
"github.com/XXXDelirious/taskgraph/mcpserver"
2528
"github.com/XXXDelirious/taskgraph/taskfile/ast"
@@ -135,9 +138,13 @@ func run() error {
135138
return runMCPServer()
136139
}
137140

141+
tracer, shutdownTracing := setupTracing(log)
142+
defer shutdownTracing()
143+
138144
e := task.NewExecutor(
139145
flags.WithFlags(),
140146
task.WithVersionCheck(true),
147+
task.WithTracer(tracer),
141148
)
142149
if err := e.Setup(); err != nil {
143150
return err
@@ -247,7 +254,83 @@ func run() error {
247254
return e.Status(ctx, calls...)
248255
}
249256

250-
return e.Run(ctx, calls...)
257+
return runTraced(ctx, e, tracer, log, calls)
258+
}
259+
260+
// setupTracing creates a tracer when --profile is set or the OpenTelemetry
261+
// environment variables ask for traces. Tracing is off in watch mode, where
262+
// runs never end. The returned function flushes exported spans.
263+
func setupTracing(log *logger.Logger) (*tracing.Tracer, func()) {
264+
noop := func() {}
265+
if flags.Watch || (flags.Profile == "" && !tracing.OTelEnabled()) {
266+
return nil, noop
267+
}
268+
269+
shutdown := noop
270+
var otelTracer trace.Tracer
271+
if tracing.OTelEnabled() {
272+
t, shutdownOTel, err := tracing.SetupOTel(context.Background(), version.GetVersion())
273+
if err != nil {
274+
log.Warnf("task: OpenTelemetry tracing disabled: %v\n", err)
275+
} else {
276+
otelTracer = t
277+
shutdown = func() {
278+
ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
279+
defer cancel()
280+
if err := shutdownOTel(ctx); err != nil {
281+
log.Warnf("task: could not export OpenTelemetry traces: %v\n", err)
282+
}
283+
}
284+
}
285+
}
286+
return tracing.New(flags.Profile != "", otelTracer), shutdown
287+
}
288+
289+
// runTraced runs the calls inside a root span, then writes the profile if
290+
// one was asked for.
291+
func runTraced(ctx context.Context, e *task.Executor, tracer *tracing.Tracer, log *logger.Logger, calls []*task.Call) error {
292+
if tracer == nil {
293+
return e.Run(ctx, calls...)
294+
}
295+
296+
names := make([]string, 0, len(calls))
297+
for _, c := range calls {
298+
names = append(names, c.Task)
299+
}
300+
// Join the caller's trace when one is passed in, e.g. from CI.
301+
ctx = tracing.ContextWithTraceParent(ctx, os.Getenv("TRACEPARENT"))
302+
ctx, root := tracer.Start(ctx, tracing.KindRun, "taskgraph "+strings.Join(names, " "))
303+
err := e.Run(ctx, calls...)
304+
root.Finish(err)
305+
306+
if flags.Profile != "" {
307+
if perr := writeProfile(flags.Profile, tracer.Spans(), log); perr != nil {
308+
log.Warnf("task: could not write profile: %v\n", perr)
309+
}
310+
}
311+
return err
312+
}
313+
314+
func writeProfile(path string, spans []*tracing.Span, log *logger.Logger) error {
315+
f, err := os.Create(path)
316+
if err != nil {
317+
return err
318+
}
319+
if err := tracing.WriteChromeTrace(f, spans); err != nil {
320+
f.Close()
321+
return err
322+
}
323+
if err := f.Close(); err != nil {
324+
return err
325+
}
326+
327+
var b strings.Builder
328+
fmt.Fprintf(&b, "\ntask: Profile written to %s (open it in https://ui.perfetto.dev)\n\n", path)
329+
if err := tracing.Summarize(spans, 5).WriteSummary(&b); err != nil {
330+
return err
331+
}
332+
log.Errf(logger.Default, "%s", b.String())
333+
return nil
251334
}
252335

253336
// runMCPServer serves the Taskfile over MCP on stdin/stdout. Nothing else may

‎completion/bash/taskgraph.bash‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -26,7 +26,7 @@ function _task()
2626
_filedir -d
2727
return $?
2828
;;
29-
--cacert|--cert|--cert-key)
29+
--cacert|--cert|--cert-key|--profile)
3030
_filedir
3131
return $?
3232
;;

‎completion/fish/taskgraph.fish‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -102,6 +102,7 @@ complete -c $GO_TASK_PROGNAME -l explain -d 'explain whet
102102
complete -c $GO_TASK_PROGNAME -l mcp -d 'serve tasks as tools over MCP (stdio)'
103103
complete -c $GO_TASK_PROGNAME -l affected -d 'run or list only tasks affected by git changes'
104104
complete -c $GO_TASK_PROGNAME -l since -d 'with --affected, compare with this git ref' -x
105+
complete -c $GO_TASK_PROGNAME -l profile -d 'write a trace of the run to this file' -r
105106
complete -c $GO_TASK_PROGNAME -s t -l taskfile -d 'choose Taskfile to run'
106107
complete -c $GO_TASK_PROGNAME -s v -l verbose -d 'verbose output'
107108
complete -c $GO_TASK_PROGNAME -l version -d 'show version'

‎completion/ps/taskgraph.ps1‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -61,6 +61,7 @@ Register-ArgumentCompleter -CommandName $cmdNames -ScriptBlock {
6161
[CompletionResult]::new('--mcp', '--mcp', [CompletionResultType]::ParameterName, 'serve tasks as tools over MCP'),
6262
[CompletionResult]::new('--affected', '--affected', [CompletionResultType]::ParameterName, 'only tasks affected by git changes'),
6363
[CompletionResult]::new('--since', '--since', [CompletionResultType]::ParameterName, 'with --affected, compare with this git ref'),
64+
[CompletionResult]::new('--profile', '--profile', [CompletionResultType]::ParameterName, 'write a trace of the run to this file'),
6465
[CompletionResult]::new('-t', '-t', [CompletionResultType]::ParameterName, 'choose Taskfile'),
6566
[CompletionResult]::new('--taskfile', '--taskfile', [CompletionResultType]::ParameterName, 'choose Taskfile'),
6667
[CompletionResult]::new('-v', '-v', [CompletionResultType]::ParameterName, 'verbose output'),

‎completion/zsh/_taskgraph‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -105,6 +105,7 @@ _task() {
105105
'(--mcp)--mcp[serve tasks as tools over the Model Context Protocol]'
106106
'(--affected)--affected[run or list only tasks affected by git changes]'
107107
'(--since)--since[with --affected, compare with this git ref]:ref: '
108+
'(--profile)--profile[write a trace of the run to this file]:file:_files'
108109
'(-t --taskfile)'{-t,--taskfile}'[specify a different taskfile]:taskfile:_files'
109110
'(-v --verbose)'{-v,--verbose}'[verbose mode]'
110111
'(-w --watch)'{-w,--watch}'[watch-mode for given tasks, re-run when inputs change]'

‎docs/tracing.md‎

Lines changed: 117 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,117 @@
1+
# Profiling and OpenTelemetry tracing
2+
3+
taskgraph can record what it does during a run: every task, the time spent
4+
waiting for dependencies, up-to-date checks, and every command. You can look at
5+
this as a profile on your machine, or send it to an OpenTelemetry backend from
6+
CI.
7+
8+
## `--profile`: where did the time go?
9+
10+
```shell
11+
taskgraph --profile trace.json ci
12+
```
13+
14+
After the run, taskgraph writes the trace and prints a summary:
15+
16+
```text
17+
task: Profile written to trace.json (open it in https://ui.perfetto.dev)
18+
19+
Total: 1.09s
20+
21+
Critical path:
22+
ci 1.09s
23+
└─ test 980ms
24+
└─ build 670ms
25+
└─ assets 261ms
26+
27+
Slowest tasks (own time, excluding tasks they run):
28+
build 408ms
29+
test 310ms
30+
assets 261ms
31+
lint 211ms
32+
gen 111ms
33+
```
34+
35+
- **Critical path:** the chain of tasks that set the total time. At each
36+
step it follows the task that finished last. Speeding up anything off this
37+
path won't make the run faster.
38+
- **Slowest tasks:** ranked by their own time: their commands and checks,
39+
minus the time covered by the tasks they run. Tasks that were up to date or
40+
skipped are marked.
41+
42+
`trace.json` uses the Chrome trace format. Open it in
43+
[ui.perfetto.dev](https://ui.perfetto.dev), `chrome://tracing` or
44+
[speedscope](https://www.speedscope.app) to see a timeline. Tasks that run in
45+
parallel appear on separate lanes:
46+
47+
```text
48+
lane 1 ci ─────────────────────────────────────────────────────────
49+
test ─────────────────────────────────────────────┐
50+
build ────────────────────────────┐ go test ─────┘
51+
gen ──┐ go build ───────────────┘
52+
lane 2 lint ────────┐
53+
lane 3 assets ──────────────┐
54+
```
55+
56+
The profile is written even when a task fails.
57+
58+
## OpenTelemetry
59+
60+
When the standard OpenTelemetry environment variables point to an OTLP
61+
endpoint, taskgraph exports its spans there. You don't need a flag or any
62+
config file:
63+
64+
```shell
65+
export OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4318
66+
taskgraph ci
67+
```
68+
69+
The standard variables are supported:
70+
71+
| Variable | Effect |
72+
| ---------------------------------------------------------------------------- | -------------------------------------------------- |
73+
| `OTEL_EXPORTER_OTLP_ENDPOINT`, `OTEL_EXPORTER_OTLP_TRACES_ENDPOINT` | Where to send spans. Tracing is on when either is set. |
74+
| `OTEL_EXPORTER_OTLP_PROTOCOL`, `OTEL_EXPORTER_OTLP_TRACES_PROTOCOL` | `http/protobuf` (default) or `grpc`. |
75+
| `OTEL_EXPORTER_OTLP_HEADERS` | e.g. an API key for your backend. |
76+
| `OTEL_SERVICE_NAME`, `OTEL_RESOURCE_ATTRIBUTES` | Override `service.name` (default `taskgraph`) and add attributes. |
77+
| `OTEL_SDK_DISABLED=true`, `OTEL_TRACES_EXPORTER=none` | Turn it off. |
78+
79+
The spans are:
80+
81+
| Span | Attributes |
82+
| ------------------------------------ | ----------------------------------------------------- |
83+
| `taskgraph <tasks>` | The root span for the whole invocation. |
84+
| `task <name>` | `task.name`, `taskgraph.status` (`ran`, `up-to-date`, `skipped`, `failed`) |
85+
| `deps` | Time spent waiting for a task's dependencies. |
86+
| `up-to-date check` | Preconditions plus the sources/status check, and `up_to_date`. |
87+
| `cmd <command>` | `task.name`, `cmd` |
88+
| `waiting for ...` | Waiting for a `--concurrency` slot, or for a `run: once` task started elsewhere. |
89+
90+
Failed tasks and commands record the error and set the span status to
91+
`Error`.
92+
93+
### Joining a larger trace
94+
95+
- **Incoming:** if the `TRACEPARENT` environment variable holds a W3C
96+
trace context, taskgraph's root span becomes its child. So a CI system or
97+
wrapper script that starts a trace sees taskgraph inside it.
98+
- **Outgoing:** every command a task runs gets `TRACEPARENT` set to its own
99+
`cmd` span. Tools that read it (including a nested `taskgraph`, test
100+
runners and build tools that support OpenTelemetry) add their spans under
101+
the command that ran them.
102+
103+
### Example: a local collector with Jaeger
104+
105+
```shell
106+
docker run --rm -p 16686:16686 -p 4318:4318 jaegertracing/jaeger:latest
107+
export OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4318
108+
taskgraph ci
109+
# open http://localhost:16686 and search for the "taskgraph" service
110+
```
111+
112+
## Notes
113+
114+
- Tracing is off in watch mode (`--watch`), whose runs never end.
115+
- `--profile` cannot be combined with `--dry`, `--watch`, `--graph`,
116+
`--explain`, `--mcp`, `--status` or `--summary`.
117+
- With neither `--profile` nor an OTLP endpoint, no spans are created at all.

‎executor.go‎

Lines changed: 16 additions & 0 deletions

0 commit comments

Comments
 (0)