|
| 1 | +package taskstatus |
| 2 | + |
| 3 | +import ( |
| 4 | + "context" |
| 5 | + "io" |
| 6 | + "strconv" |
| 7 | + "strings" |
| 8 | + "sync" |
| 9 | + "time" |
| 10 | + |
| 11 | + "golang.org/x/xerrors" |
| 12 | + |
| 13 | + "cdr.dev/slog" |
| 14 | + "cdr.dev/slog/sloggers/sloghuman" |
| 15 | + |
| 16 | + "github.com/coder/coder/v2/codersdk" |
| 17 | + "github.com/coder/coder/v2/codersdk/agentsdk" |
| 18 | + "github.com/coder/coder/v2/scaletest/harness" |
| 19 | + "github.com/coder/coder/v2/scaletest/loadtestutil" |
| 20 | + "github.com/coder/quartz" |
| 21 | +) |
| 22 | + |
| 23 | +const statusUpdatePrefix = "scaletest status update:" |
| 24 | + |
| 25 | +type Runner struct { |
| 26 | + client client |
| 27 | + cfg Config |
| 28 | + |
| 29 | + logger slog.Logger |
| 30 | + |
| 31 | + mu sync.Mutex |
| 32 | + reportTimes map[int]time.Time |
| 33 | + doneReporting bool |
| 34 | + |
| 35 | + // testing only |
| 36 | + clock quartz.Clock |
| 37 | +} |
| 38 | + |
| 39 | +var _ harness.Runnable = &Runner{} |
| 40 | + |
| 41 | +// NewRunner creates a new Runner with the provided codersdk.Client and configuration. |
| 42 | +func NewRunner(coderClient *codersdk.Client, cfg Config) *Runner { |
| 43 | + return &Runner{ |
| 44 | + client: newClient(coderClient), |
| 45 | + cfg: cfg, |
| 46 | + clock: quartz.NewReal(), |
| 47 | + reportTimes: make(map[int]time.Time), |
| 48 | + } |
| 49 | +} |
| 50 | + |
| 51 | +func (r *Runner) Run(ctx context.Context, name string, logs io.Writer) error { |
| 52 | + logs = loadtestutil.NewSyncWriter(logs) |
| 53 | + r.logger = slog.Make(sloghuman.Sink(logs)).Leveled(slog.LevelDebug).Named(name) |
| 54 | + r.client.initialize(r.logger) |
| 55 | + |
| 56 | + // ensure these labels are initialized, so we see the time series right away in prometheus. |
| 57 | + r.cfg.Metrics.MissingStatusUpdatesTotal.WithLabelValues(r.cfg.MetricLabelValues...).Add(0) |
| 58 | + r.cfg.Metrics.ReportTaskStatusErrorsTotal.WithLabelValues(r.cfg.MetricLabelValues...).Add(0) |
| 59 | + |
| 60 | + workspaceUpdatesCtx, cancelWorkspaceUpdates := context.WithCancel(ctx) |
| 61 | + defer cancelWorkspaceUpdates() |
| 62 | + workspaceUpdatesResult := make(chan error, 1) |
| 63 | + go func() { |
| 64 | + workspaceUpdatesResult <- r.watchWorkspaceUpdates(workspaceUpdatesCtx) |
| 65 | + }() |
| 66 | + |
| 67 | + err := r.reportTaskStatus(ctx) |
| 68 | + if err != nil { |
| 69 | + return xerrors.Errorf("report task status: %w", err) |
| 70 | + } |
| 71 | + |
| 72 | + err = <-workspaceUpdatesResult |
| 73 | + if err != nil { |
| 74 | + return xerrors.Errorf("watch workspace: %w", err) |
| 75 | + } |
| 76 | + return nil |
| 77 | +} |
| 78 | + |
| 79 | +func (r *Runner) watchWorkspaceUpdates(ctx context.Context) error { |
| 80 | + updates, err := r.client.WatchWorkspace(ctx, r.cfg.WorkspaceID) |
| 81 | + if err != nil { |
| 82 | + return xerrors.Errorf("watch workspace: %w", err) |
| 83 | + } |
| 84 | + r.cfg.ConnectedWaitGroup.Done() |
| 85 | + defer func() { |
| 86 | + r.mu.Lock() |
| 87 | + defer r.mu.Unlock() |
| 88 | + r.cfg.Metrics.MissingStatusUpdatesTotal. |
| 89 | + WithLabelValues(r.cfg.MetricLabelValues...). |
| 90 | + Add(float64(len(r.reportTimes))) |
| 91 | + }() |
| 92 | + for { |
| 93 | + select { |
| 94 | + case <-ctx.Done(): |
| 95 | + return ctx.Err() |
| 96 | + case workspace := <-updates: |
| 97 | + if workspace.LatestAppStatus == nil { |
| 98 | + continue |
| 99 | + } |
| 100 | + msgNo, ok := parseStatusMessage(workspace.LatestAppStatus.Message) |
| 101 | + if !ok { |
| 102 | + continue |
| 103 | + } |
| 104 | + |
| 105 | + r.mu.Lock() |
| 106 | + reportTime, ok := r.reportTimes[msgNo] |
| 107 | + delete(r.reportTimes, msgNo) |
| 108 | + allDone := r.doneReporting && len(r.reportTimes) == 0 |
| 109 | + r.mu.Unlock() |
| 110 | + |
| 111 | + if !ok { |
| 112 | + return xerrors.Errorf("report time not found for message %d", msgNo) |
| 113 | + } |
| 114 | + latency := r.clock.Since(reportTime, "watchWorkspaceUpdates") |
| 115 | + r.cfg.Metrics.TaskStatusToWorkspaceUpdateLatencySeconds. |
| 116 | + WithLabelValues(r.cfg.MetricLabelValues...). |
| 117 | + Observe(latency.Seconds()) |
| 118 | + if allDone { |
| 119 | + return nil |
| 120 | + } |
| 121 | + } |
| 122 | + } |
| 123 | +} |
| 124 | + |
| 125 | +func (r *Runner) reportTaskStatus(ctx context.Context) error { |
| 126 | + defer func() { |
| 127 | + r.mu.Lock() |
| 128 | + defer r.mu.Unlock() |
| 129 | + r.doneReporting = true |
| 130 | + }() |
| 131 | + |
| 132 | + select { |
| 133 | + case <-ctx.Done(): |
| 134 | + return ctx.Err() |
| 135 | + case <-r.cfg.StartReporting: |
| 136 | + r.logger.Info(ctx, "starting to report task status") |
| 137 | + } |
| 138 | + startedReporting := r.clock.Now("reportTaskStatus", "startedReporting") |
| 139 | + msgNo := 0 |
| 140 | + |
| 141 | + done := xerrors.New("done reporting task status") // sentinel error |
| 142 | + waiter := r.clock.TickerFunc(ctx, r.cfg.ReportStatusPeriod, func() error { |
| 143 | + r.mu.Lock() |
| 144 | + now := r.clock.Now("reportTaskStatus", "tick") |
| 145 | + r.reportTimes[msgNo] = now |
| 146 | + // It's important that we set doneReporting along with a final report, since the watchWorkspaceUpdates goroutine |
| 147 | + // needs a update to wake up and check if we're done. We could introduce a secondary signaling channel, but |
| 148 | + // it adds a lot of complexity and will be hard to test. We expect the tick period to be much smaller than the |
| 149 | + // report status duration, so one extra tick is not a big deal. |
| 150 | + if now.After(startedReporting.Add(r.cfg.ReportStatusDuration)) { |
| 151 | + r.doneReporting = true |
| 152 | + } |
| 153 | + r.mu.Unlock() |
| 154 | + |
| 155 | + err := r.client.PatchAppStatus(ctx, agentsdk.PatchAppStatus{ |
| 156 | + AppSlug: r.cfg.AppSlug, |
| 157 | + Message: statusUpdatePrefix + strconv.Itoa(msgNo), |
| 158 | + State: codersdk.WorkspaceAppStatusStateWorking, |
| 159 | + URI: "https://example.com/example-status/", |
| 160 | + }) |
| 161 | + if err != nil { |
| 162 | + r.logger.Error(ctx, "failed to report task status", slog.Error(err)) |
| 163 | + r.cfg.Metrics.ReportTaskStatusErrorsTotal.WithLabelValues(r.cfg.MetricLabelValues...).Inc() |
| 164 | + } |
| 165 | + msgNo++ |
| 166 | + // note that it's safe to read r.doneReporting here without a lock because we're the only goroutine that sets |
| 167 | + // it. |
| 168 | + if r.doneReporting { |
| 169 | + return done // causes the ticker to exit due to the sentinel error |
| 170 | + } |
| 171 | + return nil |
| 172 | + }, "reportTaskStatus") |
| 173 | + err := waiter.Wait() |
| 174 | + if xerrors.Is(err, done) { |
| 175 | + return nil |
| 176 | + } |
| 177 | + return err |
| 178 | +} |
| 179 | + |
| 180 | +func parseStatusMessage(message string) (int, bool) { |
| 181 | + if !strings.HasPrefix(message, statusUpdatePrefix) { |
| 182 | + return 0, false |
| 183 | + } |
| 184 | + message = strings.TrimPrefix(message, statusUpdatePrefix) |
| 185 | + msgNo, err := strconv.Atoi(message) |
| 186 | + if err != nil { |
| 187 | + return 0, false |
| 188 | + } |
| 189 | + return msgNo, true |
| 190 | +} |
0 commit comments