|
| 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 | +conststatusUpdatePrefix="scaletest status update:" |
| 24 | + |
| 25 | +typeRunnerstruct { |
| 26 | +clientclient |
| 27 | +cfgConfig |
| 28 | + |
| 29 | +logger slog.Logger |
| 30 | + |
| 31 | +mu sync.Mutex |
| 32 | +reportTimesmap[int]time.Time |
| 33 | +doneReportingbool |
| 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 | +funcNewRunner(coderClient*codersdk.Client,cfgConfig)*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,namestring,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 | +defercancelWorkspaceUpdates() |
| 62 | +workspaceUpdatesResult:=make(chanerror,1) |
| 63 | +gofunc() { |
| 64 | +workspaceUpdatesResult<-r.watchWorkspaceUpdates(workspaceUpdatesCtx) |
| 65 | +}() |
| 66 | + |
| 67 | +err:=r.reportTaskStatus(ctx) |
| 68 | +iferr!=nil { |
| 69 | +returnxerrors.Errorf("report task status: %w",err) |
| 70 | +} |
| 71 | + |
| 72 | +err=<-workspaceUpdatesResult |
| 73 | +iferr!=nil { |
| 74 | +returnxerrors.Errorf("watch workspace: %w",err) |
| 75 | +} |
| 76 | +returnnil |
| 77 | +} |
| 78 | + |
| 79 | +func (r*Runner)watchWorkspaceUpdates(ctx context.Context)error { |
| 80 | +updates,err:=r.client.WatchWorkspace(ctx,r.cfg.WorkspaceID) |
| 81 | +iferr!=nil { |
| 82 | +returnxerrors.Errorf("watch workspace: %w",err) |
| 83 | +} |
| 84 | +r.cfg.ConnectedWaitGroup.Done() |
| 85 | +deferfunc() { |
| 86 | +r.mu.Lock() |
| 87 | +deferr.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 | +returnctx.Err() |
| 96 | +caseworkspace:=<-updates: |
| 97 | +ifworkspace.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 | +returnxerrors.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 | +ifallDone { |
| 119 | +returnnil |
| 120 | +} |
| 121 | +} |
| 122 | +} |
| 123 | +} |
| 124 | + |
| 125 | +func (r*Runner)reportTaskStatus(ctx context.Context)error { |
| 126 | +deferfunc() { |
| 127 | +r.mu.Lock() |
| 128 | +deferr.mu.Unlock() |
| 129 | +r.doneReporting=true |
| 130 | +}() |
| 131 | + |
| 132 | +select { |
| 133 | +case<-ctx.Done(): |
| 134 | +returnctx.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 | +ifnow.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 | +iferr!=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 | +ifr.doneReporting { |
| 169 | +returndone// causes the ticker to exit due to the sentinel error |
| 170 | +} |
| 171 | +returnnil |
| 172 | +},"reportTaskStatus") |
| 173 | +err:=waiter.Wait() |
| 174 | +ifxerrors.Is(err,done) { |
| 175 | +returnnil |
| 176 | +} |
| 177 | +returnerr |
| 178 | +} |
| 179 | + |
| 180 | +funcparseStatusMessage(messagestring) (int,bool) { |
| 181 | +if!strings.HasPrefix(message,statusUpdatePrefix) { |
| 182 | +return0,false |
| 183 | +} |
| 184 | +message=strings.TrimPrefix(message,statusUpdatePrefix) |
| 185 | +msgNo,err:=strconv.Atoi(message) |
| 186 | +iferr!=nil { |
| 187 | +return0,false |
| 188 | +} |
| 189 | +returnmsgNo,true |
| 190 | +} |