feat: add metrics to workspace agent scripts (#11132)

* push startup script metrics to agent

agent/agent.go

@@ -35,6 +35,8 @@ import (
 	"tailscale.com/types/netlogtype"
 
 	"cdr.dev/slog"
+	"github.com/coder/retry"
+
 	"github.com/coder/coder/v2/agent/agentproc"
 	"github.com/coder/coder/v2/agent/agentscripts"
 	"github.com/coder/coder/v2/agent/agentssh"
@@ -45,7 +47,6 @@ import (
 	"github.com/coder/coder/v2/codersdk"
 	"github.com/coder/coder/v2/codersdk/agentsdk"
 	"github.com/coder/coder/v2/tailnet"
-	"github.com/coder/retry"
 )
 
 const (
@@ -222,8 +223,10 @@ type agent struct {
 	connCountReconnectingPTY atomic.Int64
 
 	prometheusRegistry *prometheus.Registry
-	metrics            *agentMetrics
-	syscaller          agentproc.Syscaller
+	// metrics are prometheus registered metrics that will be collected and
+	// labeled in Coder with the agent + workspace.
+	metrics   *agentMetrics
+	syscaller agentproc.Syscaller
 
 	// modifiedProcs is used for testing process priority management.
 	modifiedProcs chan []*agentproc.Process
@@ -252,6 +255,9 @@ func (a *agent) init(ctx context.Context) {
 		Filesystem: a.filesystem,
 		PatchLogs:  a.client.PatchLogs,
 	})
+	// Register runner metrics. If the prom registry is nil, the metrics
+	// will not report anywhere.
+	a.scriptRunner.RegisterMetrics(a.prometheusRegistry)
 	go a.runLoop(ctx)
 }
 
@@ -745,9 +751,12 @@ func (a *agent) run(ctx context.Context) error {
 			return xerrors.Errorf("init script runner: %w", err)
 		}
 		err = a.trackConnGoroutine(func() {
+			start := time.Now()
 			err := a.scriptRunner.Execute(ctx, func(script codersdk.WorkspaceAgentScript) bool {
 				return script.RunOnStart
 			})
+			// Measure the time immediately after the script has finished
+			dur := time.Since(start).Seconds()
 			if err != nil {
 				a.logger.Warn(ctx, "startup script(s) failed", slog.Error(err))
 				if errors.Is(err, agentscripts.ErrTimeout) {
@@ -758,6 +767,12 @@ func (a *agent) run(ctx context.Context) error {
 			} else {
 				a.setLifecycle(ctx, codersdk.WorkspaceAgentLifecycleReady)
 			}
+
+			label := "false"
+			if err == nil {
+				label = "true"
+			}
+			a.metrics.startupScriptSeconds.WithLabelValues(label).Set(dur)
 			a.scriptRunner.StartCron()
 		})
 		if err != nil {

agent/agent_test.go

@@ -46,6 +46,7 @@ import (
 	"cdr.dev/slog"
 	"cdr.dev/slog/sloggers/sloghuman"
 	"cdr.dev/slog/sloggers/slogtest"
+
 	"github.com/coder/coder/v2/agent"
 	"github.com/coder/coder/v2/agent/agentproc"
 	"github.com/coder/coder/v2/agent/agentproc/agentproctest"
@@ -2235,6 +2236,17 @@ func TestAgent_Metrics_SSH(t *testing.T) {
 			Type:  agentsdk.AgentMetricTypeCounter,
 			Value: 0,
 		},
+		{
+			Name:  "coderd_agentstats_startup_script_seconds",
+			Type:  agentsdk.AgentMetricTypeGauge,
+			Value: 0,
+			Labels: []agentsdk.AgentMetricLabel{
+				{
+					Name:  "success",
+					Value: "true",
+				},
+			},
+		},
 	}
 
 	var actual []*promgo.MetricFamily

agent/agentscripts/agentscripts.go

@@ -13,12 +13,14 @@ import (
 	"sync/atomic"
 	"time"
 
+	"github.com/prometheus/client_golang/prometheus"
 	"github.com/robfig/cron/v3"
 	"github.com/spf13/afero"
 	"golang.org/x/sync/errgroup"
 	"golang.org/x/xerrors"
 
 	"cdr.dev/slog"
+
 	"github.com/coder/coder/v2/agent/agentssh"
 	"github.com/coder/coder/v2/codersdk"
 	"github.com/coder/coder/v2/codersdk/agentsdk"
@@ -57,6 +59,11 @@ func New(opts Options) *Runner {
 		cronCtxCancel: cronCtxCancel,
 		cron:          cron.New(cron.WithParser(parser)),
 		closed:        make(chan struct{}),
+		scriptsExecuted: prometheus.NewCounterVec(prometheus.CounterOpts{
+			Namespace: "agent",
+			Subsystem: "scripts",
+			Name:      "executed_total",
+		}, []string{"success"}),
 	}
 }
 
@@ -71,6 +78,19 @@ type Runner struct {
 	cron          *cron.Cron
 	initialized   atomic.Bool
 	scripts       []codersdk.WorkspaceAgentScript
+
+	// scriptsExecuted includes all scripts executed by the workspace agent. Agents
+	// execute startup scripts, and scripts on a cron schedule. Both will increment
+	// this counter.
+	scriptsExecuted *prometheus.CounterVec
+}
+
+func (r *Runner) RegisterMetrics(reg prometheus.Registerer) {
+	if reg == nil {
+		// If no registry, do nothing.
+		return
+	}
+	reg.MustRegister(r.scriptsExecuted)
 }
 
 // Init initializes the runner with the provided scripts.
@@ -90,7 +110,7 @@ func (r *Runner) Init(scripts []codersdk.WorkspaceAgentScript) error {
 		}
 		script := script
 		_, err := r.cron.AddFunc(script.Cron, func() {
-			err := r.run(r.cronCtx, script)
+			err := r.trackRun(r.cronCtx, script)
 			if err != nil {
 				r.Logger.Warn(context.Background(), "run agent script on schedule", slog.Error(err))
 			}
@@ -131,7 +151,7 @@ func (r *Runner) Execute(ctx context.Context, filter func(script codersdk.Worksp
 		}
 		script := script
 		eg.Go(func() error {
-			err := r.run(ctx, script)
+			err := r.trackRun(ctx, script)
 			if err != nil {
 				return xerrors.Errorf("run agent script %q: %w", script.LogSourceID, err)
 			}
@@ -141,6 +161,17 @@ func (r *Runner) Execute(ctx context.Context, filter func(script codersdk.Worksp
 	return eg.Wait()
 }
 
+// trackRun wraps "run" with metrics.
+func (r *Runner) trackRun(ctx context.Context, script codersdk.WorkspaceAgentScript) error {
+	err := r.run(ctx, script)
+	if err != nil {
+		r.scriptsExecuted.WithLabelValues("false").Add(1)
+	} else {
+		r.scriptsExecuted.WithLabelValues("true").Add(1)
+	}
+	return err
+}
+
 // run executes the provided script with the timeout.
 // If the timeout is exceeded, the process is sent an interrupt signal.
 // If the process does not exit after a few seconds, it is forcefully killed.

agent/metrics.go

@@ -17,6 +17,9 @@ import (
 type agentMetrics struct {
 	connectionsTotal      prometheus.Counter
 	reconnectingPTYErrors *prometheus.CounterVec
+	// startupScriptSeconds is the time in seconds that the start script(s)
+	// took to run. This is reported once per agent.
+	startupScriptSeconds *prometheus.GaugeVec
 }
 
 func newAgentMetrics(registerer prometheus.Registerer) *agentMetrics {
@@ -35,9 +38,18 @@ func newAgentMetrics(registerer prometheus.Registerer) *agentMetrics {
 	)
 	registerer.MustRegister(reconnectingPTYErrors)
 
+	startupScriptSeconds := prometheus.NewGaugeVec(prometheus.GaugeOpts{
+		Namespace: "coderd",
+		Subsystem: "agentstats",
+		Name:      "startup_script_seconds",
+		Help:      "Amount of time taken to run the startup script in seconds.",
+	}, []string{"success"})
+	registerer.MustRegister(startupScriptSeconds)
+
 	return &agentMetrics{
 		connectionsTotal:      connectionsTotal,
 		reconnectingPTYErrors: reconnectingPTYErrors,
+		startupScriptSeconds:  startupScriptSeconds,
 	}
 }