diff --git a/README.md b/README.md index f773fbb1..e5d457ee 100644 --- a/README.md +++ b/README.md @@ -16,6 +16,7 @@ Gitte keeps all your repos in sync, runs startup checks to verify your local mac - [Commands](#commands) - [Configuration](#configuration) - [Environment variables](#environment-variables) +- [Telemetry](#telemetry) - [Global flags](#global-flags) - [State and override files](#state-and-override-files) @@ -170,6 +171,58 @@ See [docs/config.md](./docs/config.md) for the full configuration reference. --- +## Telemetry + +Gitte can export OpenTelemetry traces to an OTLP/HTTP endpoint (e.g. Elastic +APM) to help debug failures. Traces capture per-repo git context (branch, +commit SHA, dirty state) and per-task outcomes with errors. To identify which +developer and machine hit a failure, the OS username (`user.name`) and hostname +(`host.name`) are attached to every trace. + +**What is recorded:** the gitte CLI arguments and each action's command line are +exported as span attributes (this is intentional — knowing what ran is the +point). Note that gitte's **injected** environment — a project's `env`, +`env_when`, and feature-gate env — is also exported on task spans (the +`gitte.env` attribute) and in the task logs; the inherited **process** +environment (everything in `os.Environ`) is **not**. So keep secrets out of +action command definitions, CLI arguments, and config `env`/feature-gate blocks +— pass real secrets through the process environment instead. Full remote URLs +are never collected either (repos are identified by name only). + +Each `gitte run` produces a structured trace: a root span with child spans for +each phase (`startup`, `gitops`, `actions`), a span per startup check, a span +per action (e.g. `build`, `up`) parenting its task spans, and a span per repo +sync. Action and startup command output is also shipped as **OTEL logs**, +correlated to the span that produced each line (stdout → INFO, stderr → WARN). + +Logs are enabled with tracing; set `GITTE_TELEMETRY_LOGS=off` to keep traces but +disable the (higher-volume) log export. Keep secrets out of command output — +log lines are exported verbatim. + +Enable it via the shared config: + +```yaml +telemetry: + endpoint: https://apm.example.com:8200 + headers: + Authorization: "Bearer " # or: "ApiKey " +``` + +Environment variables: + +| Variable | Effect | +|---|---| +| `GITTE_TELEMETRY=off` | Disable telemetry locally (kill-switch) | +| `GITTE_TELEMETRY_URL` | Override the endpoint | +| `GITTE_TELEMETRY_LOGS=off` | Disable OTEL log export (keep traces) | +| `OTEL_EXPORTER_OTLP_ENDPOINT` / `OTEL_EXPORTER_OTLP_HEADERS` | Standard OTEL env vars, honored as a fallback when no gitte endpoint is set | + +Precedence: `GITTE_TELEMETRY=off` > `GITTE_TELEMETRY_URL` > config endpoint > +`OTEL_EXPORTER_OTLP_*`. Telemetry is best-effort and never blocks or slows +gitte; export failures are silently ignored. + +--- + ## Global flags ``` diff --git a/actions/features_test.go b/actions/features_test.go new file mode 100644 index 00000000..ccf981b6 --- /dev/null +++ b/actions/features_test.go @@ -0,0 +1,69 @@ +package actions + +import ( + "reflect" + "strings" + "testing" + + "github.com/cego/gitte/config" + "github.com/cego/gitte/state" +) + +func TestEnabledFeaturesForProject(t *testing.T) { + cfg := &config.GitteConfig{ + FeatureGates: map[string]config.FeatureGate{ + "feat-on": {}, // empty scope → applies to all projects + "feat-off": {}, // disabled in state + "feat-scoped-out": {Scope: config.FeatureScope{Projects: []string{"other"}}}, // enabled but scoped to a different project + }, + } + st := &state.GitteState{Features: map[string]state.FeatureState{ + "feat-on": {Enabled: true}, + "feat-off": {Enabled: false}, + "feat-scoped-out": {Enabled: true}, + }} + proj := config.ProjectConfig{Remote: "git@github.com:example/myproj.git"} + + got := enabledFeaturesForProject(cfg, st, "myproj", proj) + want := []string{"feat-on"} + if !reflect.DeepEqual(got, want) { + t.Fatalf("enabledFeaturesForProject = %v, want %v", got, want) + } +} + +func TestInjectedEnv(t *testing.T) { + cfg := &config.GitteConfig{ + FeatureGates: map[string]config.FeatureGate{ + "feat-on": {Effects: config.FeatureEffects{Env: map[string]string{"FEAT_VAR": "1"}}}, + }, + } + st := &state.GitteState{Features: map[string]state.FeatureState{"feat-on": {Enabled: true}}} + proj := config.ProjectConfig{ + Remote: "git@github.com:example/myproj.git", + Env: map[string]string{"PROJ_VAR": "x"}, + } + got := injectedEnv(cfg, st, "myproj", proj) + if got["PROJ_VAR"] != "x" || got["FEAT_VAR"] != "1" { + t.Fatalf("injectedEnv = %v, want PROJ_VAR=x and FEAT_VAR=1", got) + } +} + +func TestOutputTail(t *testing.T) { + // stderr preferred when non-empty + if got := outputTail([]byte("the real error"), []byte("noise")); got != "the real error" { + t.Fatalf("stderr-preferred: got %q", got) + } + // falls back to stdout when stderr is blank (e.g. gitlab-ci-local prints to stdout) + if got := outputTail([]byte(" \n"), []byte("stdout failure")); got != "stdout failure" { + t.Fatalf("stdout-fallback: got %q", got) + } + // capped to the last errorTailBytes + big := []byte(strings.Repeat("x", errorTailBytes+500)) + if got := outputTail(big, nil); len(got) != errorTailBytes { + t.Fatalf("cap: len=%d, want %d", len(got), errorTailBytes) + } + // empty when no output + if got := outputTail(nil, nil); got != "" { + t.Fatalf("empty: got %q", got) + } +} diff --git a/actions/runner.go b/actions/runner.go index 2c4a8e83..f615e0be 100644 --- a/actions/runner.go +++ b/actions/runner.go @@ -19,6 +19,11 @@ import ( "github.com/cego/gitte/features" "github.com/cego/gitte/output" "github.com/cego/gitte/state" + "github.com/cego/gitte/telemetry" + + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/codes" + "go.opentelemetry.io/otel/trace" ) // RunActions executes planned action tasks. @@ -34,6 +39,13 @@ func RunActions(ctx context.Context, cfg *config.GitteConfig, st *state.GitteSta infos := buildTaskInfos(cfg, st, cwd, keys) view := newView(mode, infos, actionOrder, runCancel, retryCh, cfg.QuickSolve.GitClean.Exclude) + tracker := telemetry.NewActionTracker(ctx) + + onStart := func(name string) { + tracker.OnStart(name) + view.OnStart(name) + } + // Track per-task outcomes so retry runs can pre-complete tasks that already finished. outcomes := newTaskOutcomes() onFinish := func(name string, err error, elapsed time.Duration) { @@ -45,6 +57,7 @@ func RunActions(ctx context.Context, cfg *config.GitteConfig, st *state.GitteSta outcomes.set(name, outcomeFailed) } view.OnFinish(name, err, elapsed) + tracker.OnFinish(name, err) } maxParallel := envMaxParallel @@ -58,7 +71,7 @@ func RunActions(ctx context.Context, cfg *config.GitteConfig, st *state.GitteSta var retrySet map[string]struct{} // nil on first run var runErr error for { - tasks := buildExecutorTasks(cfg, st, cwd, keys) + tasks := buildExecutorTasks(cfg, st, cwd, keys, tracker) // Strip needs from explicitly retried tasks so they run immediately. if retrySet != nil { @@ -71,7 +84,7 @@ func RunActions(ctx context.Context, cfg *config.GitteConfig, st *state.GitteSta exec, err := executor.NewExecutor(tasks, executor.ExecutorOptions{ MaxParallelization: maxParallel, - OnTaskStart: view.OnStart, + OnTaskStart: onStart, OnTaskReset: view.OnReset, OnTaskFinish: onFinish, }) @@ -194,7 +207,7 @@ func buildTaskInfos(cfg *config.GitteConfig, st *state.GitteState, cwd string, k } // buildExecutorTasks constructs executor.Task list from keys. -func buildExecutorTasks(cfg *config.GitteConfig, st *state.GitteState, cwd string, keys []GroupKeyWithDeps) []executor.Task { +func buildExecutorTasks(cfg *config.GitteConfig, st *state.GitteState, cwd string, keys []GroupKeyWithDeps, tracker *telemetry.ActionTracker) []executor.Task { tasks := make([]executor.Task, 0, len(keys)) searchFors := cfg.SearchFor @@ -239,7 +252,7 @@ func buildExecutorTasks(cfg *config.GitteConfig, st *state.GitteState, cwd strin Needs: needNames, Retry: retryConfig, ExecuteFn: func(ctx context.Context, tName string, handler executor.OutputHandler) error { - return runGroupTask(ctx, cfg, st, cwd, proj, key.Project, tName, cmds, allSearchFors, handler) + return runGroupTask(ctx, cfg, st, cwd, proj, key.Project, tName, cmds, allSearchFors, handler, tracker) }, }) } @@ -250,6 +263,15 @@ func taskName(key GroupKey) string { return fmt.Sprintf("%s:%s:%s", key.Project, key.Action, key.Group) } +// setActionAttrs records action context on a span. +func setActionAttrs(span trace.Span, taskName, project, command string) { + span.SetAttributes( + attribute.String("gitte.task", taskName), + attribute.String("gitte.project", project), + attribute.String("gitte.command", command), + ) +} + func runGroupTask( ctx context.Context, cfg *config.GitteConfig, @@ -261,7 +283,31 @@ func runGroupTask( cmds []string, searchFors []config.SearchFor, handler executor.OutputHandler, -) error { + tracker *telemetry.ActionTracker, +) (err error) { + actionCtx := tracker.ActionContext(telemetry.ActionOf(taskName)) + // Parent the task span under the action span, but keep running under the + // executor's incoming (cancellable) context so cancellation still propagates + // to the command — attach the span to ctx rather than replacing ctx. + _, span := telemetry.Tracer().Start(actionCtx, "action.run "+taskName) + ctx = trace.ContextWithSpan(ctx, span) + handler = telemetry.LogOutputHandler(handler) + setTaskTelemetryAttrs(span, cfg, st, projName, proj, taskName, cmds) + defer func() { + if recovered := recover(); recovered != nil { + panicErr := fmt.Errorf("panic: %v", recovered) + span.RecordError(panicErr) + span.SetStatus(codes.Error, panicErr.Error()) + span.End() + panic(recovered) + } + if err != nil { + span.RecordError(err) + span.SetStatus(codes.Error, err.Error()) + } + span.End() + }() + if len(cmds) == 0 { return fmt.Errorf("empty command for task %s", taskName) } @@ -291,6 +337,15 @@ func runGroupTask( return err } + if span.IsRecording() { + span.SetAttributes(attribute.Int("gitte.exit_code", res.ExitCode)) + if res.ExitCode != 0 { + if tail := outputTail(res.Stderr, res.Stdout); tail != "" { + span.SetAttributes(attribute.String("gitte.error_tail", tail)) + } + } + } + if res.ExitCode != 0 { return fmt.Errorf("command exited with code %d", res.ExitCode) } @@ -298,6 +353,56 @@ func runGroupTask( return nil } +func setTaskTelemetryAttrs( + span trace.Span, + cfg *config.GitteConfig, + st *state.GitteState, + projName string, + proj config.ProjectConfig, + taskName string, + cmds []string, +) { + if span.IsRecording() { + setActionAttrs(span, taskName, projName, strings.Join(cmds, " ")) + if feats := enabledFeaturesForProject(cfg, st, projName, proj); len(feats) > 0 { + span.SetAttributes(attribute.StringSlice("gitte.features", feats)) + } + if env := injectedEnv(cfg, st, projName, proj); len(env) > 0 { + keys := make([]string, 0, len(env)) + for k := range env { + keys = append(keys, k) + } + sort.Strings(keys) + kvs := make([]string, 0, len(keys)) + for _, k := range keys { + kvs = append(kvs, k+"="+env[k]) + } + span.SetAttributes(attribute.StringSlice("gitte.env", kvs)) + } + } +} + +// errorTailBytes caps how much trailing command output is attached to a failed +// task span via the gitte.error_tail attribute. +const errorTailBytes = 4096 + +// outputTail returns the last errorTailBytes of a failed command's output for +// the gitte.error_tail span attribute — stderr preferred, falling back to +// stdout (tools like gitlab-ci-local print their failures to stdout). +func outputTail(stderr, stdout []byte) string { + if tail := tailString(stderr); tail != "" { + return tail + } + return tailString(stdout) +} + +func tailString(b []byte) string { + if len(b) > errorTailBytes { + b = b[len(b)-errorTailBytes:] + } + return strings.TrimSpace(string(b)) +} + // emitTaskPreamble writes a short header to the task log showing the working // directory, command, and any env vars injected by gitte (project env, env_when, // feature gates). It is emitted before the command starts so the log is @@ -324,16 +429,7 @@ func emitTaskPreamble( emit(" cmd: " + strings.Join(cmds, " ")) // Collect only the vars gitte injects (not all of os.Environ). - injected := make(map[string]string) - for k, v := range proj.Env { - injected[k] = v - } - for k, v := range config.ResolveEnvWhen(proj.EnvWhen, runtime.GOARCH) { - injected[k] = v - } - for k, v := range extraEnvForProject(cfg, st, projName, proj) { - injected[k] = v - } + injected := injectedEnv(cfg, st, projName, proj) if len(injected) > 0 { keys := make([]string, 0, len(injected)) for k := range injected { @@ -348,13 +444,32 @@ func emitTaskPreamble( } } -// extraEnvForProject returns the env vars injected by feature gates for a project. -func extraEnvForProject(cfg *config.GitteConfig, st *state.GitteState, projName string, proj config.ProjectConfig) map[string]string { +// injectedEnv returns the env vars gitte injects for a project's task — project +// env, arch-conditional env_when, and enabled feature-gate env — excluding the +// inherited process environment (os.Environ). +func injectedEnv(cfg *config.GitteConfig, st *state.GitteState, projName string, proj config.ProjectConfig) map[string]string { + injected := make(map[string]string) + for k, v := range proj.Env { + injected[k] = v + } + for k, v := range config.ResolveEnvWhen(proj.EnvWhen, runtime.GOARCH) { + injected[k] = v + } + for k, v := range extraEnvForProject(cfg, st, projName, proj) { + injected[k] = v + } + return injected +} + +// enabledFeaturesForProject returns the sorted names of feature gates that are +// enabled and in scope for the given project (the gates that actually inject +// env into the project's tasks). +func enabledFeaturesForProject(cfg *config.GitteConfig, st *state.GitteState, projName string, proj config.ProjectConfig) []string { if st == nil || cfg.FeatureGates == nil { return nil } - extra := make(map[string]string) + var names []string for gateName, gate := range cfg.FeatureGates { fs, enabled := st.Features[gateName] if !enabled || !fs.Enabled { @@ -377,6 +492,22 @@ func extraEnvForProject(cfg *config.GitteConfig, st *state.GitteState, projName } } + names = append(names, gateName) + } + sort.Strings(names) + return names +} + +// extraEnvForProject returns the env vars injected by feature gates for a project. +func extraEnvForProject(cfg *config.GitteConfig, st *state.GitteState, projName string, proj config.ProjectConfig) map[string]string { + gates := enabledFeaturesForProject(cfg, st, projName, proj) + if len(gates) == 0 { + return nil + } + + extra := make(map[string]string) + for _, gateName := range gates { + gate := cfg.FeatureGates[gateName] for k, v := range gate.Effects.Env { extra[k] = v } @@ -384,10 +515,6 @@ func extraEnvForProject(cfg *config.GitteConfig, st *state.GitteState, projName extra[k] = v } } - - if len(extra) == 0 { - return nil - } return extra } diff --git a/actions/telemetry_test.go b/actions/telemetry_test.go new file mode 100644 index 00000000..19022e79 --- /dev/null +++ b/actions/telemetry_test.go @@ -0,0 +1,46 @@ +package actions + +import ( + "context" + "testing" + + "github.com/cego/gitte/config" + "go.opentelemetry.io/otel" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" + "go.opentelemetry.io/otel/trace/noop" +) + +func TestSetActionAttrs(t *testing.T) { + exp := tracetest.NewInMemoryExporter() + tp := sdktrace.NewTracerProvider(sdktrace.WithSyncer(exp)) + prev := otel.GetTracerProvider() + otel.SetTracerProvider(tp) + t.Cleanup(func() { + otel.SetTracerProvider(prev) + _ = tp.Shutdown(context.Background()) + }) + + _, span := tp.Tracer("test").Start(context.Background(), "action.run") + setActionAttrs(span, "proj:up:default", "proj", "docker compose up") + span.End() + + spans := exp.GetSpans() + if len(spans) != 1 { + t.Fatalf("got %d spans, want 1", len(spans)) + } + got := map[string]string{} + for _, kv := range spans[0].Attributes { + got[string(kv.Key)] = kv.Value.AsString() + } + if got["gitte.task"] != "proj:up:default" || got["gitte.project"] != "proj" || got["gitte.command"] != "docker compose up" { + t.Fatalf("attrs = %+v", got) + } +} + +func TestSetTaskTelemetryAttrs_SkipsWorkForNonRecordingSpan(t *testing.T) { + _, span := noop.NewTracerProvider().Tracer("test").Start(context.Background(), "task") + // nil config/state would panic in feature and environment resolution. A + // non-recording span must return before touching either dependency. + setTaskTelemetryAttrs(span, nil, nil, "project", config.ProjectConfig{}, "project:up:default", []string{"true"}) +} diff --git a/cmd/actions.go b/cmd/actions.go index 4d663e79..1b4da467 100644 --- a/cmd/actions.go +++ b/cmd/actions.go @@ -4,6 +4,9 @@ import ( "fmt" "github.com/cego/gitte/actions" + "github.com/cego/gitte/telemetry" + + "go.opentelemetry.io/otel/codes" "github.com/spf13/cobra" ) @@ -38,7 +41,14 @@ func runActions(args []string) error { args[0], actionStr, projectStr, groupStr) } - return actions.RunActions(globalCtx, globalCfg, globalSt, globalCwd, outputMode(), keys, actionOrder, maxParallelization()) + ctx, span := telemetry.StartPhaseSpan(globalCtx, "actions") + defer span.End() + err := actions.RunActions(ctx, globalCfg, globalSt, globalCwd, outputMode(), keys, actionOrder, maxParallelization()) + if err != nil { + span.RecordError(err) + span.SetStatus(codes.Error, err.Error()) + } + return err } // parseActionArgs maps positional CLI args to (actionStr, groupStr, projectStr). diff --git a/cmd/gitops.go b/cmd/gitops.go index be2c0dec..03969897 100644 --- a/cmd/gitops.go +++ b/cmd/gitops.go @@ -9,6 +9,9 @@ import ( "github.com/cego/gitte/gitops" "github.com/cego/gitte/output" + "github.com/cego/gitte/telemetry" + + "go.opentelemetry.io/otel/codes" "github.com/spf13/cobra" ) @@ -41,17 +44,25 @@ SSH concurrency: Discovery clone/pull runs at most 8 SSH connections in parallel to avoid overwhelming the server. Override with GITTE_MAX_TASK_PARALLELIZATION=N.`, RunE: func(cmd *cobra.Command, args []string) error { + ctx, span := telemetry.StartPhaseSpan(globalCtx, "gitops") + defer span.End() mode := outputMode() warnings, addWarning := newWarnCollector() if discover { - if err := gitops.Discover(globalCtx, globalCfg, globalCwd, mode, addWarning); err != nil { + if err := gitops.Discover(ctx, globalCfg, globalCwd, mode, addWarning); err != nil { gitops.PrintWarnings(mode, warnings()) + span.RecordError(err) + span.SetStatus(codes.Error, err.Error()) return err } } nr := noRebase || os.Getenv("GITTE_NO_REBASE") == "true" - err := gitops.Sync(globalCtx, globalCfg, globalCwd, mode, nr, makePromptFn(mode), addWarning) + err := gitops.Sync(ctx, globalCfg, globalCwd, mode, nr, makePromptFn(mode), addWarning) gitops.PrintWarnings(mode, warnings()) + if err != nil { + span.RecordError(err) + span.SetStatus(codes.Error, err.Error()) + } return err }, } diff --git a/cmd/root.go b/cmd/root.go index 6abdd7f0..1ffa3501 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -13,9 +13,12 @@ import ( "github.com/cego/gitte/config" "github.com/cego/gitte/output" "github.com/cego/gitte/state" + "github.com/cego/gitte/telemetry" "charm.land/lipgloss/v2" "github.com/spf13/cobra" + "go.opentelemetry.io/otel/codes" + "go.opentelemetry.io/otel/trace" ) var ( @@ -32,6 +35,9 @@ var ( globalCwd string globalCtx context.Context globalCancel context.CancelFunc + + globalTelemetryShutdown func(context.Context) + globalRootSpan trace.Span ) // rootCmd is the base command @@ -54,7 +60,15 @@ with dependency resolution.`, if cmd.Name() == "__complete" || cmd.Name() == "__completeNoDesc" { return nil } - return err + if err != nil { + return err + } + + // Telemetry: best-effort, never blocks. Stores root span context in globalCtx + // so it propagates through the executor into gitops/actions leaf spans. + globalTelemetryShutdown = telemetry.Init(globalCtx, globalCfg, cmd.Root().Version) + globalCtx, globalRootSpan = telemetry.StartCommandSpan(globalCtx, cmd.CommandPath(), args) + return nil }, } @@ -72,7 +86,7 @@ func Execute() { globalCancel() } }() - err := rootCmd.Execute() + err := executeRoot() if err != nil { if output.DetectMode(flagNoTTY) == output.ModePlain { fmt.Fprintln(os.Stderr, "error:", err) @@ -83,6 +97,45 @@ func Execute() { } } +// executeRoot guarantees telemetry finalization for both returned errors and +// panics. A panic is recorded as an error before being re-thrown so callers keep +// the normal panic behavior and stack output. +func executeRoot() (err error) { + return runWithTelemetry(rootCmd.Execute) +} + +func runWithTelemetry(run func() error) (err error) { + defer func() { + if recovered := recover(); recovered != nil { + panicErr := fmt.Errorf("panic: %v", recovered) + finishTelemetry(panicErr) + panic(recovered) + } + finishTelemetry(err) + }() + return run() +} + +// finishTelemetry records the final command status on the root span and flushes +// pending spans. Safe to call when telemetry was never initialized (e.g. +// completion commands or an early config failure), where the handles remain nil. +func finishTelemetry(err error) { + if globalRootSpan != nil { + if err != nil { + globalRootSpan.RecordError(err) + globalRootSpan.SetStatus(codes.Error, err.Error()) + } else { + globalRootSpan.SetStatus(codes.Ok, "") + } + globalRootSpan.End() + } + if globalTelemetryShutdown != nil { + shutdownCtx, stop := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM) + defer stop() + globalTelemetryShutdown(shutdownCtx) + } +} + func init() { rootCmd.PersistentFlags().StringVar(&flagConfigPath, "config", "", "path to .gitte.yml (default: auto-discover)") rootCmd.PersistentFlags().BoolVar(&flagNoTTY, "no-tty", false, "disable TUI (plain output)") diff --git a/cmd/root_telemetry_test.go b/cmd/root_telemetry_test.go new file mode 100644 index 00000000..ee39618a --- /dev/null +++ b/cmd/root_telemetry_test.go @@ -0,0 +1,56 @@ +package cmd + +import ( + "context" + "testing" + + "go.opentelemetry.io/otel/codes" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" +) + +func TestRunWithTelemetry_RecordsAndFlushesPanicThenRepanics(t *testing.T) { + exporter := tracetest.NewInMemoryExporter() + provider := sdktrace.NewTracerProvider(sdktrace.WithSyncer(exporter)) + t.Cleanup(func() { _ = provider.Shutdown(context.Background()) }) + + _, span := provider.Tracer("test").Start(context.Background(), "gitte test") + previousSpan := globalRootSpan + previousShutdown := globalTelemetryShutdown + globalRootSpan = span + shutdownCalled := false + globalTelemetryShutdown = func(context.Context) { shutdownCalled = true } + t.Cleanup(func() { + globalRootSpan = previousSpan + globalTelemetryShutdown = previousShutdown + }) + + var recovered any + func() { + defer func() { recovered = recover() }() + _ = runWithTelemetry(func() error { panic("boom") }) + }() + + if recovered != "boom" { + t.Fatalf("recovered panic = %v, want boom", recovered) + } + if !shutdownCalled { + t.Fatal("telemetry shutdown was not called") + } + spans := exporter.GetSpans() + if len(spans) != 1 { + t.Fatalf("exported %d spans, want 1", len(spans)) + } + if spans[0].Status.Code != codes.Error { + t.Fatalf("root span status = %v, want error", spans[0].Status.Code) + } + foundException := false + for _, event := range spans[0].Events { + if event.Name == "exception" { + foundException = true + } + } + if !foundException { + t.Fatal("panic was not sent as an exception event") + } +} diff --git a/cmd/run.go b/cmd/run.go index 9da1772c..9b1b8f42 100644 --- a/cmd/run.go +++ b/cmd/run.go @@ -6,6 +6,8 @@ import ( "github.com/cego/gitte/gitops" "github.com/cego/gitte/startup" + "github.com/cego/gitte/telemetry" + "go.opentelemetry.io/otel/codes" "github.com/spf13/cobra" ) @@ -28,33 +30,50 @@ Examples: ValidArgsFunction: actionArgsCompletion, RunE: func(cmd *cobra.Command, args []string) error { // Step 1: Startup checks - if err := startup.Run(globalCtx, globalCfg, globalCwd, outputMode()); err != nil { - return err + startupCtx, startupSpan := telemetry.StartPhaseSpan(globalCtx, "startup") + serr := startup.Run(startupCtx, globalCfg, globalCwd, outputMode()) + if serr != nil { + startupSpan.RecordError(serr) + startupSpan.SetStatus(codes.Error, serr.Error()) + } + startupSpan.End() + if serr != nil { + return serr } fmt.Println() - // Step 2: Discovery (if requested) + // Step 2: Discovery + git sync mode := outputMode() warnings, addWarning := newWarnCollector() - if discover { - if err := gitops.Discover(globalCtx, globalCfg, globalCwd, mode, addWarning); err != nil { + gitopsCtx, gitopsSpan := telemetry.StartPhaseSpan(globalCtx, "gitops") + gerr := func() error { + if discover { + if err := gitops.Discover(gitopsCtx, globalCfg, globalCwd, mode, addWarning); err != nil { + gitops.PrintWarnings(mode, warnings()) + return err + } + } + nr := noRebase || os.Getenv("GITTE_NO_REBASE") == "true" + if err := gitops.Sync(gitopsCtx, globalCfg, globalCwd, mode, nr, makePromptFn(mode), addWarning); err != nil { gitops.PrintWarnings(mode, warnings()) return err } - } - - // Step 3: Git sync - nr := noRebase || os.Getenv("GITTE_NO_REBASE") == "true" - if err := gitops.Sync(globalCtx, globalCfg, globalCwd, mode, nr, makePromptFn(mode), addWarning); err != nil { gitops.PrintWarnings(mode, warnings()) - return err + return nil + }() + if gerr != nil { + gitopsSpan.RecordError(gerr) + gitopsSpan.SetStatus(codes.Error, gerr.Error()) + } + gitopsSpan.End() + if gerr != nil { + return gerr } - gitops.PrintWarnings(mode, warnings()) fmt.Println() - // Step 4: Actions (if specified) + // Step 3: Actions (if specified) — runActions opens its own "actions" phase span. if len(args) > 0 { return runActions(args) } diff --git a/cmd/startup.go b/cmd/startup.go index efd95f49..fa0f0cd3 100644 --- a/cmd/startup.go +++ b/cmd/startup.go @@ -2,6 +2,9 @@ package cmd import ( "github.com/cego/gitte/startup" + "github.com/cego/gitte/telemetry" + + "go.opentelemetry.io/otel/codes" "github.com/spf13/cobra" ) @@ -11,7 +14,14 @@ func newStartupCmd() *cobra.Command { Use: "startup", Short: "Run startup checks", RunE: func(cmd *cobra.Command, args []string) error { - return startup.Run(globalCtx, globalCfg, globalCwd, outputMode()) + ctx, span := telemetry.StartPhaseSpan(globalCtx, "startup") + defer span.End() + err := startup.Run(ctx, globalCfg, globalCwd, outputMode()) + if err != nil { + span.RecordError(err) + span.SetStatus(codes.Error, err.Error()) + } + return err }, } } diff --git a/config/startup_checks.go b/config/startup_checks.go index 3bb7ec5b..aacd0c02 100644 --- a/config/startup_checks.go +++ b/config/startup_checks.go @@ -4,6 +4,7 @@ import ( "bytes" "context" "fmt" + "io" "os" "os/exec" "path/filepath" @@ -18,7 +19,7 @@ type StartupCheck interface { GetType() string GetHint() string GetNeeds() []string - Check(ctx context.Context, cwd string) error + Check(ctx context.Context, cwd string, stdout, stderr io.Writer) error } // BaseStartupCheck holds common fields for all check types @@ -44,14 +45,18 @@ type ShellStartupCheck struct { Script string `yaml:"script"` } -func (s *ShellStartupCheck) Check(ctx context.Context, cwd string) error { +func (s *ShellStartupCheck) Check(ctx context.Context, cwd string, stdout, stderr io.Writer) error { cmd := exec.CommandContext(ctx, s.Shell, "-c", s.Script) //nolint:gosec cmd.Dir = cwd - var stderr bytes.Buffer - cmd.Stderr = &stderr + var stderrBuf bytes.Buffer + if stderr == nil { + stderr = io.Discard + } + cmd.Stdout = stdout + cmd.Stderr = io.MultiWriter(stderr, &stderrBuf) if err := cmd.Run(); err != nil { if exitErr, ok := err.(*exec.ExitError); ok { - stderrStr := strings.TrimSpace(stderr.String()) + stderrStr := strings.TrimSpace(stderrBuf.String()) if stderrStr != "" { return fmt.Errorf("shell script exited with code %d: %s", exitErr.ExitCode(), stderrStr) } @@ -68,12 +73,14 @@ type CommandStartupCheck struct { Command []string `yaml:"cmd"` } -func (s *CommandStartupCheck) Check(ctx context.Context, cwd string) error { +func (s *CommandStartupCheck) Check(ctx context.Context, cwd string, stdout, stderr io.Writer) error { if len(s.Command) == 0 { return fmt.Errorf("command check has no command") } cmd := exec.CommandContext(ctx, s.Command[0], s.Command[1:]...) //nolint:gosec cmd.Dir = cwd + cmd.Stdout = stdout + cmd.Stderr = stderr if err := cmd.Run(); err != nil { if exitErr, ok := err.(*exec.ExitError); ok { return fmt.Errorf("command exited with code %d", exitErr.ExitCode()) @@ -90,7 +97,7 @@ type YamlPathPresentStartupCheck struct { File string `yaml:"file"` } -func (s *YamlPathPresentStartupCheck) Check(_ context.Context, _ string) error { +func (s *YamlPathPresentStartupCheck) Check(_ context.Context, _ string, _, _ io.Writer) error { path, err := goyaml.PathString(s.Path) if err != nil { return fmt.Errorf("invalid yaml path: %w", err) diff --git a/config/types.go b/config/types.go index f631740d..58887269 100644 --- a/config/types.go +++ b/config/types.go @@ -16,6 +16,7 @@ type GitteConfig struct { GroupIncludes map[string][]string `yaml:"groupIncludes,omitempty"` Projects map[string]ProjectConfig `yaml:"projects,omitempty"` QuickSolve QuickSolveConfig `yaml:"quickSolve,omitempty"` + Telemetry TelemetryConfig `yaml:"telemetry,omitempty"` } // QuickSolveConfig holds settings for the quick solve feature in the actions TUI. @@ -28,6 +29,15 @@ type QuickSolveGitClean struct { Exclude []string `yaml:"exclude,omitempty"` } +// TelemetryConfig configures OpenTelemetry tracing export. Telemetry is enabled +// when an endpoint is resolved (from this config or the GITTE_TELEMETRY_URL env +// var). Headers carries arbitrary export headers, e.g. an Elastic APM secret +// token as Authorization: "Bearer " or an API key as "ApiKey ". +type TelemetryConfig struct { + Endpoint string `yaml:"endpoint,omitempty"` + Headers map[string]string `yaml:"headers,omitempty"` +} + // Template is a reusable project configuration template. // Extends lists parent template names (resolved left-to-right, self applied last). type Template struct { diff --git a/config/types_test.go b/config/types_test.go new file mode 100644 index 00000000..02ac1aae --- /dev/null +++ b/config/types_test.go @@ -0,0 +1,22 @@ +package config + +import "testing" + +func TestGitteConfig_TelemetryUnmarshal(t *testing.T) { + yamlData := []byte(` +telemetry: + endpoint: https://apm.example.com:8200 + headers: + Authorization: "Bearer secret" +`) + cfg, err := LoadGitteConfigFromYAML(yamlData) + if err != nil { + t.Fatalf("unexpected error: %v", err) + } + if cfg.Telemetry.Endpoint != "https://apm.example.com:8200" { + t.Errorf("endpoint = %q, want https://apm.example.com:8200", cfg.Telemetry.Endpoint) + } + if got := cfg.Telemetry.Headers["Authorization"]; got != "Bearer secret" { + t.Errorf("Authorization header = %q, want %q", got, "Bearer secret") + } +} diff --git a/docs/config.md b/docs/config.md index e3e29268..72895ef7 100644 --- a/docs/config.md +++ b/docs/config.md @@ -18,6 +18,7 @@ An optional `.gitte-override.yml` in the same directory is deep-merged on top, u - [searchFor](#searchfor) - [feature\_gates](#feature_gates) - [sources](#sources) +- [telemetry](#telemetry) - [Remote configuration](#remote-configuration) --- @@ -34,6 +35,7 @@ sources: # auto-discovery sources (optional) searchFor: # global output pattern matching (optional) actionOverride: # per-action overrides (optional) retry: # global retry defaults (optional) +telemetry: # OpenTelemetry trace export (optional) ``` --- @@ -406,6 +408,42 @@ gitte run up --discover # discover, then sync, then run actions --- +## telemetry + +Gitte can export OpenTelemetry traces over OTLP/HTTP to an OTLP-compatible backend (e.g. Elastic APM) to help debug failures. Telemetry is enabled whenever an endpoint is resolved. + +```yaml +telemetry: + endpoint: https://apm.example.com:8200 # OTLP/HTTP endpoint + headers: # arbitrary export headers (optional) + Authorization: "Bearer " # or: "ApiKey " +``` + +| Field | Description | +|-------|-------------| +| `endpoint` | OTLP/HTTP endpoint to export spans to. Telemetry is enabled when this resolves to a non-empty value. | +| `headers` | Map of HTTP headers attached to every export request — typically authentication (`Authorization`). | + +Each invocation produces one trace: a root span for the command, child spans for each repo sync (branch, commit SHA, dirty flag) and each action task (command, exit code), with errors recorded on the relevant span. The OS username (`user.name`) and hostname (`host.name`) are attached to every trace to identify which developer and machine produced it. + +The gitte CLI arguments and each action's command line are exported as span attributes. gitte's injected environment — a project's `env`, `env_when`, and feature-gate env — is also exported (the `gitte.env` span attribute and the task logs); the inherited process environment (`os.Environ`) is not. Keep secrets out of action command definitions, CLI arguments, and config `env`/feature-gate blocks — pass real secrets through the process environment instead. Full remote URLs are never collected (repos are identified by name only). + +Environment variables override or disable telemetry: + +| Variable | Effect | +|----------|--------| +| `GITTE_TELEMETRY=off` | Disable telemetry locally (kill-switch) | +| `GITTE_TELEMETRY_URL` | Override the endpoint | +| `GITTE_TELEMETRY_LOGS=off` | Disable OTEL log export (keep traces) | +| `OTEL_EXPORTER_OTLP_ENDPOINT` / `OTEL_EXPORTER_OTLP_HEADERS` | Standard OTEL env vars, honored as a fallback when no gitte endpoint is set | + +Precedence: `GITTE_TELEMETRY=off` > `GITTE_TELEMETRY_URL` > config `endpoint` > `OTEL_EXPORTER_OTLP_*`. Telemetry is best-effort and never blocks or slows gitte; export failures are silently ignored and flushing on exit is time-bounded. + +Action and startup command output is also exported as OTEL logs (correlated to +the producing span) unless `GITTE_TELEMETRY_LOGS=off`. + +--- + ## Remote configuration Gitte can load its configuration from a remote git repository. Create a `.gitte-env` file alongside `.gitte.yml`: diff --git a/executor/executor.go b/executor/executor.go index fe2269a0..0d859999 100644 --- a/executor/executor.go +++ b/executor/executor.go @@ -4,6 +4,7 @@ import ( "context" "errors" "fmt" + "runtime/debug" "strconv" "strings" "time" @@ -244,7 +245,7 @@ func (e *Executor) startReadyTasks(ctx context.Context, completionCh chan<- Comm } handler := ToChannelOutputHandler{OutputCh: outputCh} - err := r.task.ExecuteFn(ctx, r.task.Name, handler) + err := executeTask(ctx, r.task, handler) elapsed := time.Since(r.startedAt) if err != nil { @@ -276,6 +277,15 @@ func (e *Executor) startReadyTasks(ctx context.Context, completionCh chan<- Comm return nil } +func executeTask(ctx context.Context, task Task, handler OutputHandler) (err error) { + defer func() { + if recovered := recover(); recovered != nil { + err = &PanicError{Task: task.Name, Value: recovered, Stack: debug.Stack()} + } + }() + return task.ExecuteFn(ctx, task.Name, handler) +} + // resetForRetry re-queues the named failed tasks and cascades to any skipped dependents. // Returns the number of tasks reset (caller must decrement its finished counter by this amount). func (e *Executor) resetForRetry(names []string) int { diff --git a/executor/executor_test.go b/executor/executor_test.go index 9c405592..8823fbb7 100644 --- a/executor/executor_test.go +++ b/executor/executor_test.go @@ -152,6 +152,27 @@ func TestExecutor_TaskFailureSkipsDependents(t *testing.T) { } } +func TestExecutor_TaskPanicBecomesError(t *testing.T) { + tasks := []Task{{ + Name: "panicking", + ExecuteFn: func(context.Context, string, OutputHandler) error { + panic("boom") + }, + }} + exec, err := NewExecutor(tasks, ExecutorOptions{}) + if err != nil { + t.Fatalf("NewExecutor() error = %v", err) + } + err = exec.Execute(context.Background()) + var panicErr *PanicError + if !errors.As(err, &panicErr) { + t.Fatalf("Execute() error = %v, want PanicError", err) + } + if panicErr.Value != "boom" || len(panicErr.Stack) == 0 { + t.Fatalf("PanicError = %+v", panicErr) + } +} + func TestExecutor_SkippedErrorWrapsErrTaskSkipped(t *testing.T) { var skippedErr error tasks := []Task{ diff --git a/executor/types.go b/executor/types.go index 5e6560c3..0908b53c 100644 --- a/executor/types.go +++ b/executor/types.go @@ -2,6 +2,7 @@ package executor import ( "context" + "fmt" "time" ) @@ -83,3 +84,15 @@ type CommandResult struct { Success bool Error error } + +// PanicError converts a task-worker panic into an error so executor output and +// telemetry can drain before the failure reaches the command root. +type PanicError struct { + Task string + Value any + Stack []byte +} + +func (e *PanicError) Error() string { + return fmt.Sprintf("task %s panicked: %v\n%s", e.Task, e.Value, e.Stack) +} diff --git a/gitops/gitops.go b/gitops/gitops.go index 20cb5959..4ab32ae9 100644 --- a/gitops/gitops.go +++ b/gitops/gitops.go @@ -18,6 +18,11 @@ import ( "github.com/cego/gitte/config" "github.com/cego/gitte/executor" "github.com/cego/gitte/output" + "github.com/cego/gitte/telemetry" + + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/codes" + "go.opentelemetry.io/otel/trace" ) // parallelLimit returns the effective parallelization cap for gitops clone/pull @@ -182,10 +187,20 @@ func syncProject( setDetail func(string), addPrompt func(CheckoutPrompt), warnFn func(string), -) error { - localDir, err := config.LocalDirForRemote(proj.Remote) - if err != nil { - return err +) (err error) { + ctx, span := telemetry.Tracer().Start(ctx, "gitops.sync "+name) + span.SetAttributes(attribute.String("gitte.repo", name)) + defer func() { + if err != nil { + span.RecordError(err) + span.SetStatus(codes.Error, err.Error()) + } + span.End() + }() + + localDir, lerr := config.LocalDirForRemote(proj.Remote) + if lerr != nil { + return lerr } projectPath := filepath.Join(cwd, localDir) @@ -245,6 +260,11 @@ func syncProject( if err != nil { return err } + // Guard on IsRecording so getHeadSHA (a git exec) never runs when telemetry + // is disabled — the span is non-recording and would discard the attributes. + if span.IsRecording() { + setGitContextAttrs(span, currentBranch, getHeadSHA(ctx, projectPath), dirty) + } if dirty { setDetail("skipped") if currentBranch != defaultBranch { @@ -407,6 +427,26 @@ func staleDays(ctx context.Context, dir, defaultBranch string) int { return 0 } +// setGitContextAttrs records git context on a span. The caller sets gitte.repo +// separately (the repo name/path, never the full remote URL which can embed +// credentials) so it is present on every span, including early-return paths. +func setGitContextAttrs(span trace.Span, branch, sha string, dirty bool) { + span.SetAttributes( + attribute.String("git.branch", branch), + attribute.String("git.sha", sha), + attribute.Bool("git.dirty", dirty), + ) +} + +// getHeadSHA returns the short HEAD commit SHA, or "" if it cannot be determined. +func getHeadSHA(ctx context.Context, dir string) string { + res, err := executor.ExecuteSyncInDir(ctx, dir, "git", "rev-parse", "--short", "HEAD") + if err != nil || res.ExitCode != 0 { + return "" + } + return strings.TrimSpace(string(res.Stdout)) +} + // ── git helpers ────────────────────────────────────────────────────────────── const fetchTimeout = 60 * time.Second diff --git a/gitops/telemetry_test.go b/gitops/telemetry_test.go new file mode 100644 index 00000000..0269fc9f --- /dev/null +++ b/gitops/telemetry_test.go @@ -0,0 +1,45 @@ +package gitops + +import ( + "context" + "testing" + + "go.opentelemetry.io/otel" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" +) + +func TestSetGitContextAttrs(t *testing.T) { + exp := tracetest.NewInMemoryExporter() + tp := sdktrace.NewTracerProvider(sdktrace.WithSyncer(exp)) + prev := otel.GetTracerProvider() + otel.SetTracerProvider(tp) + t.Cleanup(func() { + otel.SetTracerProvider(prev) + _ = tp.Shutdown(context.Background()) + }) + + _, span := tp.Tracer("test").Start(context.Background(), "gitops.sync") + setGitContextAttrs(span, "main", "abc123", true) + span.End() + + spans := exp.GetSpans() + if len(spans) != 1 { + t.Fatalf("got %d spans, want 1", len(spans)) + } + attrs := map[string]string{} + dirty := false + for _, kv := range spans[0].Attributes { + switch kv.Key { + case "git.branch": + attrs["branch"] = kv.Value.AsString() + case "git.sha": + attrs["sha"] = kv.Value.AsString() + case "git.dirty": + dirty = kv.Value.AsBool() + } + } + if attrs["branch"] != "main" || attrs["sha"] != "abc123" || !dirty { + t.Fatalf("attrs = %+v dirty=%v", attrs, dirty) + } +} diff --git a/go.mod b/go.mod index 07bf703c..73ceab5f 100644 --- a/go.mod +++ b/go.mod @@ -11,11 +11,20 @@ require ( github.com/samber/lo v1.53.0 github.com/spf13/cobra v1.10.2 github.com/zalando/go-keyring v0.2.8 - golang.org/x/term v0.42.0 + go.opentelemetry.io/otel v1.44.0 + go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploghttp v0.20.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/term v0.43.0 gopkg.in/yaml.v3 v3.0.1 ) require ( + github.com/cenkalti/backoff/v5 v5.0.3 // indirect + github.com/cespare/xxhash/v2 v2.3.0 // indirect github.com/charmbracelet/colorprofile v0.4.3 // indirect github.com/charmbracelet/ultraviolet v0.0.0-20260413211237-bd52878bcec2 // indirect github.com/charmbracelet/x/ansi v0.11.7 // indirect @@ -25,7 +34,11 @@ require ( github.com/clipperhouse/displaywidth v0.11.0 // indirect github.com/clipperhouse/uax29/v2 v2.7.0 // indirect github.com/danieljoos/wincred v1.2.3 // indirect + github.com/go-logr/logr v1.4.3 // indirect + github.com/go-logr/stdr v1.2.2 // indirect github.com/godbus/dbus/v5 v5.2.2 // indirect + github.com/google/uuid v1.6.0 // indirect + github.com/grpc-ecosystem/grpc-gateway/v2 v2.29.0 // indirect github.com/inconshreveable/mousetrap v1.1.0 // indirect github.com/lucasb-eyer/go-colorful v1.4.0 // indirect github.com/mattn/go-runewidth v0.0.23 // indirect @@ -33,7 +46,16 @@ require ( github.com/rivo/uniseg v0.4.7 // indirect github.com/spf13/pflag v1.0.9 // indirect github.com/xo/terminfo v0.0.0-20220910002029-abceb7e1c41e // indirect + go.opentelemetry.io/auto/sdk v1.2.1 // indirect + go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.44.0 // indirect + go.opentelemetry.io/otel/metric v1.44.0 // indirect + go.opentelemetry.io/proto/otlp v1.10.0 // indirect + golang.org/x/net v0.55.0 // indirect golang.org/x/sync v0.20.0 // indirect - golang.org/x/sys v0.43.0 // indirect - golang.org/x/text v0.22.0 // indirect + golang.org/x/sys v0.45.0 // indirect + golang.org/x/text v0.37.0 // indirect + google.golang.org/genproto/googleapis/api v0.0.0-20260526163538-3dc84a4a5aaa // indirect + google.golang.org/genproto/googleapis/rpc v0.0.0-20260526163538-3dc84a4a5aaa // indirect + google.golang.org/grpc v1.81.1 // indirect + google.golang.org/protobuf v1.36.11 // indirect ) diff --git a/go.sum b/go.sum index 7932f2f8..bcedc2f8 100644 --- a/go.sum +++ b/go.sum @@ -6,6 +6,10 @@ github.com/aymanbagabas/go-osc52/v2 v2.0.1 h1:HwpRHbFMcZLEVr42D4p7XBqjyuxQH5SMiE github.com/aymanbagabas/go-osc52/v2 v2.0.1/go.mod h1:uYgXzlJ7ZpABp8OJ+exZzJJhRNQ2ASbcXHWsFqH8hp8= github.com/aymanbagabas/go-udiff v0.4.1 h1:OEIrQ8maEeDBXQDoGCbbTTXYJMYRCRO1fnodZ12Gv5o= github.com/aymanbagabas/go-udiff v0.4.1/go.mod h1:0L9PGwj20lrtmEMeyw4WKJ/TMyDtvAoK9bf2u/mNo3w= +github.com/cenkalti/backoff/v5 v5.0.3 h1:ZN+IMa753KfX5hd8vVaMixjnqRZ3y8CuJKRKj1xcsSM= +github.com/cenkalti/backoff/v5 v5.0.3/go.mod h1:rkhZdG3JZukswDf7f0cwqPNk4K0sa+F97BxZthm/crw= +github.com/cespare/xxhash/v2 v2.3.0 h1:UL815xU9SqsFlibzuggzjXhog7bL6oX9BbNZnL2UFvs= +github.com/cespare/xxhash/v2 v2.3.0/go.mod h1:VGX0DQ3Q6kWi7AoAeZDth3/j3BFtOZR5XLFGgcrjCOs= github.com/charmbracelet/colorprofile v0.4.3 h1:QPa1IWkYI+AOB+fE+mg/5/4HRMZcaXex9t5KX76i20Q= github.com/charmbracelet/colorprofile v0.4.3/go.mod h1:/zT4BhpD5aGFpqQQqw7a+VtHCzu+zrQtt1zhMt9mR4Q= github.com/charmbracelet/ultraviolet v0.0.0-20260413211237-bd52878bcec2 h1:mRAlb/WARLaCnCwAEBa8Zfk965GrYc414MhJamV4anw= @@ -29,14 +33,31 @@ github.com/danieljoos/wincred v1.2.3 h1:v7dZC2x32Ut3nEfRH+vhoZGvN72+dQ/snVXo/vMF github.com/danieljoos/wincred v1.2.3/go.mod h1:6qqX0WNrS4RzPZ1tnroDzq9kY3fu1KwE7MRLQK4X0bs= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= +github.com/go-logr/logr v1.4.3 h1:CjnDlHq8ikf6E492q6eKboGOC0T8CDaOvkHCIg8idEI= +github.com/go-logr/logr v1.4.3/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= +github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= +github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= github.com/goccy/go-yaml v1.19.2 h1:PmFC1S6h8ljIz6gMRBopkjP1TVT7xuwrButHID66PoM= github.com/goccy/go-yaml v1.19.2/go.mod h1:XBurs7gK8ATbW4ZPGKgcbrY1Br56PdM69F7LkFRi1kA= github.com/godbus/dbus/v5 v5.2.2 h1:TUR3TgtSVDmjiXOgAAyaZbYmIeP3DPkld3jgKGV8mXQ= github.com/godbus/dbus/v5 v5.2.2/go.mod h1:3AAv2+hPq5rdnr5txxxRwiGjPXamgoIHgz9FPBfOp3c= +github.com/golang/protobuf v1.5.4 h1:i7eJL8qZTpSEXOPTxNKhASYpMn+8e5Q6AdndVa1dWek= +github.com/golang/protobuf v1.5.4/go.mod h1:lnTiLA8Wa4RWRcIUkrtSVa5nRhsEGBg48fD6rSs7xps= +github.com/google/go-cmp v0.7.0 h1:wk8382ETsv4JYUZwIsn6YpYiWiBsYLSJiTsyBybVuN8= +github.com/google/go-cmp v0.7.0/go.mod h1:pXiqmnSA92OHEEa9HXL2W4E7lf9JzCmGVUdgjX3N/iU= +github.com/google/uuid v1.6.0 h1:NIvaJDMOsjHA8n1jAhLSgzrAzy1Hgr+hNrb57e+94F0= +github.com/google/uuid v1.6.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= +github.com/grpc-ecosystem/grpc-gateway/v2 v2.29.0 h1:5VipnvEpbqr2gA2VbM+nYVbkIF28c5ZQfqCBQ5g2xfk= +github.com/grpc-ecosystem/grpc-gateway/v2 v2.29.0/go.mod h1:Hyl3n6Twe1hvtd9XUXDec4pTvgMSEixRuQKPTMH2bNs= github.com/inconshreveable/mousetrap v1.1.0 h1:wN+x4NVGpMsO7ErUn/mUI3vEoE6Jt13X2s0bqwp9tc8= github.com/inconshreveable/mousetrap v1.1.0/go.mod h1:vpF70FUmC8bwa3OWnCshd2FqLfsEA9PFc4w1p2J65bw= github.com/joho/godotenv v1.5.1 h1:7eLL/+HRGLY0ldzfGMeQkb7vMd0as4CfYvUVzLqw0N0= github.com/joho/godotenv v1.5.1/go.mod h1:f4LDr5Voq0i2e/R5DDNOoa2zzDfwtkZa6DnEwAbqwq4= +github.com/kr/pretty v0.3.1 h1:flRD4NNwYAUpkphVc1HcthR4KEIFJ65n8Mw5qdRn3LE= +github.com/kr/pretty v0.3.1/go.mod h1:hoEshYVHaxMs3cyo3Yncou5ZscifuDolrwPKZanG3xk= +github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= +github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= github.com/lucasb-eyer/go-colorful v1.4.0 h1:UtrWVfLdarDgc44HcS7pYloGHJUjHV/4FwW4TvVgFr4= github.com/lucasb-eyer/go-colorful v1.4.0/go.mod h1:R4dSotOR9KMtayYi1e77YzuveK+i7ruzyGqttikkLy0= github.com/mattn/go-runewidth v0.0.23 h1:7ykA0T0jkPpzSvMS5i9uoNn2Xy3R383f9HDx3RybWcw= @@ -47,6 +68,8 @@ github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZb github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/rivo/uniseg v0.4.7 h1:WUdvkW8uEhrYfLC4ZzdpI2ztxP1I582+49Oc5Mq64VQ= github.com/rivo/uniseg v0.4.7/go.mod h1:FN3SvrM+Zdj16jyLfmOkMNblXMcoc8DfTHruCPUcx88= +github.com/rogpeppe/go-internal v1.14.1 h1:UQB4HGPB6osV0SQTLymcB4TgvyWu6ZyliaW0tI/otEQ= +github.com/rogpeppe/go-internal v1.14.1/go.mod h1:MaRKkUm5W0goXpeCfT7UZI6fk/L7L7so1lCWt35ZSgc= github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= github.com/samber/lo v1.53.0 h1:t975lj2py4kJPQ6haz1QMgtId2gtmfktACxIXArw3HM= github.com/samber/lo v1.53.0/go.mod h1:4+MXEGsJzbKGaUEQFKBq2xtfuznW9oz/WrgyzMzRoM0= @@ -62,18 +85,59 @@ github.com/xo/terminfo v0.0.0-20220910002029-abceb7e1c41e h1:JVG44RsyaB9T2KIHavM github.com/xo/terminfo v0.0.0-20220910002029-abceb7e1c41e/go.mod h1:RbqR21r5mrJuqunuUZ/Dhy/avygyECGrLceyNeo4LiM= github.com/zalando/go-keyring v0.2.8 h1:6sD/Ucpl7jNq10rM2pgqTs0sZ9V3qMrqfIIy5YPccHs= github.com/zalando/go-keyring v0.2.8/go.mod h1:tsMo+VpRq5NGyKfxoBVjCuMrG47yj8cmakZDO5QGii0= +go.opentelemetry.io/auto/sdk v1.2.1 h1:jXsnJ4Lmnqd11kwkBV2LgLoFMZKizbCi5fNZ/ipaZ64= +go.opentelemetry.io/auto/sdk v1.2.1/go.mod h1:KRTj+aOaElaLi+wW1kO/DZRXwkF4C5xPbEe3ZiIhN7Y= +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/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/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= +go.opentelemetry.io/otel/trace v1.44.0/go.mod h1:oLl1jrMQAVo6v3GAggN+1VH9VIz9iUSvW53sW1Q8PIE= +go.opentelemetry.io/proto/otlp v1.10.0 h1:IQRWgT5srOCYfiWnpqUYz9CVmbO8bFmKcwYxpuCSL2g= +go.opentelemetry.io/proto/otlp v1.10.0/go.mod h1:/CV4QoCR/S9yaPj8utp3lvQPoqMtxXdzn7ozvvozVqk= +go.uber.org/goleak v1.3.0 h1:2K3zAYmnTNqV73imy9J1T3WC+gmCePx2hEGkimedGto= +go.uber.org/goleak v1.3.0/go.mod h1:CoHD4mav9JJNrW/WLlf7HGZPjdw8EucARQHekz1X6bE= go.yaml.in/yaml/v3 v3.0.4/go.mod h1:DhzuOOF2ATzADvBadXxruRBLzYTpT36CKvDb3+aBEFg= golang.org/x/exp v0.0.0-20231006140011-7918f672742d h1:jtJma62tbqLibJ5sFQz8bKtEM8rJBtfilJ2qTU199MI= golang.org/x/exp v0.0.0-20231006140011-7918f672742d/go.mod h1:ldy0pHrwJyGW56pPQzzkH36rKxoZW1tw7ZJpeKx+hdo= +golang.org/x/net v0.55.0 h1:bcvxaJn3e1U6InsFWt1JUq1aSjnRxLzT2rtD2KfkDF8= +golang.org/x/net v0.55.0/go.mod h1:L5U2KuzuOe1lY7Z+aWVIKK6qEeJXnXV9yzGA+WCHJww= golang.org/x/sync v0.20.0 h1:e0PTpb7pjO8GAtTs2dQ6jYa5BWYlMuX047Dco/pItO4= golang.org/x/sync v0.20.0/go.mod h1:9xrNwdLfx4jkKbNva9FpL6vEN7evnE43NNNJQ2LF3+0= -golang.org/x/sys v0.43.0 h1:Rlag2XtaFTxp19wS8MXlJwTvoh8ArU6ezoyFsMyCTNI= -golang.org/x/sys v0.43.0/go.mod h1:4GL1E5IUh+htKOUEOaiffhrAeqysfVGipDYzABqnCmw= -golang.org/x/term v0.42.0 h1:UiKe+zDFmJobeJ5ggPwOshJIVt6/Ft0rcfrXZDLWAWY= -golang.org/x/term v0.42.0/go.mod h1:Dq/D+snpsbazcBG5+F9Q1n2rXV8Ma+71xEjTRufARgY= -golang.org/x/text v0.22.0 h1:bofq7m3/HAFvbF51jz3Q9wLg3jkvSPuiZu/pD1XwgtM= -golang.org/x/text v0.22.0/go.mod h1:YRoo4H8PVmsu+E3Ou7cqLVH8oXWIHVoX0jqUWALQhfY= -gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= +golang.org/x/sys v0.45.0 h1:dO4czNzziLiiXplLQgBCEpCvXQ3dnkn0SdaZSYdQ+FY= +golang.org/x/sys v0.45.0/go.mod h1:4GL1E5IUh+htKOUEOaiffhrAeqysfVGipDYzABqnCmw= +golang.org/x/term v0.43.0 h1:S4RLU2sB31O/NCl+zFN9Aru9A/Cq2aqKpTZJ6B+DwT4= +golang.org/x/term v0.43.0/go.mod h1:lrhlHNdQJHO+1qVYiHfFKVuVioJIheAc3fBSMFYEIsk= +golang.org/x/text v0.37.0 h1:Cqjiwd9eSg8e0QAkyCaQTNHFIIzWtidPahFWR83rTrc= +golang.org/x/text v0.37.0/go.mod h1:a5sjxXGs9hsn/AJVwuElvCAo9v8QYLzvavO5z2PiM38= +gonum.org/v1/gonum v0.17.0 h1:VbpOemQlsSMrYmn7T2OUvQ4dqxQXU+ouZFQsZOx50z4= +gonum.org/v1/gonum v0.17.0/go.mod h1:El3tOrEuMpv2UdMrbNlKEh9vd86bmQ6vqIcDwxEOc1E= +google.golang.org/genproto/googleapis/api v0.0.0-20260526163538-3dc84a4a5aaa h1:Kjn0N0tCrDgiAFW+lGO4JZ3ck44CehvJQMAwj9QF0G8= +google.golang.org/genproto/googleapis/api v0.0.0-20260526163538-3dc84a4a5aaa/go.mod h1:q4lMZS6kskjT5HvCPrnnypcDPVJqT/f4nfxmkE7gryY= +google.golang.org/genproto/googleapis/rpc v0.0.0-20260526163538-3dc84a4a5aaa h1:mZHHdPZl0dbGHCflZgAq/Q468DWVFcU2whhB2KAo8fk= +google.golang.org/genproto/googleapis/rpc v0.0.0-20260526163538-3dc84a4a5aaa/go.mod h1:4Hqkh8ycfw05ld/3BWL7rJOSfebL2Q+DVDeRgYgxUU8= +google.golang.org/grpc v1.81.1 h1:VnnIIZ88UzOOKLukQi+ImGz8O1Wdp8nAGGnvOfEIWQQ= +google.golang.org/grpc v1.81.1/go.mod h1:xGH9GfzOyMTGIOXBJmXt+BX/V0kcdQbdcuwQ/zNw42I= +google.golang.org/protobuf v1.36.11 h1:fV6ZwhNocDyBLK0dj+fg8ektcVegBBuEolpbTQyBNVE= +google.golang.org/protobuf v1.36.11/go.mod h1:HTf+CrKn2C3g5S8VImy6tdcUvCska2kB7j23XfzDpco= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c h1:Hei/4ADfdWqJk1ZMxUNpqntNwaWcugrBjAiHlqqRiVk= +gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EVd6muEfDQjcINNoR0C8j2r3qZ4Q= gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/startup/startup.go b/startup/startup.go index cf00dcb5..f2a7e790 100644 --- a/startup/startup.go +++ b/startup/startup.go @@ -4,11 +4,15 @@ import ( "context" "errors" "fmt" + "io" "sort" "github.com/cego/gitte/config" "github.com/cego/gitte/executor" "github.com/cego/gitte/output" + "github.com/cego/gitte/telemetry" + "go.opentelemetry.io/otel/codes" + "go.opentelemetry.io/otel/trace" ) // Run executes all startup checks and streams status to stdout. @@ -28,13 +32,31 @@ func Run(ctx context.Context, cfg *config.GitteConfig, cwd string, mode output.O tasks = append(tasks, executor.Task{ Name: name, Needs: check.GetNeeds(), - ExecuteFn: func(ctx context.Context, taskName string, handler executor.OutputHandler) error { - if err := check.Check(ctx, cwd); err != nil { + ExecuteFn: func(ctx context.Context, taskName string, handler executor.OutputHandler) (err error) { + ctx, span := startCheckSpan(ctx, taskName) + defer func() { + if recovered := recover(); recovered != nil { + panicErr := fmt.Errorf("panic: %v", recovered) + span.RecordError(panicErr) + span.SetStatus(codes.Error, panicErr.Error()) + span.End() + panic(recovered) + } + if err != nil { + span.RecordError(err) + span.SetStatus(codes.Error, err.Error()) + } + span.End() + }() + logHandler := telemetry.LogOutputHandler(handler) + stdout := &handlerWriter{ctx: ctx, handler: logHandler, taskName: taskName, stream: executor.StdoutStream} + stderr := &handlerWriter{ctx: ctx, handler: logHandler, taskName: taskName, stream: executor.StderrStream} + if cerr := check.Check(ctx, cwd, stdout, stderr); cerr != nil { hint := check.GetHint() if hint != "" { - return fmt.Errorf("%s\nhint: %s", err.Error(), hint) + return fmt.Errorf("%s\nhint: %s", cerr.Error(), hint) } - return err + return cerr } return nil }, @@ -51,7 +73,6 @@ func Run(ctx context.Context, cfg *config.GitteConfig, cwd string, mode output.O if err != nil { return fmt.Errorf("startup checks have invalid dependencies: %w", err) } - runErr := exec.Execute(ctx) view.Wait() if runErr != nil && mode != output.ModePlain { @@ -62,6 +83,32 @@ func Run(ctx context.Context, cfg *config.GitteConfig, cwd string, mode output.O return runErr } +// handlerWriter adapts startup checks using io.Writer to executor output while +// retaining the check span in the context used for correlated OTEL logs. +type handlerWriter struct { + ctx context.Context + handler executor.OutputHandler + taskName string + stream executor.StreamType +} + +var _ io.Writer = (*handlerWriter)(nil) + +func (w *handlerWriter) Write(p []byte) (int, error) { + line := append([]byte(nil), p...) + _ = w.handler.HandleOutput(w.ctx, executor.Output{ + Output: line, + CmdName: w.taskName, + Stream: w.stream, + }) + return len(p), nil +} + +// startCheckSpan opens a span for a single startup check. +func startCheckSpan(ctx context.Context, name string) (context.Context, trace.Span) { + return telemetry.Tracer().Start(ctx, "startup.check "+name) +} + // newView picks the right view implementation based on output mode. func newView(mode output.OutputMode, tasks []executor.Task, cancel context.CancelFunc) View { if mode == output.ModePlain { diff --git a/startup/startup_test.go b/startup/startup_test.go new file mode 100644 index 00000000..1882d134 --- /dev/null +++ b/startup/startup_test.go @@ -0,0 +1,83 @@ +package startup + +import ( + "context" + "sync" + "testing" + + "github.com/cego/gitte/config" + "github.com/cego/gitte/output" + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/log/global" + sdklog "go.opentelemetry.io/otel/sdk/log" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" +) + +func TestStartCheckSpan_RecordsNamedSpan(t *testing.T) { + exp := tracetest.NewInMemoryExporter() + tp := sdktrace.NewTracerProvider(sdktrace.WithSyncer(exp)) + prev := otel.GetTracerProvider() + otel.SetTracerProvider(tp) + t.Cleanup(func() { otel.SetTracerProvider(prev); _ = tp.Shutdown(context.Background()) }) + + ctx, span := startCheckSpan(context.Background(), "git-present") + span.End() + _ = ctx + + spans := exp.GetSpans() + if len(spans) != 1 || spans[0].Name != "startup.check git-present" { + t.Fatalf("got %+v, want one span named 'startup.check git-present'", spans) + } +} + +type startupLogExporter struct { + mu sync.Mutex + records []sdklog.Record +} + +func (e *startupLogExporter) Export(_ context.Context, records []sdklog.Record) error { + e.mu.Lock() + defer e.mu.Unlock() + for _, record := range records { + e.records = append(e.records, record.Clone()) + } + return nil +} + +func (*startupLogExporter) Shutdown(context.Context) error { return nil } +func (*startupLogExporter) ForceFlush(context.Context) error { return nil } + +func TestRun_ExportsStartupCommandOutputWithSpanCorrelation(t *testing.T) { + logExp := &startupLogExporter{} + lp := sdklog.NewLoggerProvider(sdklog.WithProcessor(sdklog.NewSimpleProcessor(logExp))) + prevLP := global.GetLoggerProvider() + global.SetLoggerProvider(lp) + t.Cleanup(func() { global.SetLoggerProvider(prevLP); _ = lp.Shutdown(context.Background()) }) + + spanExp := tracetest.NewInMemoryExporter() + tp := sdktrace.NewTracerProvider(sdktrace.WithSyncer(spanExp)) + prevTP := otel.GetTracerProvider() + otel.SetTracerProvider(tp) + t.Cleanup(func() { otel.SetTracerProvider(prevTP); _ = tp.Shutdown(context.Background()) }) + + cfg := &config.GitteConfig{StartupChecks: config.StartupCheckMap{ + "output-check": &config.ShellStartupCheck{ + BaseStartupCheck: config.BaseStartupCheck{Type: "shell"}, + Shell: "sh", + Script: "printf stdout-line; printf stderr-line >&2", + }, + }} + if err := Run(context.Background(), cfg, t.TempDir(), output.ModePlain); err != nil { + t.Fatalf("Run() error = %v", err) + } + + if len(logExp.records) != 2 { + t.Fatalf("exported %d startup log records, want 2", len(logExp.records)) + } + for _, record := range logExp.records { + if !record.TraceID().IsValid() || !record.SpanID().IsValid() { + t.Fatalf("startup log is not span-correlated: trace=%s span=%s", record.TraceID(), record.SpanID()) + } + } +} diff --git a/telemetry/action_tracker.go b/telemetry/action_tracker.go new file mode 100644 index 00000000..6eef1ade --- /dev/null +++ b/telemetry/action_tracker.go @@ -0,0 +1,98 @@ +package telemetry + +import ( + "context" + "strings" + "sync" + + "go.opentelemetry.io/otel/codes" + "go.opentelemetry.io/otel/trace" +) + +// ActionTracker opens one span per action (e.g. "build", "up") under the +// actions phase context, driven by the executor's task hooks. An action span +// opens on its first task start and closes when its last task finishes. +type ActionTracker struct { + phaseCtx context.Context + mu sync.Mutex + spans map[string]trace.Span // action -> span + ctxs map[string]context.Context // action -> span context + active map[string]int // action -> live task count + started map[string]struct{} // tasks that have called OnStart +} + +// NewActionTracker creates a tracker rooted at the actions phase context. +func NewActionTracker(phaseCtx context.Context) *ActionTracker { + return &ActionTracker{ + phaseCtx: phaseCtx, + spans: map[string]trace.Span{}, + ctxs: map[string]context.Context{}, + active: map[string]int{}, + started: map[string]struct{}{}, + } +} + +// ActionOf extracts the action name from a "project:action:group" task name. +func ActionOf(taskName string) string { + parts := strings.Split(taskName, ":") + if len(parts) >= 2 { + return parts[1] // project:action:group + } + return taskName +} + +// OnStart opens the action span if needed and increments its live-task count. +func (t *ActionTracker) OnStart(taskName string) { + action := ActionOf(taskName) + t.mu.Lock() + defer t.mu.Unlock() + if _, ok := t.spans[action]; !ok { + ctx, span := Tracer().Start(t.phaseCtx, action) + t.spans[action] = span + t.ctxs[action] = ctx + } + t.started[taskName] = struct{}{} + t.active[action]++ +} + +// OnFinish decrements the live-task count and ends the action span at zero. +// A non-nil err is recorded on the action span so failure surfaces at the +// action level too. If the task never called OnStart (e.g. it was skipped due +// to a failed dependency), this is a no-op to avoid corrupting the active count. +func (t *ActionTracker) OnFinish(taskName string, err error) { + t.mu.Lock() + defer t.mu.Unlock() + if _, ok := t.started[taskName]; !ok { + return // skipped task — no matching OnStart, nothing to do + } + delete(t.started, taskName) + action := ActionOf(taskName) + // Propagate a failed task onto its action span so failure shows at every + // level of the trace, not just on the task span. + if err != nil { + if span, ok := t.spans[action]; ok { + span.RecordError(err) + span.SetStatus(codes.Error, err.Error()) + } + } + t.active[action]-- + if t.active[action] <= 0 { + if span, ok := t.spans[action]; ok { + span.End() + delete(t.spans, action) + delete(t.ctxs, action) + delete(t.active, action) + } + } +} + +// ActionContext returns the action span's context, or the phase context if the +// action span is not open. +func (t *ActionTracker) ActionContext(action string) context.Context { + t.mu.Lock() + defer t.mu.Unlock() + if ctx, ok := t.ctxs[action]; ok { + return ctx + } + return t.phaseCtx +} diff --git a/telemetry/action_tracker_test.go b/telemetry/action_tracker_test.go new file mode 100644 index 00000000..e3881f61 --- /dev/null +++ b/telemetry/action_tracker_test.go @@ -0,0 +1,118 @@ +package telemetry + +import ( + "context" + "errors" + "testing" + + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/codes" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" +) + +func TestActionTracker_SpanPerAction(t *testing.T) { + exp := tracetest.NewInMemoryExporter() + tp := sdktrace.NewTracerProvider(sdktrace.WithSyncer(exp)) + prev := otel.GetTracerProvider() + otel.SetTracerProvider(tp) + t.Cleanup(func() { otel.SetTracerProvider(prev); _ = tp.Shutdown(context.Background()) }) + + tr := NewActionTracker(context.Background()) + tr.OnStart("a:build:sn") + tr.OnStart("b:build:sn") + tr.OnFinish("a:build:sn", nil) + tr.OnFinish("b:build:sn", nil) // last build task -> build span ends + tr.OnStart("a:up:sn") + tr.OnFinish("a:up:sn", nil) // up span ends + + names := map[string]int{} + for _, s := range exp.GetSpans() { + names[s.Name]++ + } + if names["build"] != 1 || names["up"] != 1 { + t.Fatalf("want one build and one up span, got %v", names) + } +} + +func TestActionTracker_SkippedTaskDoesNotCloseSpan(t *testing.T) { + exp := tracetest.NewInMemoryExporter() + tp := sdktrace.NewTracerProvider(sdktrace.WithSyncer(exp)) + prev := otel.GetTracerProvider() + otel.SetTracerProvider(tp) + t.Cleanup(func() { otel.SetTracerProvider(prev); _ = tp.Shutdown(context.Background()) }) + + tr := NewActionTracker(context.Background()) + + // Two real tasks start. + tr.OnStart("a:build:sn") + tr.OnStart("b:build:sn") + + // A skipped task (never started) fires OnFinish — must be a no-op. + tr.OnFinish("c:build:sn", nil) + + // Action span must still be open: ActionContext returns the action's own + // context (not the phase/background context), and no "build" span exported. + ctxAfterSkip := tr.ActionContext("build") + if ctxAfterSkip == context.Background() { + t.Fatal("action span was prematurely closed by skipped task's OnFinish") + } + if n := countSpans(exp, "build"); n != 0 { + t.Fatalf("want 0 exported build spans after skipped OnFinish, got %d", n) + } + + // One real task finishes — span still open because b:build:sn is active. + tr.OnFinish("a:build:sn", nil) + if n := countSpans(exp, "build"); n != 0 { + t.Fatalf("want 0 exported build spans after first real OnFinish, got %d", n) + } + + // Last real task finishes — span must close now, exactly once. + tr.OnFinish("b:build:sn", nil) + if n := countSpans(exp, "build"); n != 1 { + t.Fatalf("want exactly 1 exported build span after last real OnFinish, got %d", n) + } + + // ActionContext must now fall back to the phase context. + if tr.ActionContext("build") != context.Background() { + t.Fatal("expected action context to fall back to phase context after span closed") + } +} + +func countSpans(exp *tracetest.InMemoryExporter, name string) int { + n := 0 + for _, s := range exp.GetSpans() { + if s.Name == name { + n++ + } + } + return n +} + +func TestActionTracker_RecordsTaskErrorOnActionSpan(t *testing.T) { + exp := tracetest.NewInMemoryExporter() + tp := sdktrace.NewTracerProvider(sdktrace.WithSyncer(exp)) + prev := otel.GetTracerProvider() + otel.SetTracerProvider(tp) + t.Cleanup(func() { otel.SetTracerProvider(prev); _ = tp.Shutdown(context.Background()) }) + + tr := NewActionTracker(context.Background()) + tr.OnStart("a:build:sn") + tr.OnStart("b:build:sn") + tr.OnFinish("a:build:sn", errors.New("build failed")) // one task fails + tr.OnFinish("b:build:sn", nil) // last finishes -> span ends + + spans := exp.GetSpans() + var build *tracetest.SpanStub + for i := range spans { + if spans[i].Name == "build" { + build = &spans[i] + } + } + if build == nil { + t.Fatal("no build action span exported") + } + if build.Status.Code != codes.Error { + t.Fatalf("build span status = %v, want Error", build.Status.Code) + } +} diff --git a/telemetry/logs.go b/telemetry/logs.go new file mode 100644 index 00000000..8269f5d7 --- /dev/null +++ b/telemetry/logs.go @@ -0,0 +1,61 @@ +package telemetry + +import ( + "context" + "sync" + + "github.com/cego/gitte/executor" + + "go.opentelemetry.io/otel/log" + "go.opentelemetry.io/otel/log/global" +) + +// logHandler forwards output to inner and emits a correlated OTEL log record. +type logHandler struct { + inner executor.OutputHandler + once sync.Once + lgr log.Logger +} + +// LogOutputHandler wraps inner so that every output line is also emitted as an +// OTEL log record correlated to the span in ctx. Callers should install this +// wrapper at the producer boundary, before output is handed to an asynchronous +// drain, so the task span is still available. When logs are disabled the global +// logger provider is a no-op; output is always forwarded unchanged. +// +// The logger is resolved lazily on first use so that callers constructed before +// telemetry.Init registers the real LoggerProvider still pick up the live +// provider. +func LogOutputHandler(inner executor.OutputHandler) executor.OutputHandler { + return &logHandler{inner: inner} +} + +func (h *logHandler) logger() log.Logger { + h.once.Do(func() { + h.lgr = global.GetLoggerProvider().Logger("github.com/cego/gitte") + }) + return h.lgr +} + +func (h *logHandler) HandleOutput(ctx context.Context, out executor.Output) error { + h.emit(ctx, out) + return h.inner.HandleOutput(ctx, out) +} + +func (h *logHandler) emit(ctx context.Context, out executor.Output) { + var rec log.Record + rec.SetBody(log.StringValue(string(out.Output))) + sev := log.SeverityInfo + if out.Stream == executor.StderrStream { + sev = log.SeverityWarn + } + rec.SetSeverity(sev) + rec.AddAttributes( + log.String("gitte.task", out.CmdName), + log.String("stream", string(out.Stream)), + ) + if len(out.Output) >= 6 && string(out.Output[:6]) == "[HINT]" { + rec.AddAttributes(log.Bool("gitte.hint", true)) + } + h.logger().Emit(ctx, rec) +} diff --git a/telemetry/logs_test.go b/telemetry/logs_test.go new file mode 100644 index 00000000..bc6d09ec --- /dev/null +++ b/telemetry/logs_test.go @@ -0,0 +1,193 @@ +package telemetry + +import ( + "context" + "sync" + "testing" + + "github.com/cego/gitte/executor" + "go.opentelemetry.io/otel/log" + "go.opentelemetry.io/otel/log/global" + sdklog "go.opentelemetry.io/otel/sdk/log" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" +) + +type recordingHandler struct{ lines []string } + +func (r *recordingHandler) HandleOutput(_ context.Context, o executor.Output) error { + r.lines = append(r.lines, string(o.Output)) + return nil +} + +func TestLogOutputHandler_ForwardsUnchanged(t *testing.T) { + // With logs disabled (no provider), the wrapper must still forward output + // to the inner handler and never error. + inner := &recordingHandler{} + h := LogOutputHandler(inner) + err := h.HandleOutput(context.Background(), executor.Output{ + Output: []byte("hello"), CmdName: "proj:build:sn", Stream: executor.StdoutStream, + }) + if err != nil { + t.Fatalf("unexpected error: %v", err) + } + if len(inner.lines) != 1 || inner.lines[0] != "hello" { + t.Fatalf("inner did not receive line: %+v", inner.lines) + } +} + +// recordingExporter is a minimal sdklog.Exporter that captures exported records. +type recordingExporter struct { + mu sync.Mutex + records []sdklog.Record +} + +func (e *recordingExporter) Export(_ context.Context, records []sdklog.Record) error { + e.mu.Lock() + defer e.mu.Unlock() + for _, r := range records { + e.records = append(e.records, r.Clone()) + } + return nil +} + +func (e *recordingExporter) Shutdown(_ context.Context) error { return nil } +func (e *recordingExporter) ForceFlush(_ context.Context) error { return nil } + +func (e *recordingExporter) Records() []sdklog.Record { + e.mu.Lock() + defer e.mu.Unlock() + out := make([]sdklog.Record, len(e.records)) + copy(out, e.records) + return out +} + +// setupRecordingProvider installs a real LoggerProvider backed by exp as the +// global, and returns a cleanup function that restores the previous global. +func setupRecordingProvider(t *testing.T) *recordingExporter { + t.Helper() + exp := &recordingExporter{} + proc := sdklog.NewSimpleProcessor(exp) + provider := sdklog.NewLoggerProvider(sdklog.WithProcessor(proc)) + + prev := global.GetLoggerProvider() + global.SetLoggerProvider(provider) + t.Cleanup(func() { + global.SetLoggerProvider(prev) + }) + return exp +} + +func TestLogOutputHandler_StdoutSeverityInfo(t *testing.T) { + exp := setupRecordingProvider(t) + + inner := &recordingHandler{} + h := LogOutputHandler(inner) + + _ = h.HandleOutput(context.Background(), executor.Output{ + Output: []byte("normal line"), + CmdName: "task", + Stream: executor.StdoutStream, + }) + + recs := exp.Records() + if len(recs) != 1 { + t.Fatalf("expected 1 record, got %d", len(recs)) + } + if got := recs[0].Severity(); got != log.SeverityInfo { + t.Errorf("stdout severity = %v; want SeverityInfo (%v)", got, log.SeverityInfo) + } +} + +func TestLogOutputHandler_StderrSeverityWarn(t *testing.T) { + exp := setupRecordingProvider(t) + + inner := &recordingHandler{} + h := LogOutputHandler(inner) + + _ = h.HandleOutput(context.Background(), executor.Output{ + Output: []byte("error output"), + CmdName: "task", + Stream: executor.StderrStream, + }) + + recs := exp.Records() + if len(recs) != 1 { + t.Fatalf("expected 1 record, got %d", len(recs)) + } + if got := recs[0].Severity(); got != log.SeverityWarn { + t.Errorf("stderr severity = %v; want SeverityWarn (%v)", got, log.SeverityWarn) + } +} + +func TestLogOutputHandler_HintAttribute(t *testing.T) { + exp := setupRecordingProvider(t) + + inner := &recordingHandler{} + h := LogOutputHandler(inner) + + _ = h.HandleOutput(context.Background(), executor.Output{ + Output: []byte("[HINT] do something"), + CmdName: "task", + Stream: executor.StdoutStream, + }) + + recs := exp.Records() + if len(recs) != 1 { + t.Fatalf("expected 1 record, got %d", len(recs)) + } + + var hintVal log.Value + var found bool + recs[0].WalkAttributes(func(kv log.KeyValue) bool { + if kv.Key == "gitte.hint" { + hintVal = kv.Value + found = true + return false + } + return true + }) + if !found { + t.Fatal("expected attribute gitte.hint=true but it was not present") + } + if !hintVal.AsBool() { + t.Errorf("gitte.hint = %v; want true", hintVal) + } +} + +func TestLogOutputHandler_UsesProducerSpanContext(t *testing.T) { + exp := setupRecordingProvider(t) + spanExp := tracetest.NewInMemoryExporter() + tp := sdktrace.NewTracerProvider(sdktrace.WithSyncer(spanExp)) + t.Cleanup(func() { _ = tp.Shutdown(context.Background()) }) + + ctx, span := tp.Tracer("test").Start(context.Background(), "task") + wantTraceID := span.SpanContext().TraceID() + wantSpanID := span.SpanContext().SpanID() + h := LogOutputHandler(&recordingHandler{}) + _ = h.HandleOutput(ctx, executor.Output{Output: []byte("last line"), CmdName: "task", Stream: executor.StderrStream}) + span.End() + + recs := exp.Records() + if len(recs) != 1 { + t.Fatalf("expected 1 record, got %d", len(recs)) + } + if recs[0].TraceID() != wantTraceID || recs[0].SpanID() != wantSpanID { + t.Fatalf("log correlation = %s/%s, want %s/%s", recs[0].TraceID(), recs[0].SpanID(), wantTraceID, wantSpanID) + } +} + +func TestSignalEndpointURL(t *testing.T) { + cases := []struct{ endpoint, signal, want string }{ + {"https://apm.example.com", "traces", "https://apm.example.com/v1/traces"}, + {"https://apm.example.com/", "traces", "https://apm.example.com/v1/traces"}, + {"https://apm.example.com:8200/", "logs", "https://apm.example.com:8200/v1/logs"}, + {"https://apm.example.com/custom/traces", "traces", "https://apm.example.com/custom/traces"}, + {"https://apm.example.com/?token=x", "traces", "https://apm.example.com/v1/traces?token=x"}, + } + for _, c := range cases { + if got := signalEndpointURL(c.endpoint, c.signal); got != c.want { + t.Errorf("signalEndpointURL(%q, %q) = %q, want %q", c.endpoint, c.signal, got, c.want) + } + } +} diff --git a/telemetry/telemetry.go b/telemetry/telemetry.go new file mode 100644 index 00000000..35a36367 --- /dev/null +++ b/telemetry/telemetry.go @@ -0,0 +1,247 @@ +// Package telemetry wires OpenTelemetry tracing for gitte and exports spans to +// an OTLP/HTTP endpoint (e.g. Elastic APM). It is config-driven and degrades to +// a no-op whenever telemetry is disabled or setup fails, so it never blocks or +// slows gitte. +package telemetry + +import ( + "context" + "fmt" + "net/url" + "os" + "os/user" + "runtime" + "strings" + "sync" + "time" + + "github.com/cego/gitte/config" + + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/attribute" + otlplog "go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploghttp" + "go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp" + otellog "go.opentelemetry.io/otel/log/global" + sdklog "go.opentelemetry.io/otel/sdk/log" + "go.opentelemetry.io/otel/sdk/resource" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/trace" +) + +const tracerName = "github.com/cego/gitte" + +// flushTimeout bounds how long exit can block flushing each signal. Kept short so an +// enabled-but-unreachable endpoint (e.g. laptop with the VPN off) adds at most +// this delay to every command. +const flushTimeout = 1 * time.Second + +// Resolved is the outcome of resolving telemetry settings from config + env. +type Resolved struct { + Enabled bool + Endpoint string // explicit endpoint to export to; empty when UseSDKEnv + Headers map[string]string // export headers (auth, etc.) + UseSDKEnv bool // enable from standard OTEL_* env; let the SDK read its own config +} + +// Resolve computes telemetry settings. Precedence: +// GITTE_TELEMETRY=off > GITTE_TELEMETRY_URL > config endpoint > OTEL_EXPORTER_OTLP_* env. +func Resolve(cfg *config.GitteConfig) Resolved { + if strings.EqualFold(os.Getenv("GITTE_TELEMETRY"), "off") { + return Resolved{} + } + + endpoint := os.Getenv("GITTE_TELEMETRY_URL") + if endpoint == "" && cfg != nil { + endpoint = cfg.Telemetry.Endpoint + } + if endpoint != "" { + // Headers always come from config, even when GITTE_TELEMETRY_URL overrides + // the endpoint. This is a known v1 limitation: if you need different headers + // for an override endpoint, use the standard OTEL_EXPORTER_OTLP_* env path + // instead (which lets the SDK read its own config independently). + headers := map[string]string{} + if cfg != nil { + for k, v := range cfg.Telemetry.Headers { + headers[k] = v + } + } + return Resolved{Enabled: true, Endpoint: endpoint, Headers: headers} + } + + if os.Getenv("OTEL_EXPORTER_OTLP_ENDPOINT") != "" || os.Getenv("OTEL_EXPORTER_OTLP_TRACES_ENDPOINT") != "" { + return Resolved{Enabled: true, UseSDKEnv: true} + } + + return Resolved{} +} + +// noopErrorHandler swallows OTEL-internal errors (e.g. export failures) so they +// never reach the user or interfere with gitte. +type noopErrorHandler struct{} + +func (noopErrorHandler) Handle(error) {} + +// debugErrorHandler logs OTEL-internal errors to stderr. Enabled via +// GITTE_TELEMETRY_DEBUG so export failures (auth, redirects, connectivity) are +// visible when diagnosing why traces aren't arriving — otherwise they are +// silently swallowed. +type debugErrorHandler struct{} + +func (debugErrorHandler) Handle(err error) { + fmt.Fprintf(os.Stderr, "[telemetry] %v\n", err) +} + +// resourceAttributes builds the resource attributes attached to every span. +// username and hostname identify which developer and machine produced the +// trace (the primary signal for debugging machine-specific failures); both are +// best-effort and omitted when they cannot be resolved. +func resourceAttributes(version, username, hostname string) []attribute.KeyValue { + attrs := []attribute.KeyValue{ + attribute.String("service.name", "gitte"), + attribute.String("service.version", version), + attribute.String("os.type", runtime.GOOS), + attribute.String("os.arch", runtime.GOARCH), + } + if username != "" { + attrs = append(attrs, attribute.String("user.name", username)) + } + if hostname != "" { + attrs = append(attrs, attribute.String("host.name", hostname)) + } + return attrs +} + +// Init configures the global tracer provider and returns a shutdown function +// that flushes pending spans with a bounded timeout. The returned function is +// always non-nil and safe to call; setup failures and disabled telemetry both +// degrade to a no-op shutdown. +func Init(ctx context.Context, cfg *config.GitteConfig, version string) func(context.Context) { + r := Resolve(cfg) + if !r.Enabled { + return func(context.Context) {} + } + + // Only mutate process-wide OTEL state once telemetry is known to be enabled. + // GITTE_TELEMETRY_DEBUG surfaces export errors to stderr for diagnostics. + if os.Getenv("GITTE_TELEMETRY_DEBUG") != "" { + otel.SetErrorHandler(debugErrorHandler{}) + } else { + otel.SetErrorHandler(noopErrorHandler{}) + } + + var opts []otlptracehttp.Option + if !r.UseSDKEnv { + opts = append(opts, otlptracehttp.WithEndpointURL(signalEndpointURL(r.Endpoint, "traces"))) + if len(r.Headers) > 0 { + opts = append(opts, otlptracehttp.WithHeaders(r.Headers)) + } + } + + exporter, err := otlptracehttp.New(ctx, opts...) + if err != nil { + // Never block gitte: disable telemetry on exporter setup failure. + return func(context.Context) {} + } + + username := "" + if u, uerr := user.Current(); uerr == nil { + username = u.Username + } + hostname, _ := os.Hostname() + res := resource.NewSchemaless(resourceAttributes(version, username, hostname)...) + + tp := sdktrace.NewTracerProvider( + sdktrace.WithBatcher(exporter), + sdktrace.WithResource(res), + ) + otel.SetTracerProvider(tp) + + var lp *sdklog.LoggerProvider + if logsEnabled() { + var logOpts []otlplog.Option + if !r.UseSDKEnv { + logOpts = append(logOpts, otlplog.WithEndpointURL(signalEndpointURL(r.Endpoint, "logs"))) + if len(r.Headers) > 0 { + logOpts = append(logOpts, otlplog.WithHeaders(r.Headers)) + } + } + if logExp, lerr := otlplog.New(ctx, logOpts...); lerr == nil { + lp = sdklog.NewLoggerProvider( + sdklog.WithResource(res), + sdklog.WithProcessor(sdklog.NewBatchProcessor(logExp)), + ) + otellog.SetLoggerProvider(lp) + } + } + + return func(ctx context.Context) { + providers := []shutdowner{tp} + if lp != nil { + providers = append(providers, lp) + } + shutdownProviders(ctx, providers...) + } +} + +type shutdowner interface { + Shutdown(context.Context) error +} + +// shutdownProviders flushes signals concurrently. Each provider receives its +// own timeout so one slow exporter cannot consume another signal's budget. +func shutdownProviders(ctx context.Context, providers ...shutdowner) { + var wg sync.WaitGroup + for _, provider := range providers { + provider := provider + wg.Add(1) + go func() { + defer wg.Done() + shutdownCtx, cancel := context.WithTimeout(ctx, flushTimeout) + defer cancel() + _ = provider.Shutdown(shutdownCtx) + }() + } + wg.Wait() +} + +// logsEnabled reports whether OTEL logs should be exported (enabled with tracing +// unless GITTE_TELEMETRY_LOGS=off). +func logsEnabled() bool { + return !strings.EqualFold(os.Getenv("GITTE_TELEMETRY_LOGS"), "off") +} + +// signalEndpointURL returns an OTLP/HTTP endpoint for signal. EndpointURL +// options use a URL path verbatim, so path-less and root-path configured URLs +// need the standard signal intake path appended. Custom paths are preserved. +func signalEndpointURL(endpoint, signal string) string { + u, err := url.Parse(endpoint) + if err != nil { + return endpoint + } + if u.Path == "" || u.Path == "/" { + u.Path = "/v1/" + signal + } + return u.String() +} + +// Tracer returns gitte's tracer from the global provider (a no-op tracer when +// telemetry is disabled). +func Tracer() trace.Tracer { + return otel.Tracer(tracerName) +} + +// StartPhaseSpan starts a span for a gitte run phase (startup/gitops/actions) +// and returns the derived context to thread into that phase's work. +func StartPhaseSpan(ctx context.Context, phase string) (context.Context, trace.Span) { + return Tracer().Start(ctx, phase) +} + +// StartCommandSpan starts the root span for a gitte invocation. +func StartCommandSpan(ctx context.Context, commandPath string, args []string) (context.Context, trace.Span) { + ctx, span := Tracer().Start(ctx, commandPath) + span.SetAttributes( + attribute.String("gitte.command", commandPath), + attribute.StringSlice("gitte.args", args), + ) + return ctx, span +} diff --git a/telemetry/telemetry_test.go b/telemetry/telemetry_test.go new file mode 100644 index 00000000..e8645a45 --- /dev/null +++ b/telemetry/telemetry_test.go @@ -0,0 +1,205 @@ +package telemetry + +import ( + "context" + "sync" + "testing" + "time" + + "github.com/cego/gitte/config" + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/attribute" +) + +func TestResourceAttributes(t *testing.T) { + find := func(attrs []attribute.KeyValue, key string) (string, bool) { + for _, a := range attrs { + if string(a.Key) == key { + return a.Value.AsString(), true + } + } + return "", false + } + + t.Run("includes username and hostname when resolved", func(t *testing.T) { + attrs := resourceAttributes("1.2.3", "alice", "dev-box") + if v, _ := find(attrs, "service.name"); v != "gitte" { + t.Errorf("service.name = %q, want gitte", v) + } + if v, _ := find(attrs, "service.version"); v != "1.2.3" { + t.Errorf("service.version = %q, want 1.2.3", v) + } + if v, ok := find(attrs, "user.name"); !ok || v != "alice" { + t.Errorf("user.name = %q (present=%v), want alice", v, ok) + } + if v, ok := find(attrs, "host.name"); !ok || v != "dev-box" { + t.Errorf("host.name = %q (present=%v), want dev-box", v, ok) + } + }) + + t.Run("omits username and hostname when empty", func(t *testing.T) { + attrs := resourceAttributes("1.2.3", "", "") + if _, ok := find(attrs, "user.name"); ok { + t.Error("user.name should be omitted when empty") + } + if _, ok := find(attrs, "host.name"); ok { + t.Error("host.name should be omitted when empty") + } + }) +} + +func TestResolve_Precedence(t *testing.T) { + // Save and clear env that influences resolution. + for _, k := range []string{"GITTE_TELEMETRY", "GITTE_TELEMETRY_URL", "OTEL_EXPORTER_OTLP_ENDPOINT", "OTEL_EXPORTER_OTLP_TRACES_ENDPOINT"} { + t.Setenv(k, "") + } + + cfgWith := func(ep string) *config.GitteConfig { + return &config.GitteConfig{Telemetry: config.TelemetryConfig{Endpoint: ep, Headers: map[string]string{"Authorization": "Bearer x"}}} + } + + t.Run("disabled when no endpoint anywhere", func(t *testing.T) { + r := Resolve(&config.GitteConfig{}) + if r.Enabled { + t.Fatal("expected disabled") + } + }) + + t.Run("enabled from config endpoint", func(t *testing.T) { + r := Resolve(cfgWith("https://apm:8200")) + if !r.Enabled || r.Endpoint != "https://apm:8200" || r.UseSDKEnv { + t.Fatalf("got %+v", r) + } + if r.Headers["Authorization"] != "Bearer x" { + t.Fatalf("headers not carried: %+v", r.Headers) + } + }) + + t.Run("GITTE_TELEMETRY_URL overrides config", func(t *testing.T) { + t.Setenv("GITTE_TELEMETRY_URL", "https://override:8200") + r := Resolve(cfgWith("https://apm:8200")) + if r.Endpoint != "https://override:8200" { + t.Fatalf("got %+v", r) + } + if !r.Enabled { + t.Fatalf("expected Enabled=true when GITTE_TELEMETRY_URL is set, got %+v", r) + } + }) + + t.Run("GITTE_TELEMETRY=off disables everything", func(t *testing.T) { + t.Setenv("GITTE_TELEMETRY", "off") + t.Setenv("GITTE_TELEMETRY_URL", "https://override:8200") + r := Resolve(cfgWith("https://apm:8200")) + if r.Enabled { + t.Fatalf("expected disabled, got %+v", r) + } + }) + + t.Run("falls back to OTEL env endpoint with UseSDKEnv", func(t *testing.T) { + t.Setenv("OTEL_EXPORTER_OTLP_ENDPOINT", "https://otel:4318") + r := Resolve(&config.GitteConfig{}) + if !r.Enabled || !r.UseSDKEnv || r.Endpoint != "" { + t.Fatalf("got %+v", r) + } + }) +} + +func TestInit_DisabledReturnsNoopShutdown(t *testing.T) { + t.Setenv("GITTE_TELEMETRY", "off") + shutdown := Init(context.Background(), &config.GitteConfig{}, "test") + if shutdown == nil { + t.Fatal("shutdown must never be nil") + } + shutdown(context.Background()) // must not panic +} + +func TestInit_EnabledReturnsCallableShutdown(t *testing.T) { + // Verify that Init with a valid endpoint returns a non-nil shutdown function + // that can be called without panicking or hanging (bounded flush timeout). + // Note: otlptracehttp.New is lazy — it accepts any URL including unreachable + // endpoints without error, so Init succeeds and returns a real shutdown. + // The exporter-error branch (where New returns an error and Init falls back to + // no-op) cannot be triggered deterministically with the HTTP exporter; the SDK + // silently swallows malformed URLs and connection errors at export time. + t.Setenv("GITTE_TELEMETRY", "") + prev := otel.GetTracerProvider() + t.Cleanup(func() { otel.SetTracerProvider(prev) }) + cfg := &config.GitteConfig{Telemetry: config.TelemetryConfig{Endpoint: "http://localhost:4318"}} + shutdown := Init(context.Background(), cfg, "test") + if shutdown == nil { + t.Fatal("shutdown must never be nil on the enabled path") + } + shutdown(context.Background()) // must not panic or hang beyond the flush timeout +} + +func TestInit_RespectsOTELTracesSampler(t *testing.T) { + t.Setenv("GITTE_TELEMETRY", "") + t.Setenv("GITTE_TELEMETRY_LOGS", "off") + t.Setenv("OTEL_TRACES_SAMPLER", "always_off") + prev := otel.GetTracerProvider() + t.Cleanup(func() { otel.SetTracerProvider(prev) }) + + shutdown := Init(context.Background(), &config.GitteConfig{Telemetry: config.TelemetryConfig{Endpoint: "http://localhost:4318"}}, "test") + _, span := Tracer().Start(context.Background(), "not-recorded") + if span.IsRecording() { + t.Fatal("span is recording despite OTEL_TRACES_SAMPLER=always_off") + } + span.End() + ctx, cancel := context.WithCancel(context.Background()) + cancel() + shutdown(ctx) +} + +type testShutdowner struct { + called chan struct{} + wait bool + once sync.Once +} + +func (s *testShutdowner) Shutdown(ctx context.Context) error { + s.once.Do(func() { close(s.called) }) + if s.wait { + <-ctx.Done() + } + return nil +} + +func TestShutdownProviders_RunIndependentlyAndHonorCancellation(t *testing.T) { + traceProvider := &testShutdowner{called: make(chan struct{}), wait: true} + logProvider := &testShutdowner{called: make(chan struct{})} + ctx, cancel := context.WithCancel(context.Background()) + done := make(chan struct{}) + go func() { + shutdownProviders(ctx, traceProvider, logProvider) + close(done) + }() + + select { + case <-logProvider.called: + case <-time.After(100 * time.Millisecond): + t.Fatal("log shutdown was blocked behind trace shutdown") + } + cancel() + select { + case <-done: + case <-time.After(100 * time.Millisecond): + t.Fatal("shutdown did not stop after cancellation") + } +} + +func TestStartCommandSpan_NoProviderDoesNotPanic(t *testing.T) { + // With no provider set, Tracer() returns a no-op tracer; span ops are safe. + _, span := StartCommandSpan(context.Background(), "gitte run", []string{"up"}) + span.End() +} + +func TestStartPhaseSpan_ReturnsChildContext(t *testing.T) { + ctx, span := StartPhaseSpan(context.Background(), "startup") + if span == nil { + t.Fatal("nil span") + } + if ctx == context.Background() { + t.Fatal("expected a derived context") + } + span.End() +}