diff --git a/scaletest/autostart/config.go b/scaletest/autostart/config.go new file mode 100644 index 0000000000..ad804a0b89 --- /dev/null +++ b/scaletest/autostart/config.go @@ -0,0 +1,75 @@ +package autostart + +import ( + "sync" + "time" + + "golang.org/x/xerrors" + + "github.com/coder/coder/v2/codersdk" + "github.com/coder/coder/v2/scaletest/createusers" + "github.com/coder/coder/v2/scaletest/workspacebuild" +) + +type Config struct { + // User is the configuration for the user to create. + User createusers.Config `json:"user"` + + // Workspace is the configuration for the workspace to create. The workspace + // will be built using the new user. + // + // OrganizationID is ignored and set to the new user's organization ID. + Workspace workspacebuild.Config `json:"workspace"` + + // WorkspaceJobTimeout is how long to wait for any one workspace job + // (start or stop) to complete. + WorkspaceJobTimeout time.Duration `json:"workspace_job_timeout"` + + // AutostartDelay is how long after all the workspaces have been stopped + // to schedule them to be started again. + AutostartDelay time.Duration `json:"autostart_delay"` + + // AutostartTimeout is how long to wait for the autostart build to be + // initiated after the scheduled time. + AutostartTimeout time.Duration `json:"autostart_timeout"` + + Metrics *Metrics `json:"-"` + + // SetupBarrier is used to ensure all runners own stopped workspaces + // before setting the autostart schedule on each. + SetupBarrier *sync.WaitGroup `json:"-"` +} + +func (c Config) Validate() error { + if err := c.User.Validate(); err != nil { + return xerrors.Errorf("user config: %w", err) + } + c.Workspace.OrganizationID = c.User.OrganizationID + // This value will be overwritten during the test. + c.Workspace.UserID = codersdk.Me + if err := c.Workspace.Validate(); err != nil { + return xerrors.Errorf("workspace config: %w", err) + } + + if c.SetupBarrier == nil { + return xerrors.New("setup barrier must be set") + } + + if c.WorkspaceJobTimeout <= 0 { + return xerrors.New("workspace_job_timeout must be greater than 0") + } + + if c.AutostartDelay < time.Minute*2 { + return xerrors.New("autostart_delay must be at least 2 minutes") + } + + if c.AutostartTimeout <= 0 { + return xerrors.New("autostart_timeout must be greater than 0") + } + + if c.Metrics == nil { + return xerrors.New("metrics must be set") + } + + return nil +} diff --git a/scaletest/autostart/metrics.go b/scaletest/autostart/metrics.go new file mode 100644 index 0000000000..d1ff94e789 --- /dev/null +++ b/scaletest/autostart/metrics.go @@ -0,0 +1,65 @@ +package autostart + +import ( + "time" + + "github.com/prometheus/client_golang/prometheus" +) + +type Metrics struct { + AutostartJobCreationLatencySeconds prometheus.HistogramVec + AutostartJobAcquiredLatencySeconds prometheus.HistogramVec + AutostartTotalLatencySeconds prometheus.HistogramVec + AutostartErrorsTotal prometheus.CounterVec +} + +func NewMetrics(reg prometheus.Registerer) *Metrics { + m := &Metrics{ + AutostartJobCreationLatencySeconds: *prometheus.NewHistogramVec(prometheus.HistogramOpts{ + Namespace: "coderd", + Subsystem: "scaletest", + Name: "autostart_job_creation_latency_seconds", + Help: "Time from when the workspace is scheduled to be autostarted to when the autostart job has been created.", + }, []string{"username", "workspace_name"}), + AutostartJobAcquiredLatencySeconds: *prometheus.NewHistogramVec(prometheus.HistogramOpts{ + Namespace: "coderd", + Subsystem: "scaletest", + Name: "autostart_job_acquired_latency_seconds", + Help: "Time from when the workspace is scheduled to be autostarted to when the job has been acquired by a provisioner daemon.", + }, []string{"username", "workspace_name"}), + AutostartTotalLatencySeconds: *prometheus.NewHistogramVec(prometheus.HistogramOpts{ + Namespace: "coderd", + Subsystem: "scaletest", + Name: "autostart_total_latency_seconds", + Help: "Time from when the workspace is scheduled to be autostarted to when the autostart build has finished.", + }, []string{"username", "workspace_name"}), + AutostartErrorsTotal: *prometheus.NewCounterVec(prometheus.CounterOpts{ + Namespace: "coderd", + Subsystem: "scaletest", + Name: "autostart_errors_total", + Help: "Total number of autostart errors", + }, []string{"username", "action"}), + } + + reg.MustRegister(m.AutostartTotalLatencySeconds) + reg.MustRegister(m.AutostartJobCreationLatencySeconds) + reg.MustRegister(m.AutostartJobAcquiredLatencySeconds) + reg.MustRegister(m.AutostartErrorsTotal) + return m +} + +func (m *Metrics) RecordCompletion(elapsed time.Duration, username string, workspace string) { + m.AutostartTotalLatencySeconds.WithLabelValues(username, workspace).Observe(elapsed.Seconds()) +} + +func (m *Metrics) RecordJobCreation(elapsed time.Duration, username string, workspace string) { + m.AutostartJobCreationLatencySeconds.WithLabelValues(username, workspace).Observe(elapsed.Seconds()) +} + +func (m *Metrics) RecordJobAcquired(elapsed time.Duration, username string, workspace string) { + m.AutostartJobAcquiredLatencySeconds.WithLabelValues(username, workspace).Observe(elapsed.Seconds()) +} + +func (m *Metrics) AddError(username string, action string) { + m.AutostartErrorsTotal.WithLabelValues(username, action).Inc() +} diff --git a/scaletest/autostart/run.go b/scaletest/autostart/run.go new file mode 100644 index 0000000000..59f50a04dd --- /dev/null +++ b/scaletest/autostart/run.go @@ -0,0 +1,245 @@ +package autostart + +import ( + "context" + "fmt" + "io" + "time" + + "golang.org/x/xerrors" + + "cdr.dev/slog" + "cdr.dev/slog/sloggers/sloghuman" + "github.com/coder/coder/v2/coderd/tracing" + "github.com/coder/coder/v2/codersdk" + "github.com/coder/coder/v2/scaletest/createusers" + "github.com/coder/coder/v2/scaletest/harness" + "github.com/coder/coder/v2/scaletest/loadtestutil" + "github.com/coder/coder/v2/scaletest/workspacebuild" +) + +type Runner struct { + client *codersdk.Client + cfg Config + + createUserRunner *createusers.Runner + workspacebuildRunner *workspacebuild.Runner + + autostartTotalLatency time.Duration + autostartJobCreationLatency time.Duration + autostartJobAcquiredLatency time.Duration +} + +func NewRunner(client *codersdk.Client, cfg Config) *Runner { + return &Runner{ + client: client, + cfg: cfg, + } +} + +var ( + _ harness.Runnable = &Runner{} + _ harness.Cleanable = &Runner{} + _ harness.Collectable = &Runner{} +) + +func (r *Runner) Run(ctx context.Context, id string, logs io.Writer) error { + ctx, span := tracing.StartSpan(ctx) + defer span.End() + + reachedBarrier := false + defer func() { + if !reachedBarrier { + r.cfg.SetupBarrier.Done() + } + }() + + logs = loadtestutil.NewSyncWriter(logs) + logger := slog.Make(sloghuman.Sink(logs)).Leveled(slog.LevelDebug) + r.client.SetLogger(logger) + r.client.SetLogBodies(true) + + r.createUserRunner = createusers.NewRunner(r.client, r.cfg.User) + newUserAndToken, err := r.createUserRunner.RunReturningUser(ctx, id, logs) + if err != nil { + r.cfg.Metrics.AddError("", "create_user") + return xerrors.Errorf("create user: %w", err) + } + newUser := newUserAndToken.User + + newUserClient := codersdk.New(r.client.URL, + codersdk.WithSessionToken(newUserAndToken.SessionToken), + codersdk.WithLogger(logger), + codersdk.WithLogBodies()) + + //nolint:gocritic // short log is fine + logger.Info(ctx, "user created", slog.F("username", newUser.Username), slog.F("user_id", newUser.ID.String())) + + workspaceBuildConfig := r.cfg.Workspace + workspaceBuildConfig.OrganizationID = r.cfg.User.OrganizationID + workspaceBuildConfig.UserID = newUser.ID.String() + // We'll wait for the build ourselves to avoid multiple API requests + workspaceBuildConfig.NoWaitForBuild = true + + r.workspacebuildRunner = workspacebuild.NewRunner(newUserClient, workspaceBuildConfig) + workspace, err := r.workspacebuildRunner.RunReturningWorkspace(ctx, id, logs) + if err != nil { + r.cfg.Metrics.AddError(newUser.Username, "create_workspace") + return xerrors.Errorf("create workspace: %w", err) + } + + watchCtx, cancel := context.WithCancel(ctx) + defer cancel() + workspaceUpdates, err := newUserClient.WatchWorkspace(watchCtx, workspace.ID) + if err != nil { + r.cfg.Metrics.AddError(newUser.Username, "watch_workspace") + return xerrors.Errorf("watch workspace: %w", err) + } + + createWorkspaceCtx, cancel2 := context.WithTimeout(ctx, r.cfg.WorkspaceJobTimeout) + defer cancel2() + + err = waitForWorkspaceUpdate(createWorkspaceCtx, logger, workspaceUpdates, func(ws codersdk.Workspace) bool { + return ws.LatestBuild.Transition == codersdk.WorkspaceTransitionStart && + ws.LatestBuild.Job.Status == codersdk.ProvisionerJobSucceeded + }) + if err != nil { + r.cfg.Metrics.AddError(newUser.Username, "wait_for_initial_build") + return xerrors.Errorf("timeout waiting for initial workspace build to complete: %w", err) + } + + logger.Info(ctx, "stopping workspace", slog.F("workspace_name", workspace.Name)) + + _, err = newUserClient.CreateWorkspaceBuild(ctx, workspace.ID, codersdk.CreateWorkspaceBuildRequest{ + Transition: codersdk.WorkspaceTransitionStop, + }) + if err != nil { + r.cfg.Metrics.AddError(newUser.Username, "create_stop_build") + return xerrors.Errorf("create stop build: %w", err) + } + + stopBuildCtx, cancel3 := context.WithTimeout(ctx, r.cfg.WorkspaceJobTimeout) + defer cancel3() + + err = waitForWorkspaceUpdate(stopBuildCtx, logger, workspaceUpdates, func(ws codersdk.Workspace) bool { + return ws.LatestBuild.Transition == codersdk.WorkspaceTransitionStop && + ws.LatestBuild.Job.Status == codersdk.ProvisionerJobSucceeded + }) + if err != nil { + r.cfg.Metrics.AddError(newUser.Username, "wait_for_stop_build") + return xerrors.Errorf("timeout waiting for stop build to complete: %w", err) + } + + logger.Info(ctx, "workspace stopped successfully", slog.F("workspace_name", workspace.Name)) + + logger.Info(ctx, "waiting for all runners to reach barrier") + reachedBarrier = true + r.cfg.SetupBarrier.Done() + r.cfg.SetupBarrier.Wait() + logger.Info(ctx, "all runners reached barrier, proceeding with autostart schedule") + + testStartTime := time.Now().UTC() + autostartTime := testStartTime.Add(r.cfg.AutostartDelay).Round(time.Minute) + schedule := fmt.Sprintf("CRON_TZ=UTC %d %d * * *", autostartTime.Minute(), autostartTime.Hour()) + + logger.Info(ctx, "setting autostart schedule for workspace", slog.F("workspace_name", workspace.Name), slog.F("schedule", schedule)) + + err = newUserClient.UpdateWorkspaceAutostart(ctx, workspace.ID, codersdk.UpdateWorkspaceAutostartRequest{ + Schedule: &schedule, + }) + if err != nil { + r.cfg.Metrics.AddError(newUser.Username, "update_workspace_autostart") + return xerrors.Errorf("update workspace autostart: %w", err) + } + + logger.Info(ctx, "waiting for workspace to autostart", slog.F("workspace_name", workspace.Name)) + + autostartInitiateCtx, cancel4 := context.WithDeadline(ctx, autostartTime.Add(r.cfg.AutostartDelay)) + defer cancel4() + + logger.Info(ctx, "listening for workspace updates to detect autostart build") + + err = waitForWorkspaceUpdate(autostartInitiateCtx, logger, workspaceUpdates, func(ws codersdk.Workspace) bool { + if ws.LatestBuild.Transition != codersdk.WorkspaceTransitionStart { + return false + } + + // The job has been created, but it might be pending + if r.autostartJobCreationLatency == 0 { + r.autostartJobCreationLatency = time.Since(autostartTime) + r.cfg.Metrics.RecordJobCreation(r.autostartJobCreationLatency, newUser.Username, workspace.Name) + } + + if ws.LatestBuild.Job.Status == codersdk.ProvisionerJobRunning || + ws.LatestBuild.Job.Status == codersdk.ProvisionerJobSucceeded { + // Job is no longer pending, but it might not have finished + if r.autostartJobAcquiredLatency == 0 { + r.autostartJobAcquiredLatency = time.Since(autostartTime) + r.cfg.Metrics.RecordJobAcquired(r.autostartJobAcquiredLatency, newUser.Username, workspace.Name) + } + return ws.LatestBuild.Job.Status == codersdk.ProvisionerJobSucceeded + } + + return false + }) + if err != nil { + r.cfg.Metrics.AddError(newUser.Username, "wait_for_autostart_build") + return xerrors.Errorf("timeout waiting for autostart build to be created: %w", err) + } + + r.autostartTotalLatency = time.Since(autostartTime) + + logger.Info(ctx, "autostart workspace build complete", slog.F("duration", r.autostartTotalLatency)) + r.cfg.Metrics.RecordCompletion(r.autostartTotalLatency, newUser.Username, workspace.Name) + + return nil +} + +func waitForWorkspaceUpdate(ctx context.Context, logger slog.Logger, updates <-chan codersdk.Workspace, shouldBreak func(codersdk.Workspace) bool) error { + for { + select { + case <-ctx.Done(): + return ctx.Err() + case updatedWorkspace, ok := <-updates: + if !ok { + return xerrors.New("workspace updates channel closed") + } + logger.Debug(ctx, "received workspace update", slog.F("update", updatedWorkspace)) + if shouldBreak(updatedWorkspace) { + return nil + } + } + } +} + +func (r *Runner) Cleanup(ctx context.Context, id string, logs io.Writer) error { + if r.workspacebuildRunner != nil { + _, _ = fmt.Fprintln(logs, "Cleaning up workspace...") + if err := r.workspacebuildRunner.Cleanup(ctx, id, logs); err != nil { + return xerrors.Errorf("cleanup workspace: %w", err) + } + } + + if r.createUserRunner != nil { + _, _ = fmt.Fprintln(logs, "Cleaning up user...") + if err := r.createUserRunner.Cleanup(ctx, id, logs); err != nil { + return xerrors.Errorf("cleanup user: %w", err) + } + } + + return nil +} + +const ( + AutostartTotalLatencyMetric = "autostart_total_latency_seconds" + AutostartJobCreationLatencyMetric = "autostart_job_creation_latency_seconds" + AutostartJobAcquiredLatencyMetric = "autostart_job_acquired_latency_seconds" +) + +func (r *Runner) GetMetrics() map[string]any { + return map[string]any{ + AutostartTotalLatencyMetric: r.autostartTotalLatency.Seconds(), + AutostartJobCreationLatencyMetric: r.autostartJobCreationLatency.Seconds(), + AutostartJobAcquiredLatencyMetric: r.autostartJobAcquiredLatency.Seconds(), + } +} diff --git a/scaletest/autostart/run_test.go b/scaletest/autostart/run_test.go new file mode 100644 index 0000000000..dc0fb9fea0 --- /dev/null +++ b/scaletest/autostart/run_test.go @@ -0,0 +1,158 @@ +package autostart_test + +import ( + "io" + "strconv" + "sync" + "testing" + "time" + + "github.com/google/uuid" + "github.com/prometheus/client_golang/prometheus" + "github.com/stretchr/testify/require" + "golang.org/x/sync/errgroup" + + "github.com/coder/coder/v2/coderd/coderdtest" + "github.com/coder/coder/v2/codersdk" + "github.com/coder/coder/v2/provisioner/echo" + "github.com/coder/coder/v2/provisionersdk/proto" + "github.com/coder/coder/v2/scaletest/autostart" + "github.com/coder/coder/v2/scaletest/createusers" + "github.com/coder/coder/v2/scaletest/workspacebuild" + "github.com/coder/coder/v2/testutil" +) + +func TestRun(t *testing.T) { + t.Parallel() + numUsers := 2 + autoStartDelay := 2 * time.Minute + + // Faking a workspace autostart schedule start time at the coderd level + // is difficult and error-prone. + t.Skip("This test takes several minutes to run, and is intended as a manual regression test") + + ctx := testutil.Context(t, time.Minute*3) + + client := coderdtest.New(t, &coderdtest.Options{ + IncludeProvisionerDaemon: true, + AutobuildTicker: time.NewTicker(time.Second * 1).C, + }) + user := coderdtest.CreateFirstUser(t, client) + + authToken := uuid.NewString() + version := coderdtest.CreateTemplateVersion(t, client, user.OrganizationID, &echo.Responses{ + Parse: echo.ParseComplete, + ProvisionPlan: echo.PlanComplete, + ProvisionApply: []*proto.Response{ + { + Type: &proto.Response_Apply{ + Apply: &proto.ApplyComplete{ + Resources: []*proto.Resource{ + { + Name: "example", + Type: "aws_instance", + Agents: []*proto.Agent{ + { + Id: uuid.NewString(), + Name: "agent", + Auth: &proto.Agent_Token{ + Token: authToken, + }, + Apps: []*proto.App{}, + }, + }, + }, + }, + }, + }, + }, + }, + }) + + template := coderdtest.CreateTemplate(t, client, user.OrganizationID, version.ID) + coderdtest.AwaitTemplateVersionJobCompleted(t, client, version.ID) + + barrier := new(sync.WaitGroup) + barrier.Add(numUsers) + metrics := autostart.NewMetrics(prometheus.NewRegistry()) + + eg, runCtx := errgroup.WithContext(ctx) + + runners := make([]*autostart.Runner, 0, numUsers) + for i := range numUsers { + cfg := autostart.Config{ + User: createusers.Config{ + OrganizationID: user.OrganizationID, + }, + Workspace: workspacebuild.Config{ + OrganizationID: user.OrganizationID, + Request: codersdk.CreateWorkspaceRequest{ + TemplateID: template.ID, + }, + NoWaitForAgents: true, + }, + WorkspaceJobTimeout: testutil.WaitMedium, + AutostartDelay: autoStartDelay, + AutostartTimeout: testutil.WaitShort, + Metrics: metrics, + SetupBarrier: barrier, + } + err := cfg.Validate() + require.NoError(t, err) + + runner := autostart.NewRunner(client, cfg) + runners = append(runners, runner) + eg.Go(func() error { + return runner.Run(runCtx, strconv.Itoa(i), io.Discard) + }) + } + + err := eg.Wait() + require.NoError(t, err) + + users, err := client.Users(ctx, codersdk.UsersRequest{}) + require.NoError(t, err) + require.Len(t, users.Users, 1+numUsers) // owner + created users + + workspaces, err := client.Workspaces(ctx, codersdk.WorkspaceFilter{}) + require.NoError(t, err) + require.Len(t, workspaces.Workspaces, numUsers) // one workspace per user + + // Verify that workspaces have autostart schedules set and are running + for _, workspace := range workspaces.Workspaces { + require.NotNil(t, workspace.AutostartSchedule) + require.Equal(t, codersdk.WorkspaceTransitionStart, workspace.LatestBuild.Transition) + require.Equal(t, codersdk.ProvisionerJobSucceeded, workspace.LatestBuild.Job.Status) + } + + cleanupEg, cleanupCtx := errgroup.WithContext(ctx) + for i, runner := range runners { + cleanupEg.Go(func() error { + return runner.Cleanup(cleanupCtx, strconv.Itoa(i), io.Discard) + }) + } + err = cleanupEg.Wait() + require.NoError(t, err) + + workspaces, err = client.Workspaces(ctx, codersdk.WorkspaceFilter{}) + require.NoError(t, err) + require.Len(t, workspaces.Workspaces, 0) + + users, err = client.Users(ctx, codersdk.UsersRequest{}) + require.NoError(t, err) + require.Len(t, users.Users, 1) // owner + + for _, runner := range runners { + metrics := runner.GetMetrics() + require.Contains(t, metrics, autostart.AutostartTotalLatencyMetric) + latency, ok := metrics[autostart.AutostartTotalLatencyMetric].(float64) + require.True(t, ok) + jobCreationLatency, ok := metrics[autostart.AutostartJobCreationLatencyMetric].(float64) + require.True(t, ok) + jobAcquiredLatency, ok := metrics[autostart.AutostartJobAcquiredLatencyMetric].(float64) + require.True(t, ok) + require.Greater(t, latency, float64(0)) + require.Greater(t, jobCreationLatency, float64(0)) + require.Greater(t, jobAcquiredLatency, float64(0)) + } +} diff --git a/scaletest/workspacebuild/config.go b/scaletest/workspacebuild/config.go index 90184dacf8..105883ba3b 100644 --- a/scaletest/workspacebuild/config.go +++ b/scaletest/workspacebuild/config.go @@ -19,6 +19,9 @@ type Config struct { // NoWaitForAgents determines whether the test should wait for the workspace // agents to connect before returning. NoWaitForAgents bool `json:"no_wait_for_agents"` + // NoWaitForBuild determines whether the test should wait for the workspace + // build to complete before returning. + NoWaitForBuild bool `json:"no_wait_for_build"` // Retry determines how many times to retry starting a workspace build if it // fails. Retry int `json:"retry"` diff --git a/scaletest/workspacebuild/run.go b/scaletest/workspacebuild/run.go index c9a59a18d6..308c18f0b6 100644 --- a/scaletest/workspacebuild/run.go +++ b/scaletest/workspacebuild/run.go @@ -58,26 +58,30 @@ func (r *Runner) RunReturningWorkspace(ctx context.Context, id string, logs io.W } r.workspaceID = workspace.ID - err = waitForBuild(ctx, logs, r.client, workspace.LatestBuild.ID) - if err != nil { - for i := 0; i < r.cfg.Retry; i++ { - _, _ = fmt.Fprintf(logs, "Retrying build %d/%d...\n", i+1, r.cfg.Retry) - - workspace.LatestBuild, err = r.client.CreateWorkspaceBuild(ctx, workspace.ID, codersdk.CreateWorkspaceBuildRequest{ - Transition: codersdk.WorkspaceTransitionStart, - RichParameterValues: req.RichParameterValues, - TemplateVersionID: req.TemplateVersionID, - }) - if err != nil { - return codersdk.Workspace{}, xerrors.Errorf("create workspace build: %w", err) - } - err = waitForBuild(ctx, logs, r.client, workspace.LatestBuild.ID) - if err == nil { - break - } - } + if r.cfg.NoWaitForBuild { + _, _ = fmt.Fprintln(logs, "Skipping waiting for build") + } else { + err = waitForBuild(ctx, logs, r.client, workspace.LatestBuild.ID) if err != nil { - return codersdk.Workspace{}, xerrors.Errorf("wait for build: %w", err) + for i := 0; i < r.cfg.Retry; i++ { + _, _ = fmt.Fprintf(logs, "Retrying build %d/%d...\n", i+1, r.cfg.Retry) + + workspace.LatestBuild, err = r.client.CreateWorkspaceBuild(ctx, workspace.ID, codersdk.CreateWorkspaceBuildRequest{ + Transition: codersdk.WorkspaceTransitionStart, + RichParameterValues: req.RichParameterValues, + TemplateVersionID: req.TemplateVersionID, + }) + if err != nil { + return codersdk.Workspace{}, xerrors.Errorf("create workspace build: %w", err) + } + err = waitForBuild(ctx, logs, r.client, workspace.LatestBuild.ID) + if err == nil { + break + } + } + if err != nil { + return codersdk.Workspace{}, xerrors.Errorf("wait for build: %w", err) + } } }