From 73f19d6ae56a65a6aa69247e0b1b72e5c8adb4eb Mon Sep 17 00:00:00 2001 From: Mathias Fredriksson Date: Mon, 19 Jun 2023 11:11:44 +0000 Subject: [PATCH 1/3] refactor: Replace startup script logs EOF with starting/ready time This commit reverts some of the changes in #8029 and implements an alternative method of keeping track of when the startup script has ended and there will be no more logs. This is achieved by adding new agent fields for tracking when the agent enters the "starting" and "ready"/"start_error" lifecycle states. The timestamps simplify logic since we don't need understand if the current state is before or after the state we're interested in. They can also be used to show data like how long the startup script took to execute. This also allowed us to remove the EOF field from the logs as the implementation was problematic when we returned the EOF log entry in the response since requesting _after_ that ID would give no logs and the API would thus lose track of EOF. --- agent/agent.go | 128 ++++++++------ agent/agent_test.go | 57 +------ coderd/apidoc/docs.go | 18 +- coderd/apidoc/swagger.json | 18 +- coderd/database/dbauthz/dbauthz.go | 23 +-- coderd/database/dbfake/dbfake.go | 34 ++-- coderd/database/dbmetrics/dbmetrics.go | 14 +- coderd/database/dbmock/dbmock.go | 30 ++-- coderd/database/dump.sql | 11 +- ...artup_logs_eof_and_add_completion.down.sql | 11 ++ ...startup_logs_eof_and_add_completion.up.sql | 14 ++ coderd/database/models.go | 6 +- coderd/database/querier.go | 2 +- coderd/database/querier_test.go | 2 - coderd/database/queries.sql.go | 100 ++++++----- coderd/database/queries/workspaceagents.sql | 32 ++-- coderd/workspaceagents.go | 159 +++++++++--------- coderd/workspaceagents_test.go | 152 ++--------------- codersdk/agentsdk/agentsdk.go | 4 +- codersdk/workspaceagents.go | 56 +++--- docs/api/agents.md | 18 +- docs/api/builds.md | 16 ++ docs/api/schemas.md | 37 ++-- docs/api/templates.md | 8 + docs/api/workspaces.md | 8 + scripts/coder-dev.sh | 3 + site/src/api/typesGenerated.ts | 7 +- site/src/components/Resources/AgentRow.tsx | 10 +- site/src/testHelpers/entities.ts | 11 -- .../workspaceAgentLogsXService.ts | 11 +- 30 files changed, 462 insertions(+), 538 deletions(-) create mode 100644 coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.down.sql create mode 100644 coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.up.sql diff --git a/agent/agent.go b/agent/agent.go index a60471c32a7aa..eb30680577cf2 100644 --- a/agent/agent.go +++ b/agent/agent.go @@ -14,6 +14,7 @@ import ( "net/http" "net/netip" "os" + "os/exec" "os/user" "path/filepath" "sort" @@ -126,6 +127,7 @@ func New(options Options) Agent { tempDir: options.TempDir, lifecycleUpdate: make(chan struct{}, 1), lifecycleReported: make(chan codersdk.WorkspaceAgentLifecycle, 1), + lifecycleStates: []agentsdk.PostLifecycleRequest{{State: codersdk.WorkspaceAgentLifecycleCreated}}, ignorePorts: options.IgnorePorts, connStatsChan: make(chan *agentsdk.Stats, 1), sshMaxTimeout: options.SSHMaxTimeout, @@ -170,7 +172,7 @@ type agent struct { lifecycleUpdate chan struct{} lifecycleReported chan codersdk.WorkspaceAgentLifecycle lifecycleMu sync.RWMutex // Protects following. - lifecycleState codersdk.WorkspaceAgentLifecycle + lifecycleStates []agentsdk.PostLifecycleRequest network *tailnet.Conn connStatsChan chan *agentsdk.Stats @@ -414,11 +416,10 @@ func (a *agent) reportMetadataLoop(ctx context.Context) { } } -// reportLifecycleLoop reports the current lifecycle state once. -// Only the latest state is reported, intermediate states may be -// lost if the agent can't communicate with the API. +// reportLifecycleLoop reports the current lifecycle state once. All state +// changes are reported in order. func (a *agent) reportLifecycleLoop(ctx context.Context) { - var lastReported codersdk.WorkspaceAgentLifecycle + lastReportedIndex := 0 // Start off with the created state without reporting it. for { select { case <-a.lifecycleUpdate: @@ -428,24 +429,32 @@ func (a *agent) reportLifecycleLoop(ctx context.Context) { for r := retry.New(time.Second, 15*time.Second); r.Wait(ctx); { a.lifecycleMu.RLock() - state := a.lifecycleState + lastIndex := len(a.lifecycleStates) - 1 + report := a.lifecycleStates[lastReportedIndex] + if len(a.lifecycleStates) > lastReportedIndex+1 { + report = a.lifecycleStates[lastReportedIndex+1] + } a.lifecycleMu.RUnlock() - if state == lastReported { + if lastIndex == lastReportedIndex { break } - a.logger.Debug(ctx, "reporting lifecycle state", slog.F("state", state)) + a.logger.Debug(ctx, "reporting lifecycle state", slog.F("payload", report)) - err := a.client.PostLifecycle(ctx, agentsdk.PostLifecycleRequest{ - State: state, - }) + err := a.client.PostLifecycle(ctx, report) if err == nil { - lastReported = state + lastReportedIndex++ select { - case a.lifecycleReported <- state: + case a.lifecycleReported <- report.State: case <-a.lifecycleReported: - a.lifecycleReported <- state + a.lifecycleReported <- report.State + } + if lastReportedIndex < lastIndex { + // Keep reporting until we've sent all messages, we can't + // rely on the channel triggering us before the backlog is + // consumed. + continue } break } @@ -461,15 +470,20 @@ func (a *agent) reportLifecycleLoop(ctx context.Context) { // setLifecycle sets the lifecycle state and notifies the lifecycle loop. // The state is only updated if it's a valid state transition. func (a *agent) setLifecycle(ctx context.Context, state codersdk.WorkspaceAgentLifecycle) { + report := agentsdk.PostLifecycleRequest{ + State: state, + ChangedAt: database.Now(), + } + a.lifecycleMu.Lock() - lastState := a.lifecycleState - if slices.Index(codersdk.WorkspaceAgentLifecycleOrder, lastState) > slices.Index(codersdk.WorkspaceAgentLifecycleOrder, state) { - a.logger.Warn(ctx, "attempted to set lifecycle state to a previous state", slog.F("last", lastState), slog.F("state", state)) + lastReport := a.lifecycleStates[len(a.lifecycleStates)-1] + if slices.Index(codersdk.WorkspaceAgentLifecycleOrder, lastReport.State) >= slices.Index(codersdk.WorkspaceAgentLifecycleOrder, report.State) { + a.logger.Warn(ctx, "attempted to set lifecycle state to a previous state", slog.F("last", lastReport), slog.F("current", report)) a.lifecycleMu.Unlock() return } - a.lifecycleState = state - a.logger.Debug(ctx, "set lifecycle state", slog.F("state", state), slog.F("last", lastState)) + a.lifecycleStates = append(a.lifecycleStates, report) + a.logger.Debug(ctx, "set lifecycle state", slog.F("current", report), slog.F("last", lastReport)) a.lifecycleMu.Unlock() select { @@ -534,7 +548,6 @@ func (a *agent) run(ctx context.Context) error { lifecycleState := codersdk.WorkspaceAgentLifecycleReady scriptDone := make(chan error, 1) - scriptStart := time.Now() err = a.trackConnGoroutine(func() { defer close(scriptDone) scriptDone <- a.runStartupScript(ctx, manifest.StartupScript) @@ -556,22 +569,15 @@ func (a *agent) run(ctx context.Context) error { select { case err = <-scriptDone: case <-timeout: - a.logger.Warn(ctx, "startup script timed out") + a.logger.Warn(ctx, "script timed out", slog.F("lifecycle", "startup"), slog.F("timeout", manifest.ShutdownScriptTimeout)) a.setLifecycle(ctx, codersdk.WorkspaceAgentLifecycleStartTimeout) err = <-scriptDone // The script can still complete after a timeout. } - if errors.Is(err, context.Canceled) { - return - } - // Only log if there was a startup script. - if manifest.StartupScript != "" { - execTime := time.Since(scriptStart) - if err != nil { - a.logger.Warn(ctx, "startup script failed", slog.F("execution_time", execTime), slog.Error(err)) - lifecycleState = codersdk.WorkspaceAgentLifecycleStartError - } else { - a.logger.Info(ctx, "startup script completed", slog.F("execution_time", execTime)) + if err != nil { + if errors.Is(err, context.Canceled) { + return } + lifecycleState = codersdk.WorkspaceAgentLifecycleStartError } a.setLifecycle(ctx, lifecycleState) }() @@ -830,20 +836,32 @@ func (a *agent) runShutdownScript(ctx context.Context, script string) error { return a.runScript(ctx, "shutdown", script) } -func (a *agent) runScript(ctx context.Context, lifecycle, script string) error { +func (a *agent) runScript(ctx context.Context, lifecycle, script string) (err error) { + logger := a.logger.With(slog.F("lifecycle", lifecycle)) + if script == "" { + logger.Info(ctx, "not running empty script") return nil } - a.logger.Info(ctx, "running script", slog.F("lifecycle", lifecycle), slog.F("script", script)) + logger.Info(ctx, "running script", slog.F("script", script)) fileWriter, err := a.filesystem.OpenFile(filepath.Join(a.logDir, fmt.Sprintf("coder-%s-script.log", lifecycle)), os.O_CREATE|os.O_RDWR, 0o600) if err != nil { return xerrors.Errorf("open %s script log file: %w", lifecycle, err) } defer func() { - _ = fileWriter.Close() + err := fileWriter.Close() + if err != nil { + logger.Warn(ctx, "close script log file", slog.Error(err)) + } }() + cmdPty, err := a.sshServer.CreateCommand(ctx, script, nil) + if err != nil { + return xerrors.Errorf("create command: %w", err) + } + cmd := cmdPty.AsExec() + var writer io.Writer = fileWriter if lifecycle == "startup" { // Create pipes for startup logs reader and writer @@ -862,13 +880,26 @@ func (a *agent) runScript(ctx context.Context, lifecycle, script string) error { }() } - cmdPty, err := a.sshServer.CreateCommand(ctx, script, nil) - if err != nil { - return xerrors.Errorf("create command: %w", err) - } - cmd := cmdPty.AsExec() cmd.Stdout = writer cmd.Stderr = writer + + start := time.Now() + defer func() { + end := time.Now() + execTime := end.Sub(start) + exitCode := 0 + if err != nil { + exitCode = 255 // Unknown status. + var exitError *exec.ExitError + if xerrors.As(err, &exitError) { + exitCode = exitError.ExitCode() + } + logger.Warn(ctx, "script failed", slog.F("execution_time", execTime), slog.F("exit_code", exitCode), slog.Error(err)) + } else { + logger.Info(ctx, "script completed", slog.F("execution_time", execTime), slog.F("exit_code", exitCode)) + } + }() + err = cmd.Run() if err != nil { // cmd.Run does not return a context canceled error, it returns "signal: killed". @@ -929,11 +960,6 @@ func (a *agent) trackScriptLogs(ctx context.Context, reader io.Reader) (chan str if errors.As(err, &sdkErr) { if sdkErr.StatusCode() == http.StatusRequestEntityTooLarge { a.logger.Warn(ctx, "startup logs too large, dropping logs") - // Always send the EOF even if logs overflow. - if len(logsToSend) > 1 && logsToSend[len(logsToSend)-1].EOF { - logsToSend = logsToSend[len(logsToSend)-1:] - continue - } break } } @@ -986,11 +1012,6 @@ func (a *agent) trackScriptLogs(ctx context.Context, reader io.Reader) (chan str if err := scanner.Err(); err != nil { a.logger.Error(ctx, "scan startup logs", slog.Error(err)) } - queueLog(agentsdk.StartupLog{ - CreatedAt: database.Now(), - Output: "", - EOF: true, - }) defer close(logsFinished) logsFlushed.L.Lock() for { @@ -1392,7 +1413,6 @@ func (a *agent) Close() error { lifecycleState := codersdk.WorkspaceAgentLifecycleOff if manifest := a.manifest.Load(); manifest != nil && manifest.ShutdownScript != "" { scriptDone := make(chan error, 1) - scriptStart := time.Now() go func() { defer close(scriptDone) scriptDone <- a.runShutdownScript(ctx, manifest.ShutdownScript) @@ -1411,16 +1431,12 @@ func (a *agent) Close() error { select { case err = <-scriptDone: case <-timeout: - a.logger.Warn(ctx, "shutdown script timed out") + a.logger.Warn(ctx, "script timed out", slog.F("lifecycle", "shutdown"), slog.F("timeout", manifest.ShutdownScriptTimeout)) a.setLifecycle(ctx, codersdk.WorkspaceAgentLifecycleShutdownTimeout) err = <-scriptDone // The script can still complete after a timeout. } - execTime := time.Since(scriptStart) if err != nil { - a.logger.Warn(ctx, "shutdown script failed", slog.F("execution_time", execTime), slog.Error(err)) lifecycleState = codersdk.WorkspaceAgentLifecycleShutdownError - } else { - a.logger.Info(ctx, "shutdown script completed", slog.F("execution_time", execTime)) } } diff --git a/agent/agent_test.go b/agent/agent_test.go index 0c15269343a40..1a16fa7cab612 100644 --- a/agent/agent_test.go +++ b/agent/agent_test.go @@ -905,10 +905,8 @@ func TestAgent_StartupScript(t *testing.T) { return len(got) > 0 && got[len(got)-1] == codersdk.WorkspaceAgentLifecycleReady }, testutil.WaitShort, testutil.IntervalMedium) - require.Len(t, client.getStartupLogs(), 2) + require.Len(t, client.getStartupLogs(), 1) require.Equal(t, output, client.getStartupLogs()[0].Output) - require.False(t, client.getStartupLogs()[0].EOF) - require.True(t, client.getStartupLogs()[1].EOF) }) // This ensures that even when coderd sends back that the startup // script has written too many lines it will still succeed! @@ -1115,15 +1113,8 @@ func TestAgent_Lifecycle(t *testing.T) { got = client.getLifecycleStates() return len(got) > 0 && got[len(got)-1] == want[len(want)-1] }, testutil.WaitShort, testutil.IntervalMedium) - switch len(got) { - case 1: - // This can happen if lifecycle state updates are - // too fast, only the latest one is reported. - require.Equal(t, want[1:], got) - default: - // This is the expected case. - require.Equal(t, want, got) - } + + require.Equal(t, want, got) }) t.Run("StartError", func(t *testing.T) { @@ -1144,15 +1135,8 @@ func TestAgent_Lifecycle(t *testing.T) { got = client.getLifecycleStates() return len(got) > 0 && got[len(got)-1] == want[len(want)-1] }, testutil.WaitShort, testutil.IntervalMedium) - switch len(got) { - case 1: - // This can happen if lifecycle state updates are - // too fast, only the latest one is reported. - require.Equal(t, want[1:], got) - default: - // This is the expected case. - require.Equal(t, want, got) - } + + require.Equal(t, want, got) }) t.Run("Ready", func(t *testing.T) { @@ -1173,15 +1157,8 @@ func TestAgent_Lifecycle(t *testing.T) { got = client.getLifecycleStates() return len(got) > 0 && got[len(got)-1] == want[len(want)-1] }, testutil.WaitShort, testutil.IntervalMedium) - switch len(got) { - case 1: - // This can happen if lifecycle state updates are - // too fast, only the latest one is reported. - require.Equal(t, want[1:], got) - default: - // This is the expected case. - require.Equal(t, want, got) - } + + require.Equal(t, want, got) }) t.Run("ShuttingDown", func(t *testing.T) { @@ -1258,15 +1235,7 @@ func TestAgent_Lifecycle(t *testing.T) { return len(got) > 0 && got[len(got)-1] == want[len(want)-1] }, testutil.WaitShort, testutil.IntervalMedium) - switch len(got) { - case 1: - // This can happen if lifecycle state updates are - // too fast, only the latest one is reported. - require.Equal(t, want[1:], got) - default: - // This is the expected case. - require.Equal(t, want, got) - } + require.Equal(t, want, got) }) t.Run("ShutdownError", func(t *testing.T) { @@ -1305,15 +1274,7 @@ func TestAgent_Lifecycle(t *testing.T) { return len(got) > 0 && got[len(got)-1] == want[len(want)-1] }, testutil.WaitShort, testutil.IntervalMedium) - switch len(got) { - case 1: - // This can happen if lifecycle state updates are - // too fast, only the latest one is reported. - require.Equal(t, want[1:], got) - default: - // This is the expected case. - require.Equal(t, want, got) - } + require.Equal(t, want, got) }) t.Run("ShutdownScriptOnce", func(t *testing.T) { diff --git a/coderd/apidoc/docs.go b/coderd/apidoc/docs.go index 4ea7036e01129..c2ca170360a26 100644 --- a/coderd/apidoc/docs.go +++ b/coderd/apidoc/docs.go @@ -5812,6 +5812,9 @@ const docTemplate = `{ "agentsdk.PostLifecycleRequest": { "type": "object", "properties": { + "changed_at": { + "type": "string" + }, "state": { "$ref": "#/definitions/codersdk.WorkspaceAgentLifecycle" } @@ -5856,9 +5859,6 @@ const docTemplate = `{ "created_at": { "type": "string" }, - "eof": { - "type": "boolean" - }, "level": { "$ref": "#/definitions/codersdk.LogLevel" }, @@ -9249,6 +9249,10 @@ const docTemplate = `{ "operating_system": { "type": "string" }, + "ready_at": { + "type": "string", + "format": "date-time" + }, "resource_id": { "type": "string", "format": "uuid" @@ -9259,6 +9263,10 @@ const docTemplate = `{ "shutdown_script_timeout_seconds": { "type": "integer" }, + "started_at": { + "type": "string", + "format": "date-time" + }, "startup_logs_length": { "type": "integer" }, @@ -9381,10 +9389,6 @@ const docTemplate = `{ "type": "string", "format": "date-time" }, - "eof": { - "description": "EOF indicates that this is the last log entry and the file is closed.", - "type": "boolean" - }, "id": { "type": "integer" }, diff --git a/coderd/apidoc/swagger.json b/coderd/apidoc/swagger.json index eea32d65ade16..94af600c51a1a 100644 --- a/coderd/apidoc/swagger.json +++ b/coderd/apidoc/swagger.json @@ -5127,6 +5127,9 @@ "agentsdk.PostLifecycleRequest": { "type": "object", "properties": { + "changed_at": { + "type": "string" + }, "state": { "$ref": "#/definitions/codersdk.WorkspaceAgentLifecycle" } @@ -5171,9 +5174,6 @@ "created_at": { "type": "string" }, - "eof": { - "type": "boolean" - }, "level": { "$ref": "#/definitions/codersdk.LogLevel" }, @@ -8345,6 +8345,10 @@ "operating_system": { "type": "string" }, + "ready_at": { + "type": "string", + "format": "date-time" + }, "resource_id": { "type": "string", "format": "uuid" @@ -8355,6 +8359,10 @@ "shutdown_script_timeout_seconds": { "type": "integer" }, + "started_at": { + "type": "string", + "format": "date-time" + }, "startup_logs_length": { "type": "integer" }, @@ -8477,10 +8485,6 @@ "type": "string", "format": "date-time" }, - "eof": { - "description": "EOF indicates that this is the last log entry and the file is closed.", - "type": "boolean" - }, "id": { "type": "integer" }, diff --git a/coderd/database/dbauthz/dbauthz.go b/coderd/database/dbauthz/dbauthz.go index dc8b10e5a1f27..27c2cbad88d91 100644 --- a/coderd/database/dbauthz/dbauthz.go +++ b/coderd/database/dbauthz/dbauthz.go @@ -1385,6 +1385,14 @@ func (q *querier) GetWorkspaceAgentByInstanceID(ctx context.Context, authInstanc return agent, nil } +func (q *querier) GetWorkspaceAgentLifecycleStateByID(ctx context.Context, id uuid.UUID) (database.GetWorkspaceAgentLifecycleStateByIDRow, error) { + _, err := q.GetWorkspaceAgentByID(ctx, id) + if err != nil { + return database.GetWorkspaceAgentLifecycleStateByIDRow{}, err + } + return q.db.GetWorkspaceAgentLifecycleStateByID(ctx, id) +} + func (q *querier) GetWorkspaceAgentMetadata(ctx context.Context, workspaceAgentID uuid.UUID) ([]database.WorkspaceAgentMetadatum, error) { workspace, err := q.db.GetWorkspaceByAgentID(ctx, workspaceAgentID) if err != nil { @@ -1407,14 +1415,6 @@ func (q *querier) GetWorkspaceAgentStartupLogsAfter(ctx context.Context, arg dat return q.db.GetWorkspaceAgentStartupLogsAfter(ctx, arg) } -func (q *querier) GetWorkspaceAgentStartupLogsEOF(ctx context.Context, agentID uuid.UUID) (bool, error) { - _, err := q.GetWorkspaceAgentByID(ctx, agentID) - if err != nil { - return false, err - } - return q.db.GetWorkspaceAgentStartupLogsEOF(ctx, agentID) -} - func (q *querier) GetWorkspaceAgentStats(ctx context.Context, createdAfter time.Time) ([]database.GetWorkspaceAgentStatsRow, error) { return q.db.GetWorkspaceAgentStats(ctx, createdAfter) } @@ -2324,12 +2324,7 @@ func (q *querier) UpdateWorkspaceAgentConnectionByID(ctx context.Context, arg da } func (q *querier) UpdateWorkspaceAgentLifecycleStateByID(ctx context.Context, arg database.UpdateWorkspaceAgentLifecycleStateByIDParams) error { - agent, err := q.db.GetWorkspaceAgentByID(ctx, arg.ID) - if err != nil { - return err - } - - workspace, err := q.db.GetWorkspaceByAgentID(ctx, agent.ID) + workspace, err := q.db.GetWorkspaceByAgentID(ctx, arg.ID) if err != nil { return err } diff --git a/coderd/database/dbfake/dbfake.go b/coderd/database/dbfake/dbfake.go index ede8c6cef69d7..fd527764654b7 100644 --- a/coderd/database/dbfake/dbfake.go +++ b/coderd/database/dbfake/dbfake.go @@ -2696,6 +2696,21 @@ func (q *fakeQuerier) GetWorkspaceAgentByInstanceID(_ context.Context, instanceI return database.WorkspaceAgent{}, sql.ErrNoRows } +func (q *fakeQuerier) GetWorkspaceAgentLifecycleStateByID(ctx context.Context, id uuid.UUID) (database.GetWorkspaceAgentLifecycleStateByIDRow, error) { + q.mutex.RLock() + defer q.mutex.RUnlock() + + agent, err := q.getWorkspaceAgentByIDNoLock(ctx, id) + if err != nil { + return database.GetWorkspaceAgentLifecycleStateByIDRow{}, err + } + return database.GetWorkspaceAgentLifecycleStateByIDRow{ + LifecycleState: agent.LifecycleState, + StartedAt: agent.StartedAt, + ReadyAt: agent.ReadyAt, + }, nil +} + func (q *fakeQuerier) GetWorkspaceAgentMetadata(_ context.Context, workspaceAgentID uuid.UUID) ([]database.WorkspaceAgentMetadatum, error) { q.mutex.RLock() defer q.mutex.RUnlock() @@ -2730,22 +2745,6 @@ func (q *fakeQuerier) GetWorkspaceAgentStartupLogsAfter(_ context.Context, arg d return logs, nil } -func (q *fakeQuerier) GetWorkspaceAgentStartupLogsEOF(_ context.Context, agentID uuid.UUID) (bool, error) { - q.mutex.RLock() - defer q.mutex.RUnlock() - - var lastLog database.WorkspaceAgentStartupLog - for _, log := range q.workspaceAgentLogs { - if log.AgentID != agentID { - continue - } - if log.ID > lastLog.ID { - lastLog = log - } - } - return lastLog.EOF, nil -} - func (q *fakeQuerier) GetWorkspaceAgentStats(_ context.Context, createdAfter time.Time) ([]database.GetWorkspaceAgentStatsRow, error) { q.mutex.RLock() defer q.mutex.RUnlock() @@ -4042,7 +4041,6 @@ func (q *fakeQuerier) InsertWorkspaceAgentStartupLogs(_ context.Context, arg dat CreatedAt: arg.CreatedAt[index], Level: arg.Level[index], Output: output, - EOF: arg.EOF[index], }) outputLength += int32(len(output)) } @@ -4901,6 +4899,8 @@ func (q *fakeQuerier) UpdateWorkspaceAgentLifecycleStateByID(_ context.Context, for i, agent := range q.workspaceAgents { if agent.ID == arg.ID { agent.LifecycleState = arg.LifecycleState + agent.StartedAt = arg.StartedAt + agent.ReadyAt = arg.ReadyAt q.workspaceAgents[i] = agent return nil } diff --git a/coderd/database/dbmetrics/dbmetrics.go b/coderd/database/dbmetrics/dbmetrics.go index 416ad3a9a368d..c6d15359f4022 100644 --- a/coderd/database/dbmetrics/dbmetrics.go +++ b/coderd/database/dbmetrics/dbmetrics.go @@ -724,6 +724,13 @@ func (m metricsStore) GetWorkspaceAgentByInstanceID(ctx context.Context, authIns return agent, err } +func (m metricsStore) GetWorkspaceAgentLifecycleStateByID(ctx context.Context, id uuid.UUID) (database.GetWorkspaceAgentLifecycleStateByIDRow, error) { + start := time.Now() + r0, r1 := m.s.GetWorkspaceAgentLifecycleStateByID(ctx, id) + m.queryLatencies.WithLabelValues("GetWorkspaceAgentLifecycleStateByID").Observe(time.Since(start).Seconds()) + return r0, r1 +} + func (m metricsStore) GetWorkspaceAgentMetadata(ctx context.Context, workspaceAgentID uuid.UUID) ([]database.WorkspaceAgentMetadatum, error) { start := time.Now() metadata, err := m.s.GetWorkspaceAgentMetadata(ctx, workspaceAgentID) @@ -738,13 +745,6 @@ func (m metricsStore) GetWorkspaceAgentStartupLogsAfter(ctx context.Context, arg return logs, err } -func (m metricsStore) GetWorkspaceAgentStartupLogsEOF(ctx context.Context, agentID uuid.UUID) (bool, error) { - start := time.Now() - r0, r1 := m.s.GetWorkspaceAgentStartupLogsEOF(ctx, agentID) - m.queryLatencies.WithLabelValues("GetWorkspaceAgentStartupLogsEOF").Observe(time.Since(start).Seconds()) - return r0, r1 -} - func (m metricsStore) GetWorkspaceAgentStats(ctx context.Context, createdAt time.Time) ([]database.GetWorkspaceAgentStatsRow, error) { start := time.Now() stats, err := m.s.GetWorkspaceAgentStats(ctx, createdAt) diff --git a/coderd/database/dbmock/dbmock.go b/coderd/database/dbmock/dbmock.go index 48ba84c92630f..5fd5cd6c1b02b 100644 --- a/coderd/database/dbmock/dbmock.go +++ b/coderd/database/dbmock/dbmock.go @@ -1423,6 +1423,21 @@ func (mr *MockStoreMockRecorder) GetWorkspaceAgentByInstanceID(arg0, arg1 interf return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "GetWorkspaceAgentByInstanceID", reflect.TypeOf((*MockStore)(nil).GetWorkspaceAgentByInstanceID), arg0, arg1) } +// GetWorkspaceAgentLifecycleStateByID mocks base method. +func (m *MockStore) GetWorkspaceAgentLifecycleStateByID(arg0 context.Context, arg1 uuid.UUID) (database.GetWorkspaceAgentLifecycleStateByIDRow, error) { + m.ctrl.T.Helper() + ret := m.ctrl.Call(m, "GetWorkspaceAgentLifecycleStateByID", arg0, arg1) + ret0, _ := ret[0].(database.GetWorkspaceAgentLifecycleStateByIDRow) + ret1, _ := ret[1].(error) + return ret0, ret1 +} + +// GetWorkspaceAgentLifecycleStateByID indicates an expected call of GetWorkspaceAgentLifecycleStateByID. +func (mr *MockStoreMockRecorder) GetWorkspaceAgentLifecycleStateByID(arg0, arg1 interface{}) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "GetWorkspaceAgentLifecycleStateByID", reflect.TypeOf((*MockStore)(nil).GetWorkspaceAgentLifecycleStateByID), arg0, arg1) +} + // GetWorkspaceAgentMetadata mocks base method. func (m *MockStore) GetWorkspaceAgentMetadata(arg0 context.Context, arg1 uuid.UUID) ([]database.WorkspaceAgentMetadatum, error) { m.ctrl.T.Helper() @@ -1453,21 +1468,6 @@ func (mr *MockStoreMockRecorder) GetWorkspaceAgentStartupLogsAfter(arg0, arg1 in return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "GetWorkspaceAgentStartupLogsAfter", reflect.TypeOf((*MockStore)(nil).GetWorkspaceAgentStartupLogsAfter), arg0, arg1) } -// GetWorkspaceAgentStartupLogsEOF mocks base method. -func (m *MockStore) GetWorkspaceAgentStartupLogsEOF(arg0 context.Context, arg1 uuid.UUID) (bool, error) { - m.ctrl.T.Helper() - ret := m.ctrl.Call(m, "GetWorkspaceAgentStartupLogsEOF", arg0, arg1) - ret0, _ := ret[0].(bool) - ret1, _ := ret[1].(error) - return ret0, ret1 -} - -// GetWorkspaceAgentStartupLogsEOF indicates an expected call of GetWorkspaceAgentStartupLogsEOF. -func (mr *MockStoreMockRecorder) GetWorkspaceAgentStartupLogsEOF(arg0, arg1 interface{}) *gomock.Call { - mr.mock.ctrl.T.Helper() - return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "GetWorkspaceAgentStartupLogsEOF", reflect.TypeOf((*MockStore)(nil).GetWorkspaceAgentStartupLogsEOF), arg0, arg1) -} - // GetWorkspaceAgentStats mocks base method. func (m *MockStore) GetWorkspaceAgentStats(arg0 context.Context, arg1 time.Time) ([]database.GetWorkspaceAgentStatsRow, error) { m.ctrl.T.Helper() diff --git a/coderd/database/dump.sql b/coderd/database/dump.sql index be75ba87f647c..2b67a05e364ab 100644 --- a/coderd/database/dump.sql +++ b/coderd/database/dump.sql @@ -548,12 +548,9 @@ CREATE TABLE workspace_agent_startup_logs ( created_at timestamp with time zone NOT NULL, output character varying(1024) NOT NULL, id bigint NOT NULL, - level log_level DEFAULT 'info'::log_level NOT NULL, - eof boolean DEFAULT false NOT NULL + level log_level DEFAULT 'info'::log_level NOT NULL ); -COMMENT ON COLUMN workspace_agent_startup_logs.eof IS 'End of file reached'; - CREATE SEQUENCE workspace_agent_startup_logs_id_seq START WITH 1 INCREMENT BY 1 @@ -615,6 +612,8 @@ CREATE TABLE workspace_agents ( startup_logs_overflowed boolean DEFAULT false NOT NULL, subsystem workspace_agent_subsystem DEFAULT 'none'::workspace_agent_subsystem NOT NULL, startup_script_behavior startup_script_behavior DEFAULT 'non-blocking'::startup_script_behavior NOT NULL, + started_at timestamp with time zone, + ready_at timestamp with time zone, CONSTRAINT max_startup_logs_length CHECK ((startup_logs_length <= 1048576)) ); @@ -642,6 +641,10 @@ COMMENT ON COLUMN workspace_agents.startup_logs_overflowed IS 'Whether the start COMMENT ON COLUMN workspace_agents.startup_script_behavior IS 'When startup script behavior is non-blocking, the workspace will be ready and accessible upon agent connection, when it is blocking, workspace will wait for the startup script to complete before becoming ready and accessible.'; +COMMENT ON COLUMN workspace_agents.started_at IS 'The time the agent entered the starting lifecycle state'; + +COMMENT ON COLUMN workspace_agents.ready_at IS 'The time the agent entered the ready or start_error lifecycle state'; + CREATE TABLE workspace_apps ( id uuid NOT NULL, created_at timestamp with time zone NOT NULL, diff --git a/coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.down.sql b/coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.down.sql new file mode 100644 index 0000000000000..3e6ae79cb4d32 --- /dev/null +++ b/coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.down.sql @@ -0,0 +1,11 @@ +BEGIN; + +ALTER TABLE workspace_agents + DROP COLUMN started_at, + DROP COLUMN ready_at; + +ALTER TABLE workspace_agent_startup_logs ADD COLUMN eof boolean NOT NULL DEFAULT false; + +COMMENT ON COLUMN workspace_agent_startup_logs.eof IS 'End of file reached'; + +COMMIT; diff --git a/coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.up.sql b/coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.up.sql new file mode 100644 index 0000000000000..7a11298c834f6 --- /dev/null +++ b/coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.up.sql @@ -0,0 +1,14 @@ +BEGIN; + +DELETE FROM workspace_agent_startup_logs WHERE eof IS TRUE; + +ALTER TABLE workspace_agent_startup_logs DROP COLUMN eof; + +ALTER TABLE workspace_agents + ADD COLUMN started_at TIMESTAMP WITH TIME ZONE DEFAULT NULL, + ADD COLUMN ready_at TIMESTAMP WITH TIME ZONE DEFAULT NULL; + +COMMENT ON COLUMN workspace_agents.started_at IS 'The time the agent entered the starting lifecycle state'; +COMMENT ON COLUMN workspace_agents.ready_at IS 'The time the agent entered the ready or start_error lifecycle state'; + +COMMIT; diff --git a/coderd/database/models.go b/coderd/database/models.go index c6bb681d5c00f..a493db3019d9b 100644 --- a/coderd/database/models.go +++ b/coderd/database/models.go @@ -1711,6 +1711,10 @@ type WorkspaceAgent struct { Subsystem WorkspaceAgentSubsystem `db:"subsystem" json:"subsystem"` // When startup script behavior is non-blocking, the workspace will be ready and accessible upon agent connection, when it is blocking, workspace will wait for the startup script to complete before becoming ready and accessible. StartupScriptBehavior StartupScriptBehavior `db:"startup_script_behavior" json:"startup_script_behavior"` + // The time the agent entered the starting lifecycle state + StartedAt sql.NullTime `db:"started_at" json:"started_at"` + // The time the agent entered the ready or start_error lifecycle state + ReadyAt sql.NullTime `db:"ready_at" json:"ready_at"` } type WorkspaceAgentMetadatum struct { @@ -1731,8 +1735,6 @@ type WorkspaceAgentStartupLog struct { Output string `db:"output" json:"output"` ID int64 `db:"id" json:"id"` Level LogLevel `db:"level" json:"level"` - // End of file reached - EOF bool `db:"eof" json:"eof"` } type WorkspaceAgentStat struct { diff --git a/coderd/database/querier.go b/coderd/database/querier.go index f07b5e5b8d59a..edbb8205b3042 100644 --- a/coderd/database/querier.go +++ b/coderd/database/querier.go @@ -125,9 +125,9 @@ type sqlcQuerier interface { GetWorkspaceAgentByAuthToken(ctx context.Context, authToken uuid.UUID) (WorkspaceAgent, error) GetWorkspaceAgentByID(ctx context.Context, id uuid.UUID) (WorkspaceAgent, error) GetWorkspaceAgentByInstanceID(ctx context.Context, authInstanceID string) (WorkspaceAgent, error) + GetWorkspaceAgentLifecycleStateByID(ctx context.Context, id uuid.UUID) (GetWorkspaceAgentLifecycleStateByIDRow, error) GetWorkspaceAgentMetadata(ctx context.Context, workspaceAgentID uuid.UUID) ([]WorkspaceAgentMetadatum, error) GetWorkspaceAgentStartupLogsAfter(ctx context.Context, arg GetWorkspaceAgentStartupLogsAfterParams) ([]WorkspaceAgentStartupLog, error) - GetWorkspaceAgentStartupLogsEOF(ctx context.Context, agentID uuid.UUID) (bool, error) GetWorkspaceAgentStats(ctx context.Context, createdAt time.Time) ([]GetWorkspaceAgentStatsRow, error) GetWorkspaceAgentStatsAndLabels(ctx context.Context, createdAt time.Time) ([]GetWorkspaceAgentStatsAndLabelsRow, error) GetWorkspaceAgentsByResourceIDs(ctx context.Context, ids []uuid.UUID) ([]WorkspaceAgent, error) diff --git a/coderd/database/querier_test.go b/coderd/database/querier_test.go index 4a11847d5b4aa..73bc960488a15 100644 --- a/coderd/database/querier_test.go +++ b/coderd/database/querier_test.go @@ -114,7 +114,6 @@ func TestInsertWorkspaceAgentStartupLogs(t *testing.T) { CreatedAt: []time.Time{database.Now()}, Output: []string{"first"}, Level: []database.LogLevel{database.LogLevelInfo}, - EOF: []bool{false}, // 1 MB is the max OutputLength: 1 << 20, }) @@ -126,7 +125,6 @@ func TestInsertWorkspaceAgentStartupLogs(t *testing.T) { CreatedAt: []time.Time{database.Now()}, Output: []string{"second"}, Level: []database.LogLevel{database.LogLevelInfo}, - EOF: []bool{false}, OutputLength: 1, }) require.True(t, database.IsStartupLogsLimitError(err)) diff --git a/coderd/database/queries.sql.go b/coderd/database/queries.sql.go index bab3b845b24d9..ea16c6f73a165 100644 --- a/coderd/database/queries.sql.go +++ b/coderd/database/queries.sql.go @@ -5248,7 +5248,7 @@ func (q *sqlQuerier) DeleteOldWorkspaceAgentStartupLogs(ctx context.Context) err const getWorkspaceAgentByAuthToken = `-- name: GetWorkspaceAgentByAuthToken :one SELECT - id, created_at, updated_at, name, first_connected_at, last_connected_at, disconnected_at, resource_id, auth_token, auth_instance_id, architecture, environment_variables, operating_system, startup_script, instance_metadata, resource_metadata, directory, version, last_connected_replica_id, connection_timeout_seconds, troubleshooting_url, motd_file, lifecycle_state, startup_script_timeout_seconds, expanded_directory, shutdown_script, shutdown_script_timeout_seconds, startup_logs_length, startup_logs_overflowed, subsystem, startup_script_behavior + id, created_at, updated_at, name, first_connected_at, last_connected_at, disconnected_at, resource_id, auth_token, auth_instance_id, architecture, environment_variables, operating_system, startup_script, instance_metadata, resource_metadata, directory, version, last_connected_replica_id, connection_timeout_seconds, troubleshooting_url, motd_file, lifecycle_state, startup_script_timeout_seconds, expanded_directory, shutdown_script, shutdown_script_timeout_seconds, startup_logs_length, startup_logs_overflowed, subsystem, startup_script_behavior, started_at, ready_at FROM workspace_agents WHERE @@ -5292,13 +5292,15 @@ func (q *sqlQuerier) GetWorkspaceAgentByAuthToken(ctx context.Context, authToken &i.StartupLogsOverflowed, &i.Subsystem, &i.StartupScriptBehavior, + &i.StartedAt, + &i.ReadyAt, ) return i, err } const getWorkspaceAgentByID = `-- name: GetWorkspaceAgentByID :one SELECT - id, created_at, updated_at, name, first_connected_at, last_connected_at, disconnected_at, resource_id, auth_token, auth_instance_id, architecture, environment_variables, operating_system, startup_script, instance_metadata, resource_metadata, directory, version, last_connected_replica_id, connection_timeout_seconds, troubleshooting_url, motd_file, lifecycle_state, startup_script_timeout_seconds, expanded_directory, shutdown_script, shutdown_script_timeout_seconds, startup_logs_length, startup_logs_overflowed, subsystem, startup_script_behavior + id, created_at, updated_at, name, first_connected_at, last_connected_at, disconnected_at, resource_id, auth_token, auth_instance_id, architecture, environment_variables, operating_system, startup_script, instance_metadata, resource_metadata, directory, version, last_connected_replica_id, connection_timeout_seconds, troubleshooting_url, motd_file, lifecycle_state, startup_script_timeout_seconds, expanded_directory, shutdown_script, shutdown_script_timeout_seconds, startup_logs_length, startup_logs_overflowed, subsystem, startup_script_behavior, started_at, ready_at FROM workspace_agents WHERE @@ -5340,13 +5342,15 @@ func (q *sqlQuerier) GetWorkspaceAgentByID(ctx context.Context, id uuid.UUID) (W &i.StartupLogsOverflowed, &i.Subsystem, &i.StartupScriptBehavior, + &i.StartedAt, + &i.ReadyAt, ) return i, err } const getWorkspaceAgentByInstanceID = `-- name: GetWorkspaceAgentByInstanceID :one SELECT - id, created_at, updated_at, name, first_connected_at, last_connected_at, disconnected_at, resource_id, auth_token, auth_instance_id, architecture, environment_variables, operating_system, startup_script, instance_metadata, resource_metadata, directory, version, last_connected_replica_id, connection_timeout_seconds, troubleshooting_url, motd_file, lifecycle_state, startup_script_timeout_seconds, expanded_directory, shutdown_script, shutdown_script_timeout_seconds, startup_logs_length, startup_logs_overflowed, subsystem, startup_script_behavior + id, created_at, updated_at, name, first_connected_at, last_connected_at, disconnected_at, resource_id, auth_token, auth_instance_id, architecture, environment_variables, operating_system, startup_script, instance_metadata, resource_metadata, directory, version, last_connected_replica_id, connection_timeout_seconds, troubleshooting_url, motd_file, lifecycle_state, startup_script_timeout_seconds, expanded_directory, shutdown_script, shutdown_script_timeout_seconds, startup_logs_length, startup_logs_overflowed, subsystem, startup_script_behavior, started_at, ready_at FROM workspace_agents WHERE @@ -5390,10 +5394,36 @@ func (q *sqlQuerier) GetWorkspaceAgentByInstanceID(ctx context.Context, authInst &i.StartupLogsOverflowed, &i.Subsystem, &i.StartupScriptBehavior, + &i.StartedAt, + &i.ReadyAt, ) return i, err } +const getWorkspaceAgentLifecycleStateByID = `-- name: GetWorkspaceAgentLifecycleStateByID :one +SELECT + lifecycle_state, + started_at, + ready_at +FROM + workspace_agents +WHERE + id = $1 +` + +type GetWorkspaceAgentLifecycleStateByIDRow struct { + LifecycleState WorkspaceAgentLifecycleState `db:"lifecycle_state" json:"lifecycle_state"` + StartedAt sql.NullTime `db:"started_at" json:"started_at"` + ReadyAt sql.NullTime `db:"ready_at" json:"ready_at"` +} + +func (q *sqlQuerier) GetWorkspaceAgentLifecycleStateByID(ctx context.Context, id uuid.UUID) (GetWorkspaceAgentLifecycleStateByIDRow, error) { + row := q.db.QueryRowContext(ctx, getWorkspaceAgentLifecycleStateByID, id) + var i GetWorkspaceAgentLifecycleStateByIDRow + err := row.Scan(&i.LifecycleState, &i.StartedAt, &i.ReadyAt) + return i, err +} + const getWorkspaceAgentMetadata = `-- name: GetWorkspaceAgentMetadata :many SELECT workspace_agent_id, display_name, key, script, value, error, timeout, interval, collected_at @@ -5438,7 +5468,7 @@ func (q *sqlQuerier) GetWorkspaceAgentMetadata(ctx context.Context, workspaceAge const getWorkspaceAgentStartupLogsAfter = `-- name: GetWorkspaceAgentStartupLogsAfter :many SELECT - agent_id, created_at, output, id, level, eof + agent_id, created_at, output, id, level FROM workspace_agent_startup_logs WHERE @@ -5468,7 +5498,6 @@ func (q *sqlQuerier) GetWorkspaceAgentStartupLogsAfter(ctx context.Context, arg &i.Output, &i.ID, &i.Level, - &i.EOF, ); err != nil { return nil, err } @@ -5483,29 +5512,9 @@ func (q *sqlQuerier) GetWorkspaceAgentStartupLogsAfter(ctx context.Context, arg return items, nil } -const getWorkspaceAgentStartupLogsEOF = `-- name: GetWorkspaceAgentStartupLogsEOF :one -SELECT CASE WHEN EXISTS ( - SELECT - agent_id, created_at, output, id, level, eof - FROM - workspace_agent_startup_logs - WHERE - agent_id = $1 - AND eof = true - LIMIT 1 -) THEN TRUE ELSE FALSE END -` - -func (q *sqlQuerier) GetWorkspaceAgentStartupLogsEOF(ctx context.Context, agentID uuid.UUID) (bool, error) { - row := q.db.QueryRowContext(ctx, getWorkspaceAgentStartupLogsEOF, agentID) - var column_1 bool - err := row.Scan(&column_1) - return column_1, err -} - const getWorkspaceAgentsByResourceIDs = `-- name: GetWorkspaceAgentsByResourceIDs :many SELECT - id, created_at, updated_at, name, first_connected_at, last_connected_at, disconnected_at, resource_id, auth_token, auth_instance_id, architecture, environment_variables, operating_system, startup_script, instance_metadata, resource_metadata, directory, version, last_connected_replica_id, connection_timeout_seconds, troubleshooting_url, motd_file, lifecycle_state, startup_script_timeout_seconds, expanded_directory, shutdown_script, shutdown_script_timeout_seconds, startup_logs_length, startup_logs_overflowed, subsystem, startup_script_behavior + id, created_at, updated_at, name, first_connected_at, last_connected_at, disconnected_at, resource_id, auth_token, auth_instance_id, architecture, environment_variables, operating_system, startup_script, instance_metadata, resource_metadata, directory, version, last_connected_replica_id, connection_timeout_seconds, troubleshooting_url, motd_file, lifecycle_state, startup_script_timeout_seconds, expanded_directory, shutdown_script, shutdown_script_timeout_seconds, startup_logs_length, startup_logs_overflowed, subsystem, startup_script_behavior, started_at, ready_at FROM workspace_agents WHERE @@ -5553,6 +5562,8 @@ func (q *sqlQuerier) GetWorkspaceAgentsByResourceIDs(ctx context.Context, ids [] &i.StartupLogsOverflowed, &i.Subsystem, &i.StartupScriptBehavior, + &i.StartedAt, + &i.ReadyAt, ); err != nil { return nil, err } @@ -5568,7 +5579,7 @@ func (q *sqlQuerier) GetWorkspaceAgentsByResourceIDs(ctx context.Context, ids [] } const getWorkspaceAgentsCreatedAfter = `-- name: GetWorkspaceAgentsCreatedAfter :many -SELECT id, created_at, updated_at, name, first_connected_at, last_connected_at, disconnected_at, resource_id, auth_token, auth_instance_id, architecture, environment_variables, operating_system, startup_script, instance_metadata, resource_metadata, directory, version, last_connected_replica_id, connection_timeout_seconds, troubleshooting_url, motd_file, lifecycle_state, startup_script_timeout_seconds, expanded_directory, shutdown_script, shutdown_script_timeout_seconds, startup_logs_length, startup_logs_overflowed, subsystem, startup_script_behavior FROM workspace_agents WHERE created_at > $1 +SELECT id, created_at, updated_at, name, first_connected_at, last_connected_at, disconnected_at, resource_id, auth_token, auth_instance_id, architecture, environment_variables, operating_system, startup_script, instance_metadata, resource_metadata, directory, version, last_connected_replica_id, connection_timeout_seconds, troubleshooting_url, motd_file, lifecycle_state, startup_script_timeout_seconds, expanded_directory, shutdown_script, shutdown_script_timeout_seconds, startup_logs_length, startup_logs_overflowed, subsystem, startup_script_behavior, started_at, ready_at FROM workspace_agents WHERE created_at > $1 ` func (q *sqlQuerier) GetWorkspaceAgentsCreatedAfter(ctx context.Context, createdAt time.Time) ([]WorkspaceAgent, error) { @@ -5612,6 +5623,8 @@ func (q *sqlQuerier) GetWorkspaceAgentsCreatedAfter(ctx context.Context, created &i.StartupLogsOverflowed, &i.Subsystem, &i.StartupScriptBehavior, + &i.StartedAt, + &i.ReadyAt, ); err != nil { return nil, err } @@ -5628,7 +5641,7 @@ func (q *sqlQuerier) GetWorkspaceAgentsCreatedAfter(ctx context.Context, created const getWorkspaceAgentsInLatestBuildByWorkspaceID = `-- name: GetWorkspaceAgentsInLatestBuildByWorkspaceID :many SELECT - workspace_agents.id, workspace_agents.created_at, workspace_agents.updated_at, workspace_agents.name, workspace_agents.first_connected_at, workspace_agents.last_connected_at, workspace_agents.disconnected_at, workspace_agents.resource_id, workspace_agents.auth_token, workspace_agents.auth_instance_id, workspace_agents.architecture, workspace_agents.environment_variables, workspace_agents.operating_system, workspace_agents.startup_script, workspace_agents.instance_metadata, workspace_agents.resource_metadata, workspace_agents.directory, workspace_agents.version, workspace_agents.last_connected_replica_id, workspace_agents.connection_timeout_seconds, workspace_agents.troubleshooting_url, workspace_agents.motd_file, workspace_agents.lifecycle_state, workspace_agents.startup_script_timeout_seconds, workspace_agents.expanded_directory, workspace_agents.shutdown_script, workspace_agents.shutdown_script_timeout_seconds, workspace_agents.startup_logs_length, workspace_agents.startup_logs_overflowed, workspace_agents.subsystem, workspace_agents.startup_script_behavior + workspace_agents.id, workspace_agents.created_at, workspace_agents.updated_at, workspace_agents.name, workspace_agents.first_connected_at, workspace_agents.last_connected_at, workspace_agents.disconnected_at, workspace_agents.resource_id, workspace_agents.auth_token, workspace_agents.auth_instance_id, workspace_agents.architecture, workspace_agents.environment_variables, workspace_agents.operating_system, workspace_agents.startup_script, workspace_agents.instance_metadata, workspace_agents.resource_metadata, workspace_agents.directory, workspace_agents.version, workspace_agents.last_connected_replica_id, workspace_agents.connection_timeout_seconds, workspace_agents.troubleshooting_url, workspace_agents.motd_file, workspace_agents.lifecycle_state, workspace_agents.startup_script_timeout_seconds, workspace_agents.expanded_directory, workspace_agents.shutdown_script, workspace_agents.shutdown_script_timeout_seconds, workspace_agents.startup_logs_length, workspace_agents.startup_logs_overflowed, workspace_agents.subsystem, workspace_agents.startup_script_behavior, workspace_agents.started_at, workspace_agents.ready_at FROM workspace_agents JOIN @@ -5688,6 +5701,8 @@ func (q *sqlQuerier) GetWorkspaceAgentsInLatestBuildByWorkspaceID(ctx context.Co &i.StartupLogsOverflowed, &i.Subsystem, &i.StartupScriptBehavior, + &i.StartedAt, + &i.ReadyAt, ); err != nil { return nil, err } @@ -5728,7 +5743,7 @@ INSERT INTO shutdown_script_timeout_seconds ) VALUES - ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17, $18, $19, $20, $21) RETURNING id, created_at, updated_at, name, first_connected_at, last_connected_at, disconnected_at, resource_id, auth_token, auth_instance_id, architecture, environment_variables, operating_system, startup_script, instance_metadata, resource_metadata, directory, version, last_connected_replica_id, connection_timeout_seconds, troubleshooting_url, motd_file, lifecycle_state, startup_script_timeout_seconds, expanded_directory, shutdown_script, shutdown_script_timeout_seconds, startup_logs_length, startup_logs_overflowed, subsystem, startup_script_behavior + ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17, $18, $19, $20, $21) RETURNING id, created_at, updated_at, name, first_connected_at, last_connected_at, disconnected_at, resource_id, auth_token, auth_instance_id, architecture, environment_variables, operating_system, startup_script, instance_metadata, resource_metadata, directory, version, last_connected_replica_id, connection_timeout_seconds, troubleshooting_url, motd_file, lifecycle_state, startup_script_timeout_seconds, expanded_directory, shutdown_script, shutdown_script_timeout_seconds, startup_logs_length, startup_logs_overflowed, subsystem, startup_script_behavior, started_at, ready_at ` type InsertWorkspaceAgentParams struct { @@ -5812,6 +5827,8 @@ func (q *sqlQuerier) InsertWorkspaceAgent(ctx context.Context, arg InsertWorkspa &i.StartupLogsOverflowed, &i.Subsystem, &i.StartupScriptBehavior, + &i.StartedAt, + &i.ReadyAt, ) return i, err } @@ -5854,17 +5871,16 @@ func (q *sqlQuerier) InsertWorkspaceAgentMetadata(ctx context.Context, arg Inser const insertWorkspaceAgentStartupLogs = `-- name: InsertWorkspaceAgentStartupLogs :many WITH new_length AS ( UPDATE workspace_agents SET - startup_logs_length = startup_logs_length + $6 WHERE workspace_agents.id = $1 + startup_logs_length = startup_logs_length + $5 WHERE workspace_agents.id = $1 ) INSERT INTO - workspace_agent_startup_logs (agent_id, created_at, output, level, eof) + workspace_agent_startup_logs (agent_id, created_at, output, level) SELECT $1 :: uuid AS agent_id, unnest($2 :: timestamptz [ ]) AS created_at, unnest($3 :: VARCHAR(1024) [ ]) AS output, - unnest($4 :: log_level [ ]) AS level, - unnest($5 :: boolean [ ]) AS eof - RETURNING workspace_agent_startup_logs.agent_id, workspace_agent_startup_logs.created_at, workspace_agent_startup_logs.output, workspace_agent_startup_logs.id, workspace_agent_startup_logs.level, workspace_agent_startup_logs.eof + unnest($4 :: log_level [ ]) AS level + RETURNING workspace_agent_startup_logs.agent_id, workspace_agent_startup_logs.created_at, workspace_agent_startup_logs.output, workspace_agent_startup_logs.id, workspace_agent_startup_logs.level ` type InsertWorkspaceAgentStartupLogsParams struct { @@ -5872,7 +5888,6 @@ type InsertWorkspaceAgentStartupLogsParams struct { CreatedAt []time.Time `db:"created_at" json:"created_at"` Output []string `db:"output" json:"output"` Level []LogLevel `db:"level" json:"level"` - EOF []bool `db:"eof" json:"eof"` OutputLength int32 `db:"output_length" json:"output_length"` } @@ -5882,7 +5897,6 @@ func (q *sqlQuerier) InsertWorkspaceAgentStartupLogs(ctx context.Context, arg In pq.Array(arg.CreatedAt), pq.Array(arg.Output), pq.Array(arg.Level), - pq.Array(arg.EOF), arg.OutputLength, ) if err != nil { @@ -5898,7 +5912,6 @@ func (q *sqlQuerier) InsertWorkspaceAgentStartupLogs(ctx context.Context, arg In &i.Output, &i.ID, &i.Level, - &i.EOF, ); err != nil { return nil, err } @@ -5951,7 +5964,9 @@ const updateWorkspaceAgentLifecycleStateByID = `-- name: UpdateWorkspaceAgentLif UPDATE workspace_agents SET - lifecycle_state = $2 + lifecycle_state = $2, + started_at = $3, + ready_at = $4 WHERE id = $1 ` @@ -5959,10 +5974,17 @@ WHERE type UpdateWorkspaceAgentLifecycleStateByIDParams struct { ID uuid.UUID `db:"id" json:"id"` LifecycleState WorkspaceAgentLifecycleState `db:"lifecycle_state" json:"lifecycle_state"` + StartedAt sql.NullTime `db:"started_at" json:"started_at"` + ReadyAt sql.NullTime `db:"ready_at" json:"ready_at"` } func (q *sqlQuerier) UpdateWorkspaceAgentLifecycleStateByID(ctx context.Context, arg UpdateWorkspaceAgentLifecycleStateByIDParams) error { - _, err := q.db.ExecContext(ctx, updateWorkspaceAgentLifecycleStateByID, arg.ID, arg.LifecycleState) + _, err := q.db.ExecContext(ctx, updateWorkspaceAgentLifecycleStateByID, + arg.ID, + arg.LifecycleState, + arg.StartedAt, + arg.ReadyAt, + ) return err } diff --git a/coderd/database/queries/workspaceagents.sql b/coderd/database/queries/workspaceagents.sql index 84d81eec9fdf3..03168685aa37b 100644 --- a/coderd/database/queries/workspaceagents.sql +++ b/coderd/database/queries/workspaceagents.sql @@ -87,11 +87,24 @@ SET WHERE id = $1; +-- name: GetWorkspaceAgentLifecycleStateByID :one +SELECT + lifecycle_state, + started_at, + ready_at +FROM + workspace_agents +WHERE + id = $1; + + -- name: UpdateWorkspaceAgentLifecycleStateByID :exec UPDATE workspace_agents SET - lifecycle_state = $2 + lifecycle_state = $2, + started_at = $3, + ready_at = $4 WHERE id = $1; @@ -146,31 +159,18 @@ WHERE id > @created_after ) ORDER BY id ASC; --- name: GetWorkspaceAgentStartupLogsEOF :one -SELECT CASE WHEN EXISTS ( - SELECT - * - FROM - workspace_agent_startup_logs - WHERE - agent_id = $1 - AND eof = true - LIMIT 1 -) THEN TRUE ELSE FALSE END; - -- name: InsertWorkspaceAgentStartupLogs :many WITH new_length AS ( UPDATE workspace_agents SET startup_logs_length = startup_logs_length + @output_length WHERE workspace_agents.id = @agent_id ) INSERT INTO - workspace_agent_startup_logs (agent_id, created_at, output, level, eof) + workspace_agent_startup_logs (agent_id, created_at, output, level) SELECT @agent_id :: uuid AS agent_id, unnest(@created_at :: timestamptz [ ]) AS created_at, unnest(@output :: VARCHAR(1024) [ ]) AS output, - unnest(@level :: log_level [ ]) AS level, - unnest(@eof :: boolean [ ]) AS eof + unnest(@level :: log_level [ ]) AS level RETURNING workspace_agent_startup_logs.*; -- If an agent hasn't connected in the last 7 days, we purge it's logs. diff --git a/coderd/workspaceagents.go b/coderd/workspaceagents.go index dd01e26c8c0fe..e30060627f374 100644 --- a/coderd/workspaceagents.go +++ b/coderd/workspaceagents.go @@ -259,16 +259,8 @@ func (api *API) patchWorkspaceAgentStartupLogs(rw http.ResponseWriter, r *http.R createdAt := make([]time.Time, 0) output := make([]string, 0) level := make([]database.LogLevel, 0) - eof := make([]bool, 0) outputLength := 0 - for i, logEntry := range req.Logs { - if logEntry.EOF && i != len(req.Logs)-1 { - httpapi.Write(ctx, rw, http.StatusBadRequest, codersdk.Response{ - Message: "EOF log must be the last log entry.", - }) - return - } - + for _, logEntry := range req.Logs { createdAt = append(createdAt, logEntry.CreatedAt) output = append(output, logEntry.Output) outputLength += len(logEntry.Output) @@ -285,22 +277,21 @@ func (api *API) patchWorkspaceAgentStartupLogs(rw http.ResponseWriter, r *http.R return } level = append(level, parsedLevel) - eof = append(eof, logEntry.EOF) } var logs []database.WorkspaceAgentStartupLog - // Ensure logs are not written after EOF. - eofError := xerrors.New("EOF log already received") + // Ensure logs are not written after script ended. + scriptEndedError := xerrors.New("startup script has ended") err := api.Database.InTx(func(db database.Store) error { - isEOF, err := db.GetWorkspaceAgentStartupLogsEOF(ctx, workspaceAgent.ID) + ss, err := db.GetWorkspaceAgentLifecycleStateByID(ctx, workspaceAgent.ID) if err != nil { - return xerrors.Errorf("EOF status: %w", err) + return xerrors.Errorf("workspace agent startup script status: %w", err) } - if isEOF { - // The agent has already sent an EOF log, so we don't need to process - // any more logs. - return eofError + if ss.ReadyAt.Valid { + // The agent startup script has already ended, so we don't want to + // process any more logs. + return scriptEndedError } logs, err = db.InsertWorkspaceAgentStartupLogs(ctx, database.InsertWorkspaceAgentStartupLogsParams{ @@ -308,15 +299,14 @@ func (api *API) patchWorkspaceAgentStartupLogs(rw http.ResponseWriter, r *http.R CreatedAt: createdAt, Output: output, Level: level, - EOF: eof, OutputLength: int32(outputLength), }) return err }, nil) if err != nil { - if errors.Is(err, eofError) { - httpapi.Write(ctx, rw, http.StatusBadRequest, codersdk.Response{ - Message: "Startup log has been closed.", + if errors.Is(err, scriptEndedError) { + httpapi.Write(ctx, rw, http.StatusConflict, codersdk.Response{ + Message: "Failed to upload logs, startup script has already ended.", Detail: err.Error(), }) return @@ -368,14 +358,12 @@ func (api *API) patchWorkspaceAgentStartupLogs(rw http.ResponseWriter, r *http.R return } - firstLog := logs[0] - lastLog := logs[len(logs)-1] + lowestLogID := logs[0].ID // Publish by the lowest log ID inserted so the // log stream will fetch everything from that point. api.publishWorkspaceAgentStartupLogsUpdate(ctx, workspaceAgent.ID, agentsdk.StartupLogsNotifyMessage{ - CreatedAfter: firstLog.ID - 1, - EndOfLogs: lastLog.EOF, + CreatedAfter: lowestLogID - 1, }) if workspaceAgent.StartupLogsLength == 0 { @@ -493,22 +481,23 @@ func (api *API) workspaceAgentStartupLogs(rw http.ResponseWriter, r *http.Reques return } - lastSentLogID := after - if len(logs) > 0 { - last := logs[len(logs)-1] - - if last.EOF { - // The startup script has finished running, so we can close the connection. - return - } - lastSentLogID = last.ID + if workspaceAgent.ReadyAt.Valid { + // Fast path, the startup script has finished running, so we can close + // the connection. + return } if !codersdk.WorkspaceAgentLifecycle(workspaceAgent.LifecycleState).Starting() { - // Backwards compatibility: Avoid waiting forever in case this agent was - // created before the current release. + // Backwards compatibility: Avoid waiting forever in case this agent is + // older than the current release and has already reported the ready + // state. return } + lastSentLogID := after + if len(logs) > 0 { + lastSentLogID = logs[len(logs)-1].ID + } + notifyCh := make(chan struct{}, 1) // Allow us to immediately check if we missed any logs // between initial fetch and subscribe. @@ -538,8 +527,11 @@ func (api *API) workspaceAgentStartupLogs(rw http.ResponseWriter, r *http.Reques t := time.NewTicker(recheckInterval) defer t.Stop() + var state database.GetWorkspaceAgentLifecycleStateByIDRow go func() { defer close(bufferedLogs) + + var err error for { select { case <-ctx.Done(): @@ -549,6 +541,17 @@ func (api *API) workspaceAgentStartupLogs(rw http.ResponseWriter, r *http.Reques t.Reset(recheckInterval) } + if !state.ReadyAt.Valid { + state, err = api.Database.GetWorkspaceAgentLifecycleStateByID(ctx, workspaceAgent.ID) + if err != nil { + if xerrors.Is(err, context.Canceled) { + return + } + logger.Warn(ctx, "failed to get workspace agent lifecycle state", slog.Error(err)) + continue + } + } + logs, err := api.Database.GetWorkspaceAgentStartupLogsAfter(ctx, database.GetWorkspaceAgentStartupLogsAfterParams{ AgentID: workspaceAgent.ID, CreatedAfter: lastSentLogID, @@ -561,6 +564,9 @@ func (api *API) workspaceAgentStartupLogs(rw http.ResponseWriter, r *http.Reques continue } if len(logs) == 0 { + if state.ReadyAt.Valid { + return + } continue } @@ -570,9 +576,6 @@ func (api *API) workspaceAgentStartupLogs(rw http.ResponseWriter, r *http.Reques case bufferedLogs <- logs: lastSentLogID = logs[len(logs)-1].ID } - if logs[len(logs)-1].EOF { - return - } } }() defer func() { @@ -1166,6 +1169,8 @@ func convertWorkspaceAgent(derpMap *tailcfg.DERPMap, coordinator tailnet.Coordin Architecture: dbAgent.Architecture, OperatingSystem: dbAgent.OperatingSystem, StartupScript: dbAgent.StartupScript.String, + StartupScriptBehavior: codersdk.WorkspaceAgentStartupScriptBehavior(dbAgent.StartupScriptBehavior), + StartupScriptTimeoutSeconds: dbAgent.StartupScriptTimeoutSeconds, StartupLogsLength: dbAgent.StartupLogsLength, StartupLogsOverflowed: dbAgent.StartupLogsOverflowed, Version: dbAgent.Version, @@ -1177,8 +1182,6 @@ func convertWorkspaceAgent(derpMap *tailcfg.DERPMap, coordinator tailnet.Coordin TroubleshootingURL: troubleshootingURL, LifecycleState: codersdk.WorkspaceAgentLifecycle(dbAgent.LifecycleState), LoginBeforeReady: dbAgent.StartupScriptBehavior != database.StartupScriptBehaviorBlocking, - StartupScriptBehavior: codersdk.WorkspaceAgentStartupScriptBehavior(dbAgent.StartupScriptBehavior), - StartupScriptTimeoutSeconds: dbAgent.StartupScriptTimeoutSeconds, ShutdownScript: dbAgent.ShutdownScript.String, ShutdownScriptTimeoutSeconds: dbAgent.ShutdownScriptTimeoutSeconds, Subsystem: codersdk.AgentSubsystem(dbAgent.Subsystem), @@ -1215,6 +1218,13 @@ func convertWorkspaceAgent(derpMap *tailcfg.DERPMap, coordinator tailnet.Coordin workspaceAgent.LastConnectedAt = status.LastConnectedAt workspaceAgent.DisconnectedAt = status.DisconnectedAt + if dbAgent.StartedAt.Valid { + workspaceAgent.StartedAt = &dbAgent.StartedAt.Time + } + if dbAgent.ReadyAt.Valid { + workspaceAgent.ReadyAt = &dbAgent.ReadyAt.Time + } + return workspaceAgent, nil } @@ -1593,56 +1603,38 @@ func (api *API) workspaceAgentReportLifecycle(rw http.ResponseWriter, r *http.Re return } + if req.ChangedAt.IsZero() { + // Backwards compatibility with older agents. + req.ChangedAt = database.Now() + } + changedAt := sql.NullTime{Time: req.ChangedAt, Valid: true} + + startedAt := workspaceAgent.StartedAt + readyAt := workspaceAgent.ReadyAt + switch lifecycleState { + case codersdk.WorkspaceAgentLifecycleStarting: + startedAt = changedAt + readyAt.Valid = false // This agent is re-starting, so it's not ready yet. + case codersdk.WorkspaceAgentLifecycleReady, codersdk.WorkspaceAgentLifecycleStartError: + readyAt = changedAt + } + err = api.Database.UpdateWorkspaceAgentLifecycleStateByID(ctx, database.UpdateWorkspaceAgentLifecycleStateByIDParams{ ID: workspaceAgent.ID, LifecycleState: dbLifecycleState, + StartedAt: startedAt, + ReadyAt: readyAt, }) if err != nil { + logger.Warn(ctx, "failed to update lifecycle state", slog.Error(err)) httpapi.InternalServerError(rw, err) return } - if !lifecycleState.Starting() { - var eofLog []database.WorkspaceAgentStartupLog - // Ensure the startup logs are marked as complete if the agent - // is no longer starting. This should be reported by the agent - // itself, but we do it here as a fallback. - err = api.Database.InTx(func(db database.Store) error { - isEOF, err := db.GetWorkspaceAgentStartupLogsEOF(ctx, workspaceAgent.ID) - if err != nil { - return xerrors.Errorf("EOF status: %w", err) - } - if isEOF { - return nil - } - - logger.Debug(ctx, "marking startup logs as complete because agent is no longer starting") - eofLog, err = db.InsertWorkspaceAgentStartupLogs(ctx, database.InsertWorkspaceAgentStartupLogsParams{ - AgentID: workspaceAgent.ID, - CreatedAt: []time.Time{database.Now()}, - Output: []string{""}, - Level: []database.LogLevel{database.LogLevelInfo}, - EOF: []bool{true}, - OutputLength: 0, - }) - if err != nil { - return xerrors.Errorf("write EOF log entry: %w", err) - } - return nil - }, nil) - if err != nil { - logger.Warn(ctx, "failed to mark startup logs as complete", slog.Error(err)) - // If this fails, we want the agent to keep trying so that the - // startup log is eventually marked as complete. - httpapi.InternalServerError(rw, err) - return - } - if len(eofLog) > 0 { - api.publishWorkspaceAgentStartupLogsUpdate(ctx, workspaceAgent.ID, agentsdk.StartupLogsNotifyMessage{ - CreatedAfter: eofLog[0].ID - 1, - EndOfLogs: true, - }) - } + if readyAt.Valid { + api.publishWorkspaceAgentStartupLogsUpdate(ctx, workspaceAgent.ID, agentsdk.StartupLogsNotifyMessage{ + EndOfLogs: true, + }) } api.publishWorkspaceUpdate(ctx, workspace.ID) @@ -2080,7 +2072,6 @@ func convertWorkspaceAgentStartupLog(logEntry database.WorkspaceAgentStartupLog) CreatedAt: logEntry.CreatedAt, Output: logEntry.Output, Level: codersdk.LogLevel(logEntry.Level), - EOF: logEntry.EOF, } } diff --git a/coderd/workspaceagents_test.go b/coderd/workspaceagents_test.go index 0f3301ff0c77f..eb8a8eb5252be 100644 --- a/coderd/workspaceagents_test.go +++ b/coderd/workspaceagents_test.go @@ -301,124 +301,6 @@ func TestWorkspaceAgentStartupLogs(t *testing.T) { } } }) - t.Run("AllowEOFAfterOverflowAndCloseFollowWebsocket", func(t *testing.T) { - t.Parallel() - ctx := testutil.Context(t, testutil.WaitMedium) - client := coderdtest.New(t, &coderdtest.Options{ - IncludeProvisionerDaemon: true, - }) - user := coderdtest.CreateFirstUser(t, client) - authToken := uuid.NewString() - version := coderdtest.CreateTemplateVersion(t, client, user.OrganizationID, &echo.Responses{ - Parse: echo.ParseComplete, - ProvisionPlan: echo.ProvisionComplete, - ProvisionApply: []*proto.Provision_Response{{ - Type: &proto.Provision_Response_Complete{ - Complete: &proto.Provision_Complete{ - Resources: []*proto.Resource{{ - Name: "example", - Type: "aws_instance", - Agents: []*proto.Agent{{ - Id: uuid.NewString(), - Auth: &proto.Agent_Token{ - Token: authToken, - }, - }}, - }}, - }, - }, - }}, - }) - template := coderdtest.CreateTemplate(t, client, user.OrganizationID, version.ID) - coderdtest.AwaitTemplateVersionJob(t, client, version.ID) - workspace := coderdtest.CreateWorkspace(t, client, user.OrganizationID, template.ID) - build := coderdtest.AwaitWorkspaceBuildJob(t, client, workspace.LatestBuild.ID) - - updates, err := client.WatchWorkspace(ctx, workspace.ID) - require.NoError(t, err) - - logs, closeLogs, err := client.WorkspaceAgentStartupLogsAfter(ctx, build.Resources[0].Agents[0].ID, 0) - require.NoError(t, err) - defer closeLogs.Close() - - wantLogs := []codersdk.WorkspaceAgentStartupLog{ - { - CreatedAt: database.Now(), - Output: "testing", - Level: "info", - }, - { - CreatedAt: database.Now().Add(time.Minute), - Level: "info", - EOF: true, - }, - } - - agentClient := agentsdk.New(client.URL) - agentClient.SetSessionToken(authToken) - - var convertedLogs []agentsdk.StartupLog - for _, log := range wantLogs { - convertedLogs = append(convertedLogs, agentsdk.StartupLog{ - CreatedAt: log.CreatedAt, - Output: log.Output, - Level: log.Level, - EOF: log.EOF, - }) - } - initialLogs := convertedLogs[:len(convertedLogs)-1] - eofLog := convertedLogs[len(convertedLogs)-1] - err = agentClient.PatchStartupLogs(ctx, agentsdk.PatchStartupLogs{Logs: initialLogs}) - require.NoError(t, err) - - overflowLogs := []agentsdk.StartupLog{ - { - CreatedAt: database.Now(), - Output: strings.Repeat("a", (1<<20)+1), - }, - eofLog, // Include EOF which will be discarded due to overflow. - } - err = agentClient.PatchStartupLogs(ctx, agentsdk.PatchStartupLogs{Logs: overflowLogs}) - var apiError *codersdk.Error - require.ErrorAs(t, err, &apiError) - require.Equal(t, http.StatusRequestEntityTooLarge, apiError.StatusCode()) - - // It's possible we have multiple updates queued, but that's alright, we just - // wait for the one where it overflows. - for { - var update codersdk.Workspace - select { - case <-ctx.Done(): - require.Fail(t, "timed out waiting for overflow") - case update = <-updates: - } - if update.LatestBuild.Resources[0].Agents[0].StartupLogsOverflowed { - break - } - } - - // Now we should still be able to send the EOF. - err = agentClient.PatchStartupLogs(ctx, agentsdk.PatchStartupLogs{Logs: []agentsdk.StartupLog{eofLog}}) - require.NoError(t, err) - - var gotLogs []codersdk.WorkspaceAgentStartupLog - logsLoop: - for { - select { - case <-ctx.Done(): - require.Fail(t, "timed out waiting for logs") - case l, ok := <-logs: - if !ok { - break logsLoop - } - gotLogs = append(gotLogs, l...) - } - } - for i := range gotLogs { - gotLogs[i].ID = 0 // Ignore ID for comparison. - } - require.Equal(t, wantLogs, gotLogs) - }) t.Run("CloseAfterLifecycleStateIsNotRunning", func(t *testing.T) { t.Parallel() ctx := testutil.Context(t, testutil.WaitMedium) @@ -472,25 +354,26 @@ func TestWorkspaceAgentStartupLogs(t *testing.T) { require.NoError(t, err) err = agentClient.PostLifecycle(ctx, agentsdk.PostLifecycleRequest{ - State: codersdk.WorkspaceAgentLifecycleReady, + State: codersdk.WorkspaceAgentLifecycleReady, + ChangedAt: time.Now(), }) require.NoError(t, err) + var gotLogs []codersdk.WorkspaceAgentStartupLog for { select { case <-ctx.Done(): - require.Fail(t, "timed out waiting for logs EOF") - case l := <-logs: - for _, log := range l { - if log.EOF { - // Success. - return - } + require.Fail(t, "timed out waiting for logs to end") + case l, ok := <-logs: + gotLogs = append(gotLogs, l...) + if !ok { + require.Len(t, gotLogs, 1, "expected one log") + return // Success. } } } }) - t.Run("NoLogAfterEOF", func(t *testing.T) { + t.Run("NoLogAfterScriptEnded", func(t *testing.T) { t.Parallel() ctx := testutil.Context(t, testutil.WaitMedium) client := coderdtest.New(t, &coderdtest.Options{ @@ -526,13 +409,9 @@ func TestWorkspaceAgentStartupLogs(t *testing.T) { agentClient := agentsdk.New(client.URL) agentClient.SetSessionToken(authToken) - err := agentClient.PatchStartupLogs(ctx, agentsdk.PatchStartupLogs{ - Logs: []agentsdk.StartupLog{ - { - CreatedAt: database.Now(), - EOF: true, - }, - }, + err := agentClient.PostLifecycle(ctx, agentsdk.PostLifecycleRequest{ + State: codersdk.WorkspaceAgentLifecycleReady, + ChangedAt: time.Now(), }) require.NoError(t, err) @@ -544,7 +423,7 @@ func TestWorkspaceAgentStartupLogs(t *testing.T) { }, }, }) - require.Error(t, err, "insert after EOF should not succeed") + require.Error(t, err, "insert after script ended should not succeed") }) } @@ -1410,7 +1289,8 @@ func TestWorkspaceAgent_LifecycleState(t *testing.T) { ctx := testutil.Context(t, testutil.WaitLong) err := agentClient.PostLifecycle(ctx, agentsdk.PostLifecycleRequest{ - State: tt.state, + State: tt.state, + ChangedAt: time.Now(), }) if tt.wantErr { require.Error(t, err) diff --git a/codersdk/agentsdk/agentsdk.go b/codersdk/agentsdk/agentsdk.go index 90d2834a37337..289ee07eafd9f 100644 --- a/codersdk/agentsdk/agentsdk.go +++ b/codersdk/agentsdk/agentsdk.go @@ -533,7 +533,8 @@ func (c *Client) PostStats(ctx context.Context, stats *Stats) (StatsResponse, er } type PostLifecycleRequest struct { - State codersdk.WorkspaceAgentLifecycle `json:"state"` + State codersdk.WorkspaceAgentLifecycle `json:"state"` + ChangedAt time.Time `json:"changed_at"` } func (c *Client) PostLifecycle(ctx context.Context, req PostLifecycleRequest) error { @@ -571,7 +572,6 @@ type StartupLog struct { CreatedAt time.Time `json:"created_at"` Output string `json:"output"` Level codersdk.LogLevel `json:"level"` - EOF bool `json:"eof"` } type PatchStartupLogs struct { diff --git a/codersdk/workspaceagents.go b/codersdk/workspaceagents.go index 89396406962ae..d9df5530b6762 100644 --- a/codersdk/workspaceagents.go +++ b/codersdk/workspaceagents.go @@ -39,10 +39,6 @@ const ( // The agent lifecycle starts in the "created" state, and transitions to // "starting" when the agent reports it has begun preparing (e.g. started // executing the startup script). -// -// Note that states are not guaranteed to be reported, for instance the agent -// may go from "created" to "ready" without reporting "starting", if it had -// trouble connecting on startup. type WorkspaceAgentLifecycle string // WorkspaceAgentLifecycle enums. @@ -126,36 +122,37 @@ type WorkspaceAgentMetadata struct { } type WorkspaceAgent struct { - ID uuid.UUID `json:"id" format:"uuid"` - CreatedAt time.Time `json:"created_at" format:"date-time"` - UpdatedAt time.Time `json:"updated_at" format:"date-time"` - FirstConnectedAt *time.Time `json:"first_connected_at,omitempty" format:"date-time"` - LastConnectedAt *time.Time `json:"last_connected_at,omitempty" format:"date-time"` - DisconnectedAt *time.Time `json:"disconnected_at,omitempty" format:"date-time"` - Status WorkspaceAgentStatus `json:"status"` - LifecycleState WorkspaceAgentLifecycle `json:"lifecycle_state"` - Name string `json:"name"` - ResourceID uuid.UUID `json:"resource_id" format:"uuid"` - InstanceID string `json:"instance_id,omitempty"` - Architecture string `json:"architecture"` - EnvironmentVariables map[string]string `json:"environment_variables"` - OperatingSystem string `json:"operating_system"` - StartupScript string `json:"startup_script,omitempty"` - StartupLogsLength int32 `json:"startup_logs_length"` - StartupLogsOverflowed bool `json:"startup_logs_overflowed"` - Directory string `json:"directory,omitempty"` - ExpandedDirectory string `json:"expanded_directory,omitempty"` - Version string `json:"version"` - Apps []WorkspaceApp `json:"apps"` + ID uuid.UUID `json:"id" format:"uuid"` + CreatedAt time.Time `json:"created_at" format:"date-time"` + UpdatedAt time.Time `json:"updated_at" format:"date-time"` + FirstConnectedAt *time.Time `json:"first_connected_at,omitempty" format:"date-time"` + LastConnectedAt *time.Time `json:"last_connected_at,omitempty" format:"date-time"` + DisconnectedAt *time.Time `json:"disconnected_at,omitempty" format:"date-time"` + StartedAt *time.Time `json:"started_at,omitempty" format:"date-time"` + ReadyAt *time.Time `json:"ready_at,omitempty" format:"date-time"` + Status WorkspaceAgentStatus `json:"status"` + LifecycleState WorkspaceAgentLifecycle `json:"lifecycle_state"` + Name string `json:"name"` + ResourceID uuid.UUID `json:"resource_id" format:"uuid"` + InstanceID string `json:"instance_id,omitempty"` + Architecture string `json:"architecture"` + EnvironmentVariables map[string]string `json:"environment_variables"` + OperatingSystem string `json:"operating_system"` + StartupScript string `json:"startup_script,omitempty"` + StartupScriptBehavior WorkspaceAgentStartupScriptBehavior `json:"startup_script_behavior"` + StartupScriptTimeoutSeconds int32 `json:"startup_script_timeout_seconds"` // StartupScriptTimeoutSeconds is the number of seconds to wait for the startup script to complete. If the script does not complete within this time, the agent lifecycle will be marked as start_timeout. + StartupLogsLength int32 `json:"startup_logs_length"` + StartupLogsOverflowed bool `json:"startup_logs_overflowed"` + Directory string `json:"directory,omitempty"` + ExpandedDirectory string `json:"expanded_directory,omitempty"` + Version string `json:"version"` + Apps []WorkspaceApp `json:"apps"` // DERPLatency is mapped by region name (e.g. "New York City", "Seattle"). DERPLatency map[string]DERPRegion `json:"latency,omitempty"` ConnectionTimeoutSeconds int32 `json:"connection_timeout_seconds"` TroubleshootingURL string `json:"troubleshooting_url"` // Deprecated: Use StartupScriptBehavior instead. - LoginBeforeReady bool `json:"login_before_ready"` - StartupScriptBehavior WorkspaceAgentStartupScriptBehavior `json:"startup_script_behavior"` - // StartupScriptTimeoutSeconds is the number of seconds to wait for the startup script to complete. If the script does not complete within this time, the agent lifecycle will be marked as start_timeout. - StartupScriptTimeoutSeconds int32 `json:"startup_script_timeout_seconds"` + LoginBeforeReady bool `json:"login_before_ready"` ShutdownScript string `json:"shutdown_script,omitempty"` ShutdownScriptTimeoutSeconds int32 `json:"shutdown_script_timeout_seconds"` Subsystem AgentSubsystem `json:"subsystem"` @@ -604,7 +601,6 @@ type WorkspaceAgentStartupLog struct { CreatedAt time.Time `json:"created_at" format:"date-time"` Output string `json:"output"` Level LogLevel `json:"level"` - EOF bool `json:"eof"` // EOF indicates that this is the last log entry and the file is closed. } type AgentSubsystem string diff --git a/docs/api/agents.md b/docs/api/agents.md index 7964b3fcd67a0..e25173782600b 100644 --- a/docs/api/agents.md +++ b/docs/api/agents.md @@ -466,9 +466,11 @@ curl -X GET http://coder-server:8080/api/v2/workspaceagents/{workspaceagent} \ "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -702,7 +704,6 @@ curl -X GET http://coder-server:8080/api/v2/workspaceagents/{workspaceagent}/sta [ { "created_at": "2019-08-24T14:15:22Z", - "eof": true, "id": 0, "level": "trace", "output": "string" @@ -720,14 +721,13 @@ curl -X GET http://coder-server:8080/api/v2/workspaceagents/{workspaceagent}/sta Status Code **200** -| Name | Type | Required | Restrictions | Description | -| -------------- | ------------------------------------------------ | -------- | ------------ | --------------------------------------------------------------------- | -| `[array item]` | array | false | | | -| `» created_at` | string(date-time) | false | | | -| `» eof` | boolean | false | | Eof indicates that this is the last log entry and the file is closed. | -| `» id` | integer | false | | | -| `» level` | [codersdk.LogLevel](schemas.md#codersdkloglevel) | false | | | -| `» output` | string | false | | | +| Name | Type | Required | Restrictions | Description | +| -------------- | ------------------------------------------------ | -------- | ------------ | ----------- | +| `[array item]` | array | false | | | +| `» created_at` | string(date-time) | false | | | +| `» id` | integer | false | | | +| `» level` | [codersdk.LogLevel](schemas.md#codersdkloglevel) | false | | | +| `» output` | string | false | | | #### Enumerated Values diff --git a/docs/api/builds.md b/docs/api/builds.md index e58f77251a342..9be82f66851be 100644 --- a/docs/api/builds.md +++ b/docs/api/builds.md @@ -103,9 +103,11 @@ curl -X GET http://coder-server:8080/api/v2/users/{user}/workspace/{workspacenam "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -257,9 +259,11 @@ curl -X GET http://coder-server:8080/api/v2/workspacebuilds/{workspacebuild} \ "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -552,9 +556,11 @@ curl -X GET http://coder-server:8080/api/v2/workspacebuilds/{workspacebuild}/res "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -636,9 +642,11 @@ Status Code **200** | `»» login_before_ready` | boolean | false | | Deprecated: Use StartupScriptBehavior instead. | | `»» name` | string | false | | | | `»» operating_system` | string | false | | | +| `»» ready_at` | string(date-time) | false | | | | `»» resource_id` | string(uuid) | false | | | | `»» shutdown_script` | string | false | | | | `»» shutdown_script_timeout_seconds` | integer | false | | | +| `»» started_at` | string(date-time) | false | | | | `»» startup_logs_length` | integer | false | | | | `»» startup_logs_overflowed` | boolean | false | | | | `»» startup_script` | string | false | | | @@ -797,9 +805,11 @@ curl -X GET http://coder-server:8080/api/v2/workspacebuilds/{workspacebuild}/sta "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -956,9 +966,11 @@ curl -X GET http://coder-server:8080/api/v2/workspaces/{workspace}/builds \ "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -1074,9 +1086,11 @@ Status Code **200** | `»»» login_before_ready` | boolean | false | | Deprecated: Use StartupScriptBehavior instead. | | `»»» name` | string | false | | | | `»»» operating_system` | string | false | | | +| `»»» ready_at` | string(date-time) | false | | | | `»»» resource_id` | string(uuid) | false | | | | `»»» shutdown_script` | string | false | | | | `»»» shutdown_script_timeout_seconds` | integer | false | | | +| `»»» started_at` | string(date-time) | false | | | | `»»» startup_logs_length` | integer | false | | | | `»»» startup_logs_overflowed` | boolean | false | | | | `»»» startup_script` | string | false | | | @@ -1289,9 +1303,11 @@ curl -X POST http://coder-server:8080/api/v2/workspaces/{workspace}/builds \ "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", diff --git a/docs/api/schemas.md b/docs/api/schemas.md index b05444c94696a..cf3e3ac9918e8 100644 --- a/docs/api/schemas.md +++ b/docs/api/schemas.md @@ -280,7 +280,6 @@ "logs": [ { "created_at": "string", - "eof": true, "level": "trace", "output": "string" } @@ -316,15 +315,17 @@ ```json { + "changed_at": "string", "state": "created" } ``` ### Properties -| Name | Type | Required | Restrictions | Description | -| ------- | -------------------------------------------------------------------- | -------- | ------------ | ----------- | -| `state` | [codersdk.WorkspaceAgentLifecycle](#codersdkworkspaceagentlifecycle) | false | | | +| Name | Type | Required | Restrictions | Description | +| ------------ | -------------------------------------------------------------------- | -------- | ------------ | ----------- | +| `changed_at` | string | false | | | +| `state` | [codersdk.WorkspaceAgentLifecycle](#codersdkworkspaceagentlifecycle) | false | | | ## agentsdk.PostMetadataRequest @@ -369,7 +370,6 @@ ```json { "created_at": "string", - "eof": true, "level": "trace", "output": "string" } @@ -380,7 +380,6 @@ | Name | Type | Required | Restrictions | Description | | ------------ | -------------------------------------- | -------- | ------------ | ----------- | | `created_at` | string | false | | | -| `eof` | boolean | false | | | | `level` | [codersdk.LogLevel](#codersdkloglevel) | false | | | | `output` | string | false | | | @@ -4508,9 +4507,11 @@ AuthorizationObject can represent a "set" of objects, such as: all workspaces in "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -4640,9 +4641,11 @@ AuthorizationObject can represent a "set" of objects, such as: all workspaces in "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -4679,9 +4682,11 @@ AuthorizationObject can represent a "set" of objects, such as: all workspaces in | `login_before_ready` | boolean | false | | Deprecated: Use StartupScriptBehavior instead. | | `name` | string | false | | | | `operating_system` | string | false | | | +| `ready_at` | string | false | | | | `resource_id` | string | false | | | | `shutdown_script` | string | false | | | | `shutdown_script_timeout_seconds` | integer | false | | | +| `started_at` | string | false | | | | `startup_logs_length` | integer | false | | | | `startup_logs_overflowed` | boolean | false | | | | `startup_script` | string | false | | | @@ -4844,7 +4849,6 @@ AuthorizationObject can represent a "set" of objects, such as: all workspaces in ```json { "created_at": "2019-08-24T14:15:22Z", - "eof": true, "id": 0, "level": "trace", "output": "string" @@ -4853,13 +4857,12 @@ AuthorizationObject can represent a "set" of objects, such as: all workspaces in ### Properties -| Name | Type | Required | Restrictions | Description | -| ------------ | -------------------------------------- | -------- | ------------ | --------------------------------------------------------------------- | -| `created_at` | string | false | | | -| `eof` | boolean | false | | Eof indicates that this is the last log entry and the file is closed. | -| `id` | integer | false | | | -| `level` | [codersdk.LogLevel](#codersdkloglevel) | false | | | -| `output` | string | false | | | +| Name | Type | Required | Restrictions | Description | +| ------------ | -------------------------------------- | -------- | ------------ | ----------- | +| `created_at` | string | false | | | +| `id` | integer | false | | | +| `level` | [codersdk.LogLevel](#codersdkloglevel) | false | | | +| `output` | string | false | | | ## codersdk.WorkspaceAgentStartupScriptBehavior @@ -5052,9 +5055,11 @@ AuthorizationObject can represent a "set" of objects, such as: all workspaces in "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -5335,9 +5340,11 @@ AuthorizationObject can represent a "set" of objects, such as: all workspaces in "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -5535,9 +5542,11 @@ AuthorizationObject can represent a "set" of objects, such as: all workspaces in "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", diff --git a/docs/api/templates.md b/docs/api/templates.md index b9e3033a83e73..4e5eddc12489c 100644 --- a/docs/api/templates.md +++ b/docs/api/templates.md @@ -1647,9 +1647,11 @@ curl -X GET http://coder-server:8080/api/v2/templateversions/{templateversion}/d "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -1731,9 +1733,11 @@ Status Code **200** | `»» login_before_ready` | boolean | false | | Deprecated: Use StartupScriptBehavior instead. | | `»» name` | string | false | | | | `»» operating_system` | string | false | | | +| `»» ready_at` | string(date-time) | false | | | | `»» resource_id` | string(uuid) | false | | | | `»» shutdown_script` | string | false | | | | `»» shutdown_script_timeout_seconds` | integer | false | | | +| `»» started_at` | string(date-time) | false | | | | `»» startup_logs_length` | integer | false | | | | `»» startup_logs_overflowed` | boolean | false | | | | `»» startup_script` | string | false | | | @@ -2028,9 +2032,11 @@ curl -X GET http://coder-server:8080/api/v2/templateversions/{templateversion}/r "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -2112,9 +2118,11 @@ Status Code **200** | `»» login_before_ready` | boolean | false | | Deprecated: Use StartupScriptBehavior instead. | | `»» name` | string | false | | | | `»» operating_system` | string | false | | | +| `»» ready_at` | string(date-time) | false | | | | `»» resource_id` | string(uuid) | false | | | | `»» shutdown_script` | string | false | | | | `»» shutdown_script_timeout_seconds` | integer | false | | | +| `»» started_at` | string(date-time) | false | | | | `»» startup_logs_length` | integer | false | | | | `»» startup_logs_overflowed` | boolean | false | | | | `»» startup_script` | string | false | | | diff --git a/docs/api/workspaces.md b/docs/api/workspaces.md index b8c31d1bf83eb..57981c3203953 100644 --- a/docs/api/workspaces.md +++ b/docs/api/workspaces.md @@ -127,9 +127,11 @@ curl -X POST http://coder-server:8080/api/v2/organizations/{organization}/member "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -302,9 +304,11 @@ curl -X GET http://coder-server:8080/api/v2/users/{user}/workspace/{workspacenam "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -497,9 +501,11 @@ curl -X GET http://coder-server:8080/api/v2/workspaces \ "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", @@ -673,9 +679,11 @@ curl -X GET http://coder-server:8080/api/v2/workspaces/{workspace} \ "login_before_ready": true, "name": "string", "operating_system": "string", + "ready_at": "2019-08-24T14:15:22Z", "resource_id": "4d5215ed-38bb-48ed-879a-fdb9ca58522f", "shutdown_script": "string", "shutdown_script_timeout_seconds": 0, + "started_at": "2019-08-24T14:15:22Z", "startup_logs_length": 0, "startup_logs_overflowed": true, "startup_script": "string", diff --git a/scripts/coder-dev.sh b/scripts/coder-dev.sh index 5c3de4e310d13..3cffdb87168d1 100755 --- a/scripts/coder-dev.sh +++ b/scripts/coder-dev.sh @@ -26,4 +26,7 @@ if [[ ! -x "${CODER_DEV_BIN}" ]]; then exit 1 fi +if [[ -x /tmp/coder ]]; then + CODER_DEV_BIN=/tmp/coder +fi exec "${CODER_DEV_BIN}" --global-config "${CODER_DEV_DIR}" "$@" diff --git a/site/src/api/typesGenerated.ts b/site/src/api/typesGenerated.ts index 961cc8f16e455..6869e2f47e9bc 100644 --- a/site/src/api/typesGenerated.ts +++ b/site/src/api/typesGenerated.ts @@ -1077,6 +1077,8 @@ export interface WorkspaceAgent { readonly first_connected_at?: string readonly last_connected_at?: string readonly disconnected_at?: string + readonly started_at?: string + readonly ready_at?: string readonly status: WorkspaceAgentStatus readonly lifecycle_state: WorkspaceAgentLifecycle readonly name: string @@ -1086,6 +1088,8 @@ export interface WorkspaceAgent { readonly environment_variables: Record readonly operating_system: string readonly startup_script?: string + readonly startup_script_behavior: WorkspaceAgentStartupScriptBehavior + readonly startup_script_timeout_seconds: number readonly startup_logs_length: number readonly startup_logs_overflowed: boolean readonly directory?: string @@ -1096,8 +1100,6 @@ export interface WorkspaceAgent { readonly connection_timeout_seconds: number readonly troubleshooting_url: string readonly login_before_ready: boolean - readonly startup_script_behavior: WorkspaceAgentStartupScriptBehavior - readonly startup_script_timeout_seconds: number readonly shutdown_script?: string readonly shutdown_script_timeout_seconds: number readonly subsystem: AgentSubsystem @@ -1144,7 +1146,6 @@ export interface WorkspaceAgentStartupLog { readonly created_at: string readonly output: string readonly level: LogLevel - readonly eof: boolean } // From codersdk/workspaceapps.go diff --git a/site/src/components/Resources/AgentRow.tsx b/site/src/components/Resources/AgentRow.tsx index bc2e43e697230..a6a7e9fb57d86 100644 --- a/site/src/components/Resources/AgentRow.tsx +++ b/site/src/components/Resources/AgentRow.tsx @@ -26,7 +26,7 @@ import { FixedSizeList as List, ListOnScrollProps } from "react-window" import { colors } from "theme/colors" import { combineClasses } from "utils/combineClasses" import { - LineWithIDAndEOF, + LineWithID, workspaceAgentLogsMachine, } from "xServices/workspaceAgentLogs/workspaceAgentLogsXService" import { @@ -54,7 +54,7 @@ export interface AgentRowProps { hideVSCodeDesktopButton?: boolean serverVersion: string onUpdateAgent: () => void - storybookStartupLogs?: LineWithIDAndEOF[] + storybookStartupLogs?: LineWithID[] storybookAgentMetadata?: WorkspaceAgentMetadata[] } @@ -124,17 +124,13 @@ export const AgentRow: FC = ({ const startupLogs = useMemo(() => { const allLogs = logsMachine.context.startupLogs || [] - // Filter out eof, since we don't want to show an empty line to the - // user. The timesetamp could be used to show when the log ended in - // the future. - const logs = [...allLogs.filter((log) => !log.eof)] + const logs = [...allLogs] if (agent.startup_logs_overflowed) { logs.push({ id: -1, level: "error", output: "Startup logs exceeded the max size of 1MB!", time: new Date().toISOString(), - eof: false, }) } return logs diff --git a/site/src/testHelpers/entities.ts b/site/src/testHelpers/entities.ts index dd4d8565e2278..6697f83c8ddb2 100644 --- a/site/src/testHelpers/entities.ts +++ b/site/src/testHelpers/entities.ts @@ -1649,7 +1649,6 @@ export const MockStartupLogs: TypesGen.WorkspaceAgentStartupLog[] = [ created_at: "2023-05-04T11:30:41.402072Z", output: "+ curl -fsSL https://code-server.dev/install.sh", level: "info", - eof: false, }, { id: 166664, @@ -1657,28 +1656,18 @@ export const MockStartupLogs: TypesGen.WorkspaceAgentStartupLog[] = [ output: "+ sh -s -- --method=standalone --prefix=/tmp/code-server --version 4.8.3", level: "info", - eof: false, }, { id: 166665, created_at: "2023-05-04T11:30:42.590731Z", output: "Ubuntu 22.04.2 LTS", level: "info", - eof: false, }, { id: 166666, created_at: "2023-05-04T11:30:42.593686Z", output: "Installing v4.8.3 of the amd64 release from GitHub.", level: "info", - eof: false, - }, - { - id: 166667, - created_at: "2023-05-04T11:30:42.599999Z", - output: "", - level: "info", - eof: true, }, ] diff --git a/site/src/xServices/workspaceAgentLogs/workspaceAgentLogsXService.ts b/site/src/xServices/workspaceAgentLogs/workspaceAgentLogsXService.ts index c9aac20eb64bf..37ca026533e7a 100644 --- a/site/src/xServices/workspaceAgentLogs/workspaceAgentLogsXService.ts +++ b/site/src/xServices/workspaceAgentLogs/workspaceAgentLogsXService.ts @@ -6,9 +6,8 @@ import { Line } from "components/Logs/Logs" // Logs are stored as the Line interface to make rendering // much more efficient. Instead of mapping objects each time, we're // able to just pass the array of logs to the component. -export interface LineWithIDAndEOF extends Line { +export interface LineWithID extends Line { id: number - eof: boolean } export const workspaceAgentLogsMachine = createMachine( @@ -19,7 +18,7 @@ export const workspaceAgentLogsMachine = createMachine( events: {} as | { type: "ADD_STARTUP_LOGS" - logs: LineWithIDAndEOF[] + logs: LineWithID[] } | { type: "FETCH_STARTUP_LOGS" @@ -29,11 +28,11 @@ export const workspaceAgentLogsMachine = createMachine( }, context: {} as { agentID: string - startupLogs?: LineWithIDAndEOF[] + startupLogs?: LineWithID[] }, services: {} as { getStartupLogs: { - data: LineWithIDAndEOF[] + data: LineWithID[] } }, }, @@ -83,7 +82,6 @@ export const workspaceAgentLogsMachine = createMachine( level: log.level || "info", output: log.output, time: log.created_at, - eof: log.eof, })), ), streamStartupLogs: (ctx) => async (callback) => { @@ -102,7 +100,6 @@ export const workspaceAgentLogsMachine = createMachine( level: "info" as TypesGen.LogLevel, output: log.output, time: log.created_at, - eof: log.eof, })), }) }, From 43a0f87dc84fb04a692b4b69290db01336d34cc8 Mon Sep 17 00:00:00 2001 From: Mathias Fredriksson Date: Tue, 20 Jun 2023 10:39:24 +0000 Subject: [PATCH 2/3] PR comment fixes --- agent/agent.go | 19 +++++++++---------- ...artup_logs_eof_and_add_completion.down.sql | 2 ++ coderd/workspaceagents.go | 6 +++--- scripts/coder-dev.sh | 3 --- 4 files changed, 14 insertions(+), 16 deletions(-) diff --git a/agent/agent.go b/agent/agent.go index eb30680577cf2..5c1f393f83126 100644 --- a/agent/agent.go +++ b/agent/agent.go @@ -837,14 +837,13 @@ func (a *agent) runShutdownScript(ctx context.Context, script string) error { } func (a *agent) runScript(ctx context.Context, lifecycle, script string) (err error) { - logger := a.logger.With(slog.F("lifecycle", lifecycle)) - if script == "" { - logger.Info(ctx, "not running empty script") return nil } - logger.Info(ctx, "running script", slog.F("script", script)) + logger := a.logger.With(slog.F("lifecycle", lifecycle)) + + logger.Info(ctx, fmt.Sprintf("running %s script", lifecycle), slog.F("script", script)) fileWriter, err := a.filesystem.OpenFile(filepath.Join(a.logDir, fmt.Sprintf("coder-%s-script.log", lifecycle)), os.O_CREATE|os.O_RDWR, 0o600) if err != nil { return xerrors.Errorf("open %s script log file: %w", lifecycle, err) @@ -852,13 +851,13 @@ func (a *agent) runScript(ctx context.Context, lifecycle, script string) (err er defer func() { err := fileWriter.Close() if err != nil { - logger.Warn(ctx, "close script log file", slog.Error(err)) + logger.Warn(ctx, fmt.Sprintf("close %s script log file", lifecycle), slog.Error(err)) } }() cmdPty, err := a.sshServer.CreateCommand(ctx, script, nil) if err != nil { - return xerrors.Errorf("create command: %w", err) + return xerrors.Errorf("%s script: create command: %w", lifecycle, err) } cmd := cmdPty.AsExec() @@ -872,7 +871,7 @@ func (a *agent) runScript(ctx context.Context, lifecycle, script string) (err er writer = io.MultiWriter(fileWriter, logsWriter) flushedLogs, err := a.trackScriptLogs(ctx, logsReader) if err != nil { - return xerrors.Errorf("track script logs: %w", err) + return xerrors.Errorf("track %s script logs: %w", lifecycle, err) } defer func() { _ = logsWriter.Close() @@ -894,9 +893,9 @@ func (a *agent) runScript(ctx context.Context, lifecycle, script string) (err er if xerrors.As(err, &exitError) { exitCode = exitError.ExitCode() } - logger.Warn(ctx, "script failed", slog.F("execution_time", execTime), slog.F("exit_code", exitCode), slog.Error(err)) + logger.Warn(ctx, fmt.Sprintf("%s script failed", lifecycle), slog.F("execution_time", execTime), slog.F("exit_code", exitCode), slog.Error(err)) } else { - logger.Info(ctx, "script completed", slog.F("execution_time", execTime), slog.F("exit_code", exitCode)) + logger.Info(ctx, fmt.Sprintf("%s script completed", lifecycle), slog.F("execution_time", execTime), slog.F("exit_code", exitCode)) } }() @@ -907,7 +906,7 @@ func (a *agent) runScript(ctx context.Context, lifecycle, script string) (err er return ctx.Err() } - return xerrors.Errorf("run: %w", err) + return xerrors.Errorf("%s script: run: %w", lifecycle, err) } return nil } diff --git a/coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.down.sql b/coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.down.sql index 3e6ae79cb4d32..9d57ded80bb7c 100644 --- a/coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.down.sql +++ b/coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.down.sql @@ -4,6 +4,8 @@ ALTER TABLE workspace_agents DROP COLUMN started_at, DROP COLUMN ready_at; +-- We won't bring back log entries where eof = TRUE, but this doesn't matter +-- as the implementation doesn't require it and hasn't been part of a release. ALTER TABLE workspace_agent_startup_logs ADD COLUMN eof boolean NOT NULL DEFAULT false; COMMENT ON COLUMN workspace_agent_startup_logs.eof IS 'End of file reached'; diff --git a/coderd/workspaceagents.go b/coderd/workspaceagents.go index e30060627f374..983178dd7e062 100644 --- a/coderd/workspaceagents.go +++ b/coderd/workspaceagents.go @@ -283,12 +283,12 @@ func (api *API) patchWorkspaceAgentStartupLogs(rw http.ResponseWriter, r *http.R // Ensure logs are not written after script ended. scriptEndedError := xerrors.New("startup script has ended") err := api.Database.InTx(func(db database.Store) error { - ss, err := db.GetWorkspaceAgentLifecycleStateByID(ctx, workspaceAgent.ID) + state, err := db.GetWorkspaceAgentLifecycleStateByID(ctx, workspaceAgent.ID) if err != nil { return xerrors.Errorf("workspace agent startup script status: %w", err) } - if ss.ReadyAt.Valid { + if state.ReadyAt.Valid { // The agent startup script has already ended, so we don't want to // process any more logs. return scriptEndedError @@ -1626,7 +1626,7 @@ func (api *API) workspaceAgentReportLifecycle(rw http.ResponseWriter, r *http.Re ReadyAt: readyAt, }) if err != nil { - logger.Warn(ctx, "failed to update lifecycle state", slog.Error(err)) + logger.Error(ctx, "failed to update lifecycle state", slog.Error(err)) httpapi.InternalServerError(rw, err) return } diff --git a/scripts/coder-dev.sh b/scripts/coder-dev.sh index 3cffdb87168d1..5c3de4e310d13 100755 --- a/scripts/coder-dev.sh +++ b/scripts/coder-dev.sh @@ -26,7 +26,4 @@ if [[ ! -x "${CODER_DEV_BIN}" ]]; then exit 1 fi -if [[ -x /tmp/coder ]]; then - CODER_DEV_BIN=/tmp/coder -fi exec "${CODER_DEV_BIN}" --global-config "${CODER_DEV_DIR}" "$@" From b4f78eb52502b409a05965267ac8be6c3f990444 Mon Sep 17 00:00:00 2001 From: Mathias Fredriksson Date: Tue, 20 Jun 2023 10:45:09 +0000 Subject: [PATCH 3/3] ./coderd/database/migrations/fix_migration_numbers.sh --- ...l => 000129_drop_startup_logs_eof_and_add_completion.down.sql} | 0 ...sql => 000129_drop_startup_logs_eof_and_add_completion.up.sql} | 0 2 files changed, 0 insertions(+), 0 deletions(-) rename coderd/database/migrations/{000128_drop_startup_logs_eof_and_add_completion.down.sql => 000129_drop_startup_logs_eof_and_add_completion.down.sql} (100%) rename coderd/database/migrations/{000128_drop_startup_logs_eof_and_add_completion.up.sql => 000129_drop_startup_logs_eof_and_add_completion.up.sql} (100%) diff --git a/coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.down.sql b/coderd/database/migrations/000129_drop_startup_logs_eof_and_add_completion.down.sql similarity index 100% rename from coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.down.sql rename to coderd/database/migrations/000129_drop_startup_logs_eof_and_add_completion.down.sql diff --git a/coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.up.sql b/coderd/database/migrations/000129_drop_startup_logs_eof_and_add_completion.up.sql similarity index 100% rename from coderd/database/migrations/000128_drop_startup_logs_eof_and_add_completion.up.sql rename to coderd/database/migrations/000129_drop_startup_logs_eof_and_add_completion.up.sql