Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions agent/agent_configuration.go
Original file line number Diff line number Diff line change
Expand Up @@ -66,6 +66,7 @@ type AgentConfiguration struct {
EnableJobLogTmpfile bool
JobLogPath string
WriteJobLogsToStdout bool
JobLogsOTLP bool
LogFormat string
Shell string
HooksShell string
Expand Down
33 changes: 19 additions & 14 deletions agent/job_runner.go
Original file line number Diff line number Diff line change
Expand Up @@ -709,25 +709,30 @@ BUILDKITE_AGENT_JWKS_KEY_ID`
setEnv("BUILDKITE_TRACING_BACKEND", r.conf.AgentConfiguration.TracingBackend)
setEnv("BUILDKITE_TRACING_SERVICE_NAME", r.conf.AgentConfiguration.TracingServiceName)

// Buildkite backend can provide a traceparent property on the job
// which can be propagated to the job tracing if OpenTelemetry is used
//
// https://www.w3.org/TR/trace-context/#traceparent-header
if r.conf.Job.TraceParent != "" {
setEnv("BUILDKITE_TRACING_TRACEPARENT", r.conf.Job.TraceParent)
}
// Buildkite backend may also provide a tracestate property on the job,
// which carries vendor-specific trace context alongside the traceparent.
//
// https://www.w3.org/TR/trace-context/#tracestate-header
if r.conf.Job.TraceState != "" {
setEnv("BUILDKITE_TRACING_TRACESTATE", r.conf.Job.TraceState)
}
if r.conf.AgentConfiguration.TracingPropagateTraceparent {
// Buildkite backend can provide a traceparent property on the job
// which can be propagated to the job tracing if OpenTelemetry is used.
//
// https://www.w3.org/TR/trace-context/#traceparent-header
if r.conf.Job.TraceParent != "" {
setEnv("BUILDKITE_TRACING_TRACEPARENT", r.conf.Job.TraceParent)
}
// Buildkite backend may also provide a tracestate property on the job,
// which carries vendor-specific trace context alongside traceparent.
//
// https://www.w3.org/TR/trace-context/#tracestate-header
if r.conf.Job.TraceState != "" {
setEnv("BUILDKITE_TRACING_TRACESTATE", r.conf.Job.TraceState)
}
setEnv("BUILDKITE_TRACING_PROPAGATE_TRACEPARENT", "true")
}
}

// This is an agent-operator setting, not a pipeline setting. Always
// overwrite the job-provided value so a pipeline cannot enable OTLP export
// or choose its destination when the agent operator has not opted in.
setEnv("BUILDKITE_JOB_LOGS_OTLP", fmt.Sprint(r.conf.AgentConfiguration.JobLogsOTLP))

setEnv("BUILDKITE_AGENT_DISABLE_WARNINGS_FOR", strings.Join(r.conf.AgentConfiguration.DisableWarningsFor, ","))

// see documentation for BuildkiteMessageMax
Expand Down
7 changes: 7 additions & 0 deletions clicommand/agent_start.go
Original file line number Diff line number Diff line change
Expand Up @@ -127,6 +127,7 @@ type AgentStartConfig struct {

LogFormat string `cli:"log-format"`
WriteJobLogsToStdout bool `cli:"write-job-logs-to-stdout"`
JobLogsOTLP bool `cli:"job-logs-otlp"`
DisableWarningsFor []string `cli:"disable-warnings-for" normalize:"list"`

BuildPath string `cli:"build-path" normalize:"filepath" validate:"required"`
Expand Down Expand Up @@ -439,6 +440,11 @@ var AgentStartCommand = cli.Command{
Usage: "Writes job logs to the agent process' stdout. This simplifies log collection if running agents in Docker (default: false)",
EnvVar: "BUILDKITE_WRITE_JOB_LOGS_TO_STDOUT",
},
cli.BoolFlag{
Name: "job-logs-otlp",
Usage: "Export job logs directly as OpenTelemetry log records using the OTEL_EXPORTER_OTLP_LOGS_* / OTEL_EXPORTER_OTLP_* environment configuration (default: false)",
EnvVar: "BUILDKITE_JOB_LOGS_OTLP",
},
cli.StringFlag{
Name: "shell",
Value: DefaultShell(),
Expand Down Expand Up @@ -1109,6 +1115,7 @@ var AgentStartCommand = cli.Command{
EnableJobLogTmpfile: cfg.EnableJobLogTmpfile,
JobLogPath: cfg.JobLogPath,
WriteJobLogsToStdout: cfg.WriteJobLogsToStdout,
JobLogsOTLP: cfg.JobLogsOTLP,
LogFormat: cfg.LogFormat,
Shell: cfg.Shell,
HooksShell: cfg.HooksShell,
Expand Down
8 changes: 7 additions & 1 deletion clicommand/bootstrap.go
Original file line number Diff line number Diff line change
Expand Up @@ -117,6 +117,7 @@ type BootstrapConfig struct {
TracingPropagateTraceparent bool `cli:"tracing-propagate-traceparent"`
TraceContextEncoding string `cli:"trace-context-encoding"`
NoJobAPI bool `cli:"no-job-api"`
JobLogsOTLP bool `cli:"job-logs-otlp"`
DisableWarningsFor []string `cli:"disable-warnings-for" normalize:"list"`
CheckoutAttempts int `cli:"checkout-attempts"`
}
Expand Down Expand Up @@ -367,12 +368,16 @@ var BootstrapCommand = cli.Command{
Usage: "Accept traceparent from Buildkite control plane (default: false)",
EnvVar: "BUILDKITE_TRACING_PROPAGATE_TRACEPARENT",
},

cli.BoolFlag{
Name: "no-job-api",
Usage: "Disables the Job API, which gives commands in jobs some abilities to introspect and mutate the state of the job (default: false)",
EnvVar: "BUILDKITE_AGENT_NO_JOB_API",
},
cli.BoolFlag{
Name: "job-logs-otlp",
EnvVar: "BUILDKITE_JOB_LOGS_OTLP",
Hidden: true,
},
cli.StringSliceFlag{
Name: "disable-warnings-for",
Usage: "A list of warning IDs to disable",
Expand Down Expand Up @@ -508,6 +513,7 @@ var BootstrapCommand = cli.Command{
TracingTraceState: cfg.TracingTraceState,
TracingPropagateTraceparent: cfg.TracingPropagateTraceparent,
JobAPI: !cfg.NoJobAPI,
JobLogsOTLP: cfg.JobLogsOTLP,
DisabledWarnings: cfg.DisableWarningsFor,
Secrets: cfg.Secrets,
CheckoutAttempts: cfg.CheckoutAttempts,
Expand Down
4 changes: 4 additions & 0 deletions go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -57,9 +57,13 @@ require (
go.opentelemetry.io/contrib/propagators/jaeger v1.44.0
go.opentelemetry.io/contrib/propagators/ot v1.44.0
go.opentelemetry.io/otel v1.44.0
go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploggrpc v0.20.0
go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploghttp v0.20.0
go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc v1.44.0
go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.44.0
go.opentelemetry.io/otel/log v0.20.0
go.opentelemetry.io/otel/sdk v1.44.0
go.opentelemetry.io/otel/sdk/log v0.20.0
go.opentelemetry.io/otel/trace v1.44.0
golang.org/x/crypto v0.53.0
golang.org/x/net v0.56.0
Expand Down
10 changes: 10 additions & 0 deletions go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -477,16 +477,26 @@ go.opentelemetry.io/contrib/propagators/ot v1.44.0 h1:JLTPenzmPtLp5ODPntAA5JhxVu
go.opentelemetry.io/contrib/propagators/ot v1.44.0/go.mod h1:8zr0bHgwkoQXucBK39/H4QphmLf1lSen1Z7FPDZD5Uc=
go.opentelemetry.io/otel v1.44.0 h1:JjwHmHpA4iZ3wBxluu2fbbE7j4kqlE8jXyAyPXH7HqU=
go.opentelemetry.io/otel v1.44.0/go.mod h1:BMgjTHL9WPRlRjL2oZCBTL4whCGtXch2H4BhOPIAyYc=
go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploggrpc v0.20.0 h1:rydZ9sxbcFdm/oWrVyfLTjHIygMgv0bEeMd+3B/BvoM=
go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploggrpc v0.20.0/go.mod h1:earQ25dooT0Hhspq59DZ8YCC50jWfOlFEeWoxy/P444=
go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploghttp v0.20.0 h1:owlhcJ3QO3X0YTDTCcDZ4V+6aVDkWbNmBoQ5NUp7Oww=
go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploghttp v0.20.0/go.mod h1:MP4eemTiI9zC8fgg+DYynhYDYf3ba72S376TvP+Ye0Q=
go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.44.0 h1:4YsVu3B8+3qtWYYrsUYgn0OG78pN0rnNPRGX4SbokQI=
go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.44.0/go.mod h1:+wnlSn0mD1ADVMe3v9Z/WIaiz6q6gL2J/ejaAmdmv80=
go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc v1.44.0 h1:qazEJlUOQzhCpzQpFETGby7EdqjI1wsd0W+6Gg1SCTU=
go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc v1.44.0/go.mod h1:fOD2Yefuxixkx3ahVNf0O/PERb6r4OlbxfATVnYvzCo=
go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.44.0 h1:lgh3PiVrRUWMLOVSkQicxzZll5NjF1r+AtsX1XRIHw0=
go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.44.0/go.mod h1:5Cnhth3m/AgOeTgE3ex12pPmiu/gGtZit03kSzx9X7s=
go.opentelemetry.io/otel/log v0.20.0 h1:/5i0vuHxCLWUfChWG41K9wkM0jafruPw9NU1/RCJirs=
go.opentelemetry.io/otel/log v0.20.0/go.mod h1:wOcMcjsZpG8x7Bak7IhSi/lg8wscV2C1VdrKCLPlt0E=
go.opentelemetry.io/otel/metric v1.44.0 h1:1w0gILTcHdr3YI+ixLyjemwrVnsMURbTZFrSYCdDdmc=
go.opentelemetry.io/otel/metric v1.44.0/go.mod h1:8O7hanEPBNgEMmybD3s2VBKcgWOCsA6tzHBPODAiquo=
go.opentelemetry.io/otel/sdk v1.44.0 h1:nHYwb9lK+fJPU/dnT6s7W7Z8itMWyqrnVfbheVYrZ58=
go.opentelemetry.io/otel/sdk v1.44.0/go.mod h1:Osuydd3Se74nqjAKxid74N5eC+jfEqfTegHRnq58oK0=
go.opentelemetry.io/otel/sdk/log v0.20.0 h1:vM3xI7TQgKPiSghe6urZtAkyFY7SodrSpC83CffDFuY=
go.opentelemetry.io/otel/sdk/log v0.20.0/go.mod h1:Knej2nmsTUzN79T2eeXdRsjjPcoxoq2pUyUHz9TFyyU=
go.opentelemetry.io/otel/sdk/log/logtest v0.20.0 h1:OqdRZ1guyzamK3M6LlRsmGqRrjkHWw6WZOKKli5ELpg=
go.opentelemetry.io/otel/sdk/log/logtest v0.20.0/go.mod h1:PuMIlm7zAt7c3z8zfOI5ox4iT1Z87We+PF6YoINux/M=
go.opentelemetry.io/otel/sdk/metric v1.44.0 h1:3LlKgI+VjbVsjNRFZJZAJ30WjXC5VkNRks6si09iEfI=
go.opentelemetry.io/otel/sdk/metric v1.44.0/go.mod h1:5B5pMARnXxKhltooO4xUuCBorl65a4EpnTalObqOigA=
go.opentelemetry.io/otel/trace v1.44.0 h1:jxF5CsGYCe74MCRx2X4g7WsY/VBKRqqpNvXlX/6gtIk=
Expand Down
9 changes: 6 additions & 3 deletions internal/job/config.go
Original file line number Diff line number Diff line change
Expand Up @@ -206,9 +206,9 @@ type ExecutorConfig struct {
TracingTraceParent string

// W3C tracestate accompanying TracingTraceParent. Plumbed through to the
// bootstrap environment whenever the server provides a value, but only
// attached to the OTel span context when TracingPropagateTraceparent is
// enabled (same opt-in gate as TracingTraceParent).
// bootstrap environment and attached to the OTel span context only when
// TracingPropagateTraceparent is enabled (same opt-in gate as
// TracingTraceParent).
TracingTraceState string

// Accept traceparent context from Buildkite control plane
Expand All @@ -220,6 +220,9 @@ type ExecutorConfig struct {
// Whether to start the JobAPI
JobAPI bool

// Whether to emit visible job process output as OTLP log records.
JobLogsOTLP bool

// The warnings that have been disabled by the user
DisabledWarnings []string

Expand Down
115 changes: 109 additions & 6 deletions internal/job/executor.go
Original file line number Diff line number Diff line change
Expand Up @@ -74,10 +74,54 @@ type Executor struct {
// In order for the latter to happen, a reference is passed into the the Job API server as well
redactors *replacer.Mux

// otlpJobLogger retains the OTLP redaction streams while job log export is
// enabled. Executor redactor flush boundaries must flush these streams too
// so OTLP and the customer-facing job log have identical stream semantics.
otlpJobLogger *otlpJobLogger

// jobAPI is the Job API server for this job. It's retained so the executor
// can consume out-of-band requests made by hooks, such as a working
// directory set by an unwrapped hook via the /workdir endpoint.
jobAPI *jobapi.Server

// loggerTee carries the redacted shell logger output (section headers,
// prompts, comments, warnings) to stderr and, when OTLP job logging is
// enabled, mirrors it into the OTLP exporter so the exported records match
// the customer-facing Buildkite job log.
loggerTee *teeWriter
}

// teeWriter writes to a primary writer and, when configured, also to a
// secondary writer. The secondary sink can be attached after construction,
// which lets the executor mirror already-redacted shell logger output into the
// OTLP exporter once it has been initialised.
type teeWriter struct {
mu sync.Mutex
primary io.Writer
secondary io.Writer
}

func (w *teeWriter) Write(p []byte) (int, error) {
// Hold the lock for the whole write so that detaching the secondary sink
// (setSecondary(nil), called before the OTLP exporter is flushed and shut
// down) cannot complete while a write is still in flight. This guarantees
// no control output lands on the OTLP emitter after it has been flushed.
w.mu.Lock()
defer w.mu.Unlock()

n, err := w.primary.Write(p)
if w.secondary != nil {
// The secondary sink is best-effort: failures must not affect the
// primary (customer-facing) job log output.
_, _ = w.secondary.Write(p)
Comment on lines +114 to +116

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why is the secondary sink considered best-effort? I can imagine a user totally ignoring the BK UI and instead expecting 100% of logs to always be present in their OTel system.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

thats reasonable

}
return n, err
}

func (w *teeWriter) setSecondary(secondary io.Writer) {
w.mu.Lock()
w.secondary = secondary
w.mu.Unlock()
}

// New returns a new executor instance
Expand Down Expand Up @@ -156,6 +200,36 @@ func (e *Executor) Run(ctx context.Context) (exitCode int) {
// Create an empty env for us to keep track of our env changes in
e.shell.Env = env.FromSlice(os.Environ())

// OTLP job log export lives entirely in the bootstrap process, which is the
// single home for this feature. When OpenTelemetry tracing is enabled, the
// per-command emit context carries the active hook/command span, so log
// records are trace-correlated. With tracing disabled, records are still
// emitted but remain uncorrelated.
if e.JobLogsOTLP {
jobLogger, err := newOTLPJobLogger(ctx, e)
if err != nil {
e.shell.Warningf("Failed to initialize OTLP job log exporter: %v", err)
} else {
e.otlpJobLogger = jobLogger
e.shell.SetOutputInterceptor(jobLogger.Wrap)
// Mirror the redacted shell logger control output (section headers,
// prompts, comments, warnings) into OTLP so the exported records
// match the downloadable Buildkite job log and the UI stream.
if e.loggerTee != nil {
e.loggerTee.setSecondary(jobLogger.controlWriter())
}
defer func() {
if e.loggerTee != nil {
e.loggerTee.setSecondary(nil)
}
if err := jobLogger.Close(); err != nil {
e.shell.Warningf("Failed to close OTLP job log exporter: %v", err)
}
e.otlpJobLogger = nil
}()
}
Comment on lines +209 to +230

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The large else branch here makes me think this might be better as a method with an early return:

func (e *Executor) setupOTLPJobLogger(ctx context.Context) func() {
	jobLogger, err := newOTLPJobLogger(ctx, e)
	if err != nil {
		e.shell.Warningf("Failed to initialize OTLP job log exporter: %v", err)
		return func() {}
	}
	e.otlpJobLogger = jobLogger
	e.shell.SetOutputInterceptor(jobLogger.Wrap)
	// Mirror the redacted shell logger control output (section headers,
	// prompts, comments, warnings) into OTLP so the exported records
	// match the downloadable Buildkite job log and the UI stream.
	if e.loggerTee != nil {
		e.loggerTee.setSecondary(jobLogger.controlWriter())
	}
	return func() {
		if e.loggerTee != nil {
			e.loggerTee.setSecondary(nil)
		}
		if err := jobLogger.Close(); err != nil {
			e.shell.Warningf("Failed to close OTLP job log exporter: %v", err)
		}
		e.otlpJobLogger = nil
	}
}
Suggested change
jobLogger, err := newOTLPJobLogger(ctx, e)
if err != nil {
e.shell.Warningf("Failed to initialize OTLP job log exporter: %v", err)
} else {
e.otlpJobLogger = jobLogger
e.shell.SetOutputInterceptor(jobLogger.Wrap)
// Mirror the redacted shell logger control output (section headers,
// prompts, comments, warnings) into OTLP so the exported records
// match the downloadable Buildkite job log and the UI stream.
if e.loggerTee != nil {
e.loggerTee.setSecondary(jobLogger.controlWriter())
}
defer func() {
if e.loggerTee != nil {
e.loggerTee.setSecondary(nil)
}
if err := jobLogger.Close(); err != nil {
e.shell.Warningf("Failed to close OTLP job log exporter: %v", err)
}
e.otlpJobLogger = nil
}()
}
cleanup := e.setupOTLPJobLogger(ctx)
defer cleanup()

}

// Initialize the job API, iff the experiment is enabled. Noop otherwise
if e.JobAPI {
cleanup, err := e.startJobAPI()
Expand Down Expand Up @@ -361,6 +435,18 @@ type HookConfig struct {
PluginName string
}

func hookLogAttributes(hookCfg HookConfig) map[string]string {
attrs := map[string]string{
"buildkite.phase": "hook",
"buildkite.hook.name": hookCfg.Name,
"buildkite.hook.scope": hookCfg.Scope,
}
if hookCfg.PluginName != "" {
attrs["buildkite.hook.plugin"] = hookCfg.PluginName
}
return attrs
}

func (e *Executor) tracingImplementationSpecificHookScope(scope string) string {
if e.TracingBackend != tracetools.BackendDatadog {
return scope
Expand Down Expand Up @@ -463,7 +549,7 @@ func (e *Executor) runUnwrappedHook(ctx context.Context, _ string, hookCfg HookC
environ.Set("BUILDKITE_HOOK_PATH", hookCfg.Path)
environ.Set("BUILDKITE_HOOK_SCOPE", hookCfg.Scope)

if err := e.shell.Command(hookCfg.Path).Run(ctx, shell.WithExtraEnv(environ)); err != nil {
if err := e.shell.Command(hookCfg.Path).Run(ctx, shell.WithExtraEnv(environ), shell.WithOutputAttributes(hookLogAttributes(hookCfg))); err != nil {
return err
}
// Passing an empty env changes through because in polyglot hook we can't detect
Expand Down Expand Up @@ -537,7 +623,7 @@ func logMissingHookInfo(l shell.Logger, hookName, wrapperPath string) {

func (e *Executor) runWrappedShellScriptHook(ctx context.Context, hookName string, hookCfg HookConfig) error {
defer func() {
if err := e.redactors.Flush(); err != nil {
if err := e.flushOutputRedactors(); err != nil {
e.shell.Errorf("Error flushing redactors: %v", err)
}
}()
Expand Down Expand Up @@ -572,7 +658,7 @@ func (e *Executor) runWrappedShellScriptHook(ctx context.Context, hookName strin
if err != nil {
return err
}
return script.Run(ctx, shell.ShowPrompt(false), shell.WithExtraEnv(hookCfg.Env))
return script.Run(ctx, shell.ShowPrompt(false), shell.WithExtraEnv(hookCfg.Env), shell.WithOutputAttributes(hookLogAttributes(hookCfg)))
}()
if err != nil {
exitCode := shell.ExitCode(err)
Expand Down Expand Up @@ -730,6 +816,14 @@ func (e *Executor) addOutputRedactors() {
}
}

func (e *Executor) flushOutputRedactors() error {
err := e.redactors.Flush()
if e.otlpJobLogger != nil {
e.otlpJobLogger.FlushRedactors()
}
return err
}

func (e *Executor) hasGlobalHook(name string) bool {
_, err := hook.Find(nil, e.HooksPath, name)
if err == nil {
Expand Down Expand Up @@ -1167,7 +1261,7 @@ func (e *Executor) CommandPhase(ctx context.Context) (hookErr, commandErr error)
// defaultCommandPhase is executed if there is no global or plugin command hook
func (e *Executor) defaultCommandPhase(ctx context.Context) (retErr error) {
defer func() {
if err := e.redactors.Flush(); err != nil {
if err := e.flushOutputRedactors(); err != nil {
e.shell.Errorf("Error flushing redactors: %v", err)
}
}()
Expand Down Expand Up @@ -1299,7 +1393,11 @@ func (e *Executor) defaultCommandPhase(ctx context.Context) (retErr error) {
e.shell.Promptf("%s", cmdToExec)
}

err = e.shell.Command(cmd[0], cmd[1:]...).Run(ctx, shell.ShowPrompt(false))
err = e.shell.Command(cmd[0], cmd[1:]...).Run(ctx, shell.ShowPrompt(false), shell.WithOutputAttributes(map[string]string{
"buildkite.phase": "command",
"buildkite.hook.name": "command",
"buildkite.hook.scope": "default",
}))
return err
}

Expand Down Expand Up @@ -1398,7 +1496,12 @@ func (e *Executor) setupRedactors(log shell.Logger, environ *env.Environment, st

stdoutRedactor := replacer.New(stdout, needles, redact.Redacted)
e.redactors.Append(stdoutRedactor)
loggerRedactor := replacer.New(stderr, needles, redact.Redacted)
// The shell logger writes through this redactor into loggerTee, whose
// primary sink is stderr. When OTLP job logging is enabled, a secondary
// sink is attached so the same already-redacted control output is mirrored
// into the OTLP exporter.
e.loggerTee = &teeWriter{primary: stderr}
loggerRedactor := replacer.New(e.loggerTee, needles, redact.Redacted)
e.redactors.Append(loggerRedactor)

logger := shell.NewWriterLogger(loggerRedactor, true, e.DisabledWarnings)
Expand Down
Loading