chore: move stat reporting into workspacestats package (#13386)

This commit is contained in:
Garrett Delfosse
2024-05-29 11:49:08 -04:00
committed by GitHub
parent afd9d3b35f
commit 5789ea5397
19 changed files with 314 additions and 346 deletions
+61
View File
@@ -0,0 +1,61 @@
package workspacestats
import (
"context"
"time"
"github.com/google/uuid"
"golang.org/x/xerrors"
"cdr.dev/slog"
"github.com/coder/coder/v2/coderd/database"
)
// ActivityBumpWorkspace automatically bumps the workspace's auto-off timer
// if it is set to expire soon. The deadline will be bumped by 1 hour*.
// If the bump crosses over an autostart time, the workspace will be
// bumped by the workspace ttl instead.
//
// If nextAutostart is the zero value or in the past, the workspace
// will be bumped by 1 hour.
// It handles the edge case in the example:
// 1. Autostart is set to 9am.
// 2. User works all day, and leaves a terminal open to the workspace overnight.
// 3. The open terminal continually bumps the workspace deadline.
// 4. 9am the next day, the activity bump pushes to 10am.
// 5. If the user goes inactive for 1 hour during the day, the workspace will
// now stop, because it has been extended by 1 hour durations. Despite the TTL
// being set to 8hrs from the autostart time.
//
// So the issue is that when the workspace is bumped across an autostart
// deadline, we should treat the workspace as being "started" again and
// extend the deadline by the autostart time + workspace ttl instead.
//
// The issue still remains with build_max_deadline. We need to respect the original
// maximum deadline, so that will need to be handled separately.
// A way to avoid this is to configure the max deadline to something that will not
// span more than 1 day. This will force the workspace to restart and reset the deadline
// each morning when it autostarts.
func ActivityBumpWorkspace(ctx context.Context, log slog.Logger, db database.Store, workspaceID uuid.UUID, nextAutostart time.Time) {
// We set a short timeout so if the app is under load, these
// low priority operations fail first.
ctx, cancel := context.WithTimeout(ctx, time.Second*15)
defer cancel()
err := db.ActivityBumpWorkspace(ctx, database.ActivityBumpWorkspaceParams{
NextAutostart: nextAutostart.UTC(),
WorkspaceID: workspaceID,
})
if err != nil {
if !xerrors.Is(err, context.Canceled) && !database.IsQueryCanceledError(err) {
// Bump will fail if the context is canceled, but this is ok.
log.Error(ctx, "activity bump failed", slog.Error(err),
slog.F("workspace_id", workspaceID),
)
}
return
}
log.Debug(ctx, "bumped deadline from activity",
slog.F("workspace_id", workspaceID),
)
}
+319
View File
@@ -0,0 +1,319 @@
package workspacestats_test
import (
"database/sql"
"testing"
"time"
"github.com/google/uuid"
"cdr.dev/slog/sloggers/slogtest"
"github.com/coder/coder/v2/coderd/database"
"github.com/coder/coder/v2/coderd/database/dbgen"
"github.com/coder/coder/v2/coderd/database/dbtestutil"
"github.com/coder/coder/v2/coderd/database/dbtime"
"github.com/coder/coder/v2/coderd/util/ptr"
"github.com/coder/coder/v2/coderd/workspacestats"
"github.com/coder/coder/v2/testutil"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
func Test_ActivityBumpWorkspace(t *testing.T) {
t.Parallel()
// We test the below in multiple timezones specifically
// chosen to trigger timezone-related bugs.
timezones := []string{
"Asia/Kolkata", // No DST, positive fractional offset
"Canada/Newfoundland", // DST, negative fractional offset
"Europe/Paris", // DST, positive offset
"US/Arizona", // No DST, negative offset
"UTC", // Baseline
}
for _, tt := range []struct {
name string
transition database.WorkspaceTransition
jobCompletedAt sql.NullTime
buildDeadlineOffset *time.Duration
maxDeadlineOffset *time.Duration
workspaceTTL time.Duration
templateTTL time.Duration
templateActivityBump time.Duration
templateDisallowsUserAutostop bool
expectedBump time.Duration
// If the tests get queued, we need to be able to set the next autostart
// based on the actual time the unit test is running.
nextAutostart func(now time.Time) time.Time
}{
{
name: "NotFinishedYet",
transition: database.WorkspaceTransitionStart,
jobCompletedAt: sql.NullTime{},
buildDeadlineOffset: ptr.Ref(8 * time.Hour),
workspaceTTL: 8 * time.Hour,
expectedBump: 0,
},
{
name: "ManualShutdown",
transition: database.WorkspaceTransitionStart,
jobCompletedAt: sql.NullTime{Valid: true, Time: dbtime.Now()},
buildDeadlineOffset: nil,
expectedBump: 0,
},
{
name: "NotTimeToBumpYet",
transition: database.WorkspaceTransitionStart,
jobCompletedAt: sql.NullTime{Valid: true, Time: dbtime.Now()},
buildDeadlineOffset: ptr.Ref(8 * time.Hour),
workspaceTTL: 8 * time.Hour,
expectedBump: 0,
},
{
// Expected bump is 0 because the original deadline is more than 1 hour
// out, so a bump would decrease the deadline.
name: "BumpLessThanDeadline",
transition: database.WorkspaceTransitionStart,
jobCompletedAt: sql.NullTime{Valid: true, Time: dbtime.Now().Add(-30 * time.Minute)},
buildDeadlineOffset: ptr.Ref(8*time.Hour - 30*time.Minute),
workspaceTTL: 8 * time.Hour,
expectedBump: 0,
},
{
name: "TimeToBump",
transition: database.WorkspaceTransitionStart,
jobCompletedAt: sql.NullTime{Valid: true, Time: dbtime.Now().Add(-30 * time.Minute)},
buildDeadlineOffset: ptr.Ref(-30 * time.Minute),
workspaceTTL: 8 * time.Hour,
expectedBump: time.Hour,
},
{
name: "TimeToBumpNextAutostart",
transition: database.WorkspaceTransitionStart,
jobCompletedAt: sql.NullTime{Valid: true, Time: dbtime.Now().Add(-30 * time.Minute)},
buildDeadlineOffset: ptr.Ref(-30 * time.Minute),
workspaceTTL: 8 * time.Hour,
expectedBump: 8*time.Hour + 30*time.Minute,
nextAutostart: func(now time.Time) time.Time { return now.Add(time.Minute * 30) },
},
{
name: "MaxDeadline",
transition: database.WorkspaceTransitionStart,
jobCompletedAt: sql.NullTime{Valid: true, Time: dbtime.Now().Add(-24 * time.Minute)},
buildDeadlineOffset: ptr.Ref(time.Minute), // last chance to bump!
maxDeadlineOffset: ptr.Ref(time.Minute * 30),
workspaceTTL: 8 * time.Hour,
expectedBump: time.Minute * 30,
},
{
// A workspace that is still running, has passed its deadline, but has not
// yet been auto-stopped should still bump the deadline.
name: "PastDeadlineStillBumps",
transition: database.WorkspaceTransitionStart,
jobCompletedAt: sql.NullTime{Valid: true, Time: dbtime.Now().Add(-24 * time.Minute)},
buildDeadlineOffset: ptr.Ref(-time.Minute),
workspaceTTL: 8 * time.Hour,
expectedBump: time.Hour,
},
{
// A stopped workspace should never bump.
name: "StoppedWorkspace",
transition: database.WorkspaceTransitionStop,
jobCompletedAt: sql.NullTime{Valid: true, Time: dbtime.Now().Add(-time.Minute)},
buildDeadlineOffset: ptr.Ref(-time.Minute),
workspaceTTL: 8 * time.Hour,
},
{
// A workspace built from a template that disallows user autostop should bump
// by the template TTL instead.
name: "TemplateDisallowsUserAutostop",
transition: database.WorkspaceTransitionStart,
jobCompletedAt: sql.NullTime{Valid: true, Time: dbtime.Now().Add(-3 * time.Hour)},
buildDeadlineOffset: ptr.Ref(-30 * time.Minute),
workspaceTTL: 2 * time.Hour,
templateTTL: 10 * time.Hour,
templateDisallowsUserAutostop: true,
expectedBump: 10*time.Hour + (time.Minute * 30),
nextAutostart: func(now time.Time) time.Time { return now.Add(time.Minute * 30) },
},
{
// Custom activity bump duration specified on the template.
name: "TemplateCustomActivityBump",
transition: database.WorkspaceTransitionStart,
jobCompletedAt: sql.NullTime{Valid: true, Time: dbtime.Now().Add(-30 * time.Minute)},
buildDeadlineOffset: ptr.Ref(-30 * time.Minute),
workspaceTTL: 8 * time.Hour,
templateActivityBump: 5 * time.Hour, // instead of default 1h
expectedBump: 5 * time.Hour,
},
{
// Activity bump duration is 0.
name: "TemplateCustomActivityBumpZero",
transition: database.WorkspaceTransitionStart,
jobCompletedAt: sql.NullTime{Valid: true, Time: dbtime.Now().Add(-30 * time.Minute)},
buildDeadlineOffset: ptr.Ref(-30 * time.Minute),
workspaceTTL: 8 * time.Hour,
templateActivityBump: -1, // negative values get changed to 0 in the test
expectedBump: 0,
},
} {
tt := tt
for _, tz := range timezones {
tz := tz
t.Run(tt.name+"/"+tz, func(t *testing.T) {
t.Parallel()
nextAutostart := tt.nextAutostart
if tt.nextAutostart == nil {
nextAutostart = func(now time.Time) time.Time { return time.Time{} }
}
var (
now = dbtime.Now()
ctx = testutil.Context(t, testutil.WaitShort)
log = slogtest.Make(t, nil)
db, _ = dbtestutil.NewDB(t, dbtestutil.WithTimezone(tz))
org = dbgen.Organization(t, db, database.Organization{})
user = dbgen.User(t, db, database.User{
Status: database.UserStatusActive,
})
_ = dbgen.OrganizationMember(t, db, database.OrganizationMember{
UserID: user.ID,
OrganizationID: org.ID,
})
templateVersion = dbgen.TemplateVersion(t, db, database.TemplateVersion{
OrganizationID: org.ID,
CreatedBy: user.ID,
})
template = dbgen.Template(t, db, database.Template{
OrganizationID: org.ID,
ActiveVersionID: templateVersion.ID,
CreatedBy: user.ID,
})
ws = dbgen.Workspace(t, db, database.Workspace{
OwnerID: user.ID,
OrganizationID: org.ID,
TemplateID: template.ID,
Ttl: sql.NullInt64{Valid: true, Int64: int64(tt.workspaceTTL)},
})
job = dbgen.ProvisionerJob(t, db, nil, database.ProvisionerJob{
OrganizationID: org.ID,
CompletedAt: tt.jobCompletedAt,
})
_ = dbgen.WorkspaceResource(t, db, database.WorkspaceResource{
JobID: job.ID,
})
buildID = uuid.New()
)
activityBump := 1 * time.Hour
if tt.templateActivityBump < 0 {
// less than 0 => 0
activityBump = 0
} else if tt.templateActivityBump != 0 {
activityBump = tt.templateActivityBump
}
require.NoError(t, db.UpdateTemplateScheduleByID(ctx, database.UpdateTemplateScheduleByIDParams{
ID: template.ID,
UpdatedAt: dbtime.Now(),
AllowUserAutostop: !tt.templateDisallowsUserAutostop,
DefaultTTL: int64(tt.templateTTL),
ActivityBump: int64(activityBump),
}), "unexpected error updating template schedule")
var buildNumber int32 = 1
// Insert a number of previous workspace builds.
for i := 0; i < 5; i++ {
insertPrevWorkspaceBuild(t, db, org.ID, templateVersion.ID, ws.ID, database.WorkspaceTransitionStart, buildNumber)
buildNumber++
insertPrevWorkspaceBuild(t, db, org.ID, templateVersion.ID, ws.ID, database.WorkspaceTransitionStop, buildNumber)
buildNumber++
}
// dbgen.WorkspaceBuild automatically sets deadline to now+1 hour if not set
var buildDeadline time.Time
if tt.buildDeadlineOffset != nil {
buildDeadline = now.Add(*tt.buildDeadlineOffset)
}
var maxDeadline time.Time
if tt.maxDeadlineOffset != nil {
maxDeadline = now.Add(*tt.maxDeadlineOffset)
}
err := db.InsertWorkspaceBuild(ctx, database.InsertWorkspaceBuildParams{
ID: buildID,
CreatedAt: dbtime.Now(),
UpdatedAt: dbtime.Now(),
BuildNumber: buildNumber,
InitiatorID: user.ID,
Reason: database.BuildReasonInitiator,
WorkspaceID: ws.ID,
JobID: job.ID,
TemplateVersionID: templateVersion.ID,
Transition: tt.transition,
Deadline: buildDeadline,
MaxDeadline: maxDeadline,
})
require.NoError(t, err, "unexpected error inserting workspace build")
bld, err := db.GetWorkspaceBuildByID(ctx, buildID)
require.NoError(t, err, "unexpected error fetching inserted workspace build")
// Validate our initial state before bump
require.Equal(t, tt.transition, bld.Transition, "unexpected transition before bump")
require.Equal(t, tt.jobCompletedAt.Time.UTC(), job.CompletedAt.Time.UTC(), "unexpected job completed at before bump")
require.Equal(t, buildDeadline.UTC(), bld.Deadline.UTC(), "unexpected build deadline before bump")
require.Equal(t, maxDeadline.UTC(), bld.MaxDeadline.UTC(), "unexpected max deadline before bump")
require.Equal(t, tt.workspaceTTL, time.Duration(ws.Ttl.Int64), "unexpected workspace TTL before bump")
// Wait a bit before bumping as dbtime is rounded to the nearest millisecond.
// This should also hopefully be enough for Windows time resolution to register
// a tick (win32 max timer resolution is apparently between 0.5 and 15.6ms)
<-time.After(testutil.IntervalFast)
// Bump duration is measured from the time of the bump, so we measure from here.
start := dbtime.Now()
workspacestats.ActivityBumpWorkspace(ctx, log, db, bld.WorkspaceID, nextAutostart(start))
end := dbtime.Now()
// Validate our state after bump
updatedBuild, err := db.GetLatestWorkspaceBuildByWorkspaceID(ctx, bld.WorkspaceID)
require.NoError(t, err, "unexpected error getting latest workspace build")
require.Equal(t, bld.MaxDeadline.UTC(), updatedBuild.MaxDeadline.UTC(), "max_deadline should not have changed")
if tt.expectedBump == 0 {
assert.Equal(t, bld.UpdatedAt.UTC(), updatedBuild.UpdatedAt.UTC(), "should not have bumped updated_at")
assert.Equal(t, bld.Deadline.UTC(), updatedBuild.Deadline.UTC(), "should not have bumped deadline")
return
}
assert.NotEqual(t, bld.UpdatedAt.UTC(), updatedBuild.UpdatedAt.UTC(), "should have bumped updated_at")
if tt.maxDeadlineOffset != nil {
assert.Equal(t, bld.MaxDeadline.UTC(), updatedBuild.MaxDeadline.UTC(), "new deadline must equal original max deadline")
return
}
// Assert that the bump occurred between start and end. 1min buffer on either side.
expectedDeadlineStart := start.Add(tt.expectedBump).Add(time.Minute * -1)
expectedDeadlineEnd := end.Add(tt.expectedBump).Add(time.Minute)
require.GreaterOrEqual(t, updatedBuild.Deadline, expectedDeadlineStart, "new deadline should be greater than or equal to start")
require.LessOrEqual(t, updatedBuild.Deadline, expectedDeadlineEnd, "new deadline should be less than or equal to end")
})
}
}
}
func insertPrevWorkspaceBuild(t *testing.T, db database.Store, orgID, tvID, workspaceID uuid.UUID, transition database.WorkspaceTransition, buildNumber int32) {
t.Helper()
job := dbgen.ProvisionerJob(t, db, nil, database.ProvisionerJob{
OrganizationID: orgID,
})
_ = dbgen.WorkspaceResource(t, db, database.WorkspaceResource{
JobID: job.ID,
})
_ = dbgen.WorkspaceBuild(t, db, database.WorkspaceBuild{
BuildNumber: buildNumber,
WorkspaceID: workspaceID,
JobID: job.ID,
TemplateVersionID: tvID,
Transition: transition,
})
}
+194
View File
@@ -0,0 +1,194 @@
package workspacestats
import (
"context"
"sync/atomic"
"time"
"github.com/google/uuid"
"golang.org/x/sync/errgroup"
"golang.org/x/xerrors"
"cdr.dev/slog"
agentproto "github.com/coder/coder/v2/agent/proto"
"github.com/coder/coder/v2/coderd/database"
"github.com/coder/coder/v2/coderd/database/dbtime"
"github.com/coder/coder/v2/coderd/database/pubsub"
"github.com/coder/coder/v2/coderd/prometheusmetrics"
"github.com/coder/coder/v2/coderd/schedule"
"github.com/coder/coder/v2/coderd/util/slice"
"github.com/coder/coder/v2/coderd/workspaceapps"
"github.com/coder/coder/v2/codersdk"
)
type StatsBatcher interface {
Add(now time.Time, agentID uuid.UUID, templateID uuid.UUID, userID uuid.UUID, workspaceID uuid.UUID, st *agentproto.Stats) error
}
type ReporterOptions struct {
Database database.Store
Logger slog.Logger
Pubsub pubsub.Pubsub
TemplateScheduleStore *atomic.Pointer[schedule.TemplateScheduleStore]
StatsBatcher StatsBatcher
UpdateAgentMetricsFn func(ctx context.Context, labels prometheusmetrics.AgentMetricLabels, metrics []*agentproto.Stats_Metric)
AppStatBatchSize int
}
type Reporter struct {
opts ReporterOptions
}
func NewReporter(opts ReporterOptions) *Reporter {
return &Reporter{opts: opts}
}
func (r *Reporter) ReportAppStats(ctx context.Context, stats []workspaceapps.StatsReport) error {
err := r.opts.Database.InTx(func(tx database.Store) error {
maxBatchSize := r.opts.AppStatBatchSize
if len(stats) < maxBatchSize {
maxBatchSize = len(stats)
}
batch := database.InsertWorkspaceAppStatsParams{
UserID: make([]uuid.UUID, 0, maxBatchSize),
WorkspaceID: make([]uuid.UUID, 0, maxBatchSize),
AgentID: make([]uuid.UUID, 0, maxBatchSize),
AccessMethod: make([]string, 0, maxBatchSize),
SlugOrPort: make([]string, 0, maxBatchSize),
SessionID: make([]uuid.UUID, 0, maxBatchSize),
SessionStartedAt: make([]time.Time, 0, maxBatchSize),
SessionEndedAt: make([]time.Time, 0, maxBatchSize),
Requests: make([]int32, 0, maxBatchSize),
}
for _, stat := range stats {
batch.UserID = append(batch.UserID, stat.UserID)
batch.WorkspaceID = append(batch.WorkspaceID, stat.WorkspaceID)
batch.AgentID = append(batch.AgentID, stat.AgentID)
batch.AccessMethod = append(batch.AccessMethod, string(stat.AccessMethod))
batch.SlugOrPort = append(batch.SlugOrPort, stat.SlugOrPort)
batch.SessionID = append(batch.SessionID, stat.SessionID)
batch.SessionStartedAt = append(batch.SessionStartedAt, stat.SessionStartedAt)
batch.SessionEndedAt = append(batch.SessionEndedAt, stat.SessionEndedAt)
batch.Requests = append(batch.Requests, int32(stat.Requests))
if len(batch.UserID) >= r.opts.AppStatBatchSize {
err := tx.InsertWorkspaceAppStats(ctx, batch)
if err != nil {
return err
}
// Reset batch.
batch.UserID = batch.UserID[:0]
batch.WorkspaceID = batch.WorkspaceID[:0]
batch.AgentID = batch.AgentID[:0]
batch.AccessMethod = batch.AccessMethod[:0]
batch.SlugOrPort = batch.SlugOrPort[:0]
batch.SessionID = batch.SessionID[:0]
batch.SessionStartedAt = batch.SessionStartedAt[:0]
batch.SessionEndedAt = batch.SessionEndedAt[:0]
batch.Requests = batch.Requests[:0]
}
}
if len(batch.UserID) == 0 {
return nil
}
if err := tx.InsertWorkspaceAppStats(ctx, batch); err != nil {
return err
}
// TODO: We currently measure workspace usage based on when we get stats from it.
// There are currently two paths for this:
// 1) From SSH -> workspace agent stats POSTed from agent
// 2) From workspace apps / rpty -> workspace app stats (from coderd / wsproxy)
// Ideally we would have a single code path for this.
uniqueIDs := slice.Unique(batch.WorkspaceID)
if err := tx.BatchUpdateWorkspaceLastUsedAt(ctx, database.BatchUpdateWorkspaceLastUsedAtParams{
IDs: uniqueIDs,
LastUsedAt: dbtime.Now(), // This isn't 100% accurate, but it's good enough.
}); err != nil {
return err
}
return nil
}, nil)
if err != nil {
return xerrors.Errorf("insert workspace app stats failed: %w", err)
}
return nil
}
func (r *Reporter) ReportAgentStats(ctx context.Context, now time.Time, workspace database.Workspace, workspaceAgent database.WorkspaceAgent, templateName string, stats *agentproto.Stats) error {
if stats.ConnectionCount > 0 {
var nextAutostart time.Time
if workspace.AutostartSchedule.String != "" {
templateSchedule, err := (*(r.opts.TemplateScheduleStore.Load())).Get(ctx, r.opts.Database, workspace.TemplateID)
// If the template schedule fails to load, just default to bumping
// without the next transition and log it.
if err != nil {
r.opts.Logger.Error(ctx, "failed to load template schedule bumping activity, defaulting to bumping by 60min",
slog.F("workspace_id", workspace.ID),
slog.F("template_id", workspace.TemplateID),
slog.Error(err),
)
} else {
next, allowed := schedule.NextAutostart(now, workspace.AutostartSchedule.String, templateSchedule)
if allowed {
nextAutostart = next
}
}
}
ActivityBumpWorkspace(ctx, r.opts.Logger.Named("activity_bump"), r.opts.Database, workspace.ID, nextAutostart)
}
var errGroup errgroup.Group
errGroup.Go(func() error {
err := r.opts.StatsBatcher.Add(now, workspaceAgent.ID, workspace.TemplateID, workspace.OwnerID, workspace.ID, stats)
if err != nil {
r.opts.Logger.Error(ctx, "add agent stats to batcher", slog.Error(err))
return xerrors.Errorf("insert workspace agent stats batch: %w", err)
}
return nil
})
errGroup.Go(func() error {
err := r.opts.Database.UpdateWorkspaceLastUsedAt(ctx, database.UpdateWorkspaceLastUsedAtParams{
ID: workspace.ID,
LastUsedAt: now,
})
if err != nil {
return xerrors.Errorf("update workspace LastUsedAt: %w", err)
}
return nil
})
if r.opts.UpdateAgentMetricsFn != nil {
errGroup.Go(func() error {
user, err := r.opts.Database.GetUserByID(ctx, workspace.OwnerID)
if err != nil {
return xerrors.Errorf("get user: %w", err)
}
r.opts.UpdateAgentMetricsFn(ctx, prometheusmetrics.AgentMetricLabels{
Username: user.Username,
WorkspaceName: workspace.Name,
AgentName: workspaceAgent.Name,
TemplateName: templateName,
}, stats.Metrics)
return nil
})
}
err := errGroup.Wait()
if err != nil {
return xerrors.Errorf("update stats in database: %w", err)
}
err = r.opts.Pubsub.Publish(codersdk.WorkspaceNotifyChannel(workspace.ID), []byte{})
if err != nil {
r.opts.Logger.Warn(ctx, "failed to publish workspace agent stats",
slog.F("workspace_id", workspace.ID), slog.Error(err))
}
return nil
}