diff --git a/cli/cliui/cliui.go b/cli/cliui/cliui.go index 5d324e76cd244..e69280cdf4119 100644 --- a/cli/cliui/cliui.go +++ b/cli/cliui/cliui.go @@ -23,7 +23,9 @@ func ValidateNotEmpty(s string) error { // Styles compose visual elements of the UI! var Styles = struct { Bold, + Checkmark, Code, + Crossmark, Field, Keyword, Paragraph, @@ -36,7 +38,9 @@ var Styles = struct { Wrap lipgloss.Style }{ Bold: lipgloss.NewStyle().Bold(true), + Checkmark: defaultStyles.Checkmark, Code: defaultStyles.Code, + Crossmark: defaultStyles.Error.Copy().SetString("✘"), Field: defaultStyles.Code.Copy().Foreground(lipgloss.AdaptiveColor{Light: "#000000", Dark: "#FFFFFF"}), Keyword: defaultStyles.Keyword, Paragraph: defaultStyles.Paragraph, diff --git a/cli/cliui/job.go b/cli/cliui/job.go deleted file mode 100644 index bd7983a5cfcd9..0000000000000 --- a/cli/cliui/job.go +++ /dev/null @@ -1,157 +0,0 @@ -package cliui - -import ( - "fmt" - "os" - "os/signal" - "time" - - "github.com/briandowns/spinner" - "github.com/charmbracelet/lipgloss" - "github.com/spf13/cobra" - - "github.com/coder/coder/coderd/database" - "github.com/coder/coder/codersdk" -) - -type JobOptions struct { - Title string - Output bool - Fetch func() (codersdk.ProvisionerJob, error) - Cancel func() error - Logs func() (<-chan codersdk.ProvisionerJobLog, error) -} - -// Job renders a provisioner job. -func Job(cmd *cobra.Command, opts JobOptions) (codersdk.ProvisionerJob, error) { - var ( - spin = spinner.New(spinner.CharSets[5], 100*time.Millisecond, spinner.WithColor("fgGreen")) - - started = false - completed = false - job codersdk.ProvisionerJob - ) - _, _ = fmt.Fprintf(cmd.OutOrStdout(), "%s%s %s\n", Styles.FocusedPrompt, opts.Title, Styles.Placeholder.Render("(ctrl+c to cancel)")) - - spin.Writer = cmd.OutOrStdout() - defer spin.Stop() - - // Refreshes the job state! - refresh := func() { - var err error - job, err = opts.Fetch() - if err != nil { - _, _ = fmt.Fprintln(cmd.OutOrStdout(), defaultStyles.Error.Render(err.Error())) - return - } - - if !started && job.StartedAt != nil { - spin.Stop() - _, _ = fmt.Fprintf(cmd.OutOrStdout(), Styles.Prompt.String()+"Started "+Styles.Placeholder.Render("[%dms]")+"\n", job.StartedAt.Sub(job.CreatedAt).Milliseconds()) - spin.Start() - started = true - } - if !completed && job.CompletedAt != nil { - spin.Stop() - msg := "" - switch job.Status { - case codersdk.ProvisionerJobCanceled: - msg = "Canceled" - case codersdk.ProvisionerJobFailed: - msg = "Completed" - case codersdk.ProvisionerJobSucceeded: - msg = "Built" - } - started := job.CreatedAt - if job.StartedAt != nil { - started = *job.StartedAt - } - _, _ = fmt.Fprintf(cmd.OutOrStderr(), Styles.Prompt.String()+msg+" "+Styles.Placeholder.Render("[%dms]")+"\n", job.CompletedAt.Sub(started).Milliseconds()) - spin.Start() - completed = true - } - - switch job.Status { - case codersdk.ProvisionerJobPending: - spin.Suffix = " Queued" - case codersdk.ProvisionerJobRunning: - spin.Suffix = " Running" - case codersdk.ProvisionerJobCanceling: - spin.Suffix = " Canceling" - } - } - refresh() - spin.Start() - - stopChan := make(chan os.Signal, 1) - defer signal.Stop(stopChan) - go func() { - signal.Notify(stopChan, os.Interrupt) - select { - case <-cmd.Context().Done(): - return - case _, ok := <-stopChan: - if !ok { - return - } - } - signal.Stop(stopChan) - spin.Stop() - _, _ = fmt.Fprintf(cmd.OutOrStdout(), Styles.FocusedPrompt.String()+"Gracefully canceling... wait for exit or data loss may occur!\n") - spin.Start() - err := opts.Cancel() - if err != nil { - spin.Stop() - _, _ = fmt.Fprintln(cmd.OutOrStdout(), defaultStyles.Error.Render(err.Error())) - return - } - refresh() - }() - - logs, err := opts.Logs() - if err != nil { - return job, err - } - - firstLog := false - ticker := time.NewTicker(time.Second) - for { - select { - case <-cmd.Context().Done(): - return job, cmd.Context().Err() - case <-ticker.C: - refresh() - if job.CompletedAt != nil { - return job, nil - } - case log, ok := <-logs: - if !ok { - refresh() - return job, nil - } - if !firstLog { - refresh() - firstLog = true - } - if !opts.Output { - continue - } - spin.Stop() - var style lipgloss.Style - switch log.Level { - case database.LogLevelTrace: - style = defaultStyles.Error - case database.LogLevelDebug: - style = defaultStyles.Error - case database.LogLevelError: - style = defaultStyles.Error - case database.LogLevelWarn: - style = Styles.Warn - case database.LogLevelInfo: - style = defaultStyles.Note - } - _, _ = fmt.Fprintf(cmd.OutOrStdout(), "%s %s %s\n", Styles.Placeholder.Render("|"), style.Render(string(log.Level)), log.Output) - spin.Start() - } - } -} diff --git a/cli/cliui/provisionerjob.go b/cli/cliui/provisionerjob.go new file mode 100644 index 0000000000000..639c08de8f5d5 --- /dev/null +++ b/cli/cliui/provisionerjob.go @@ -0,0 +1,191 @@ +package cliui + +import ( + "context" + "fmt" + "os" + "os/signal" + "sync" + "time" + + "github.com/google/uuid" + "github.com/spf13/cobra" + "golang.org/x/xerrors" + + "github.com/coder/coder/coderd/database" + "github.com/coder/coder/codersdk" +) + +func WorkspaceBuild(cmd *cobra.Command, client *codersdk.Client, build uuid.UUID, before time.Time) error { + return ProvisionerJob(cmd, ProvisionerJobOptions{ + Fetch: func() (codersdk.ProvisionerJob, error) { + build, err := client.WorkspaceBuild(cmd.Context(), build) + return build.Job, err + }, + Logs: func() (<-chan codersdk.ProvisionerJobLog, error) { + return client.WorkspaceBuildLogsAfter(cmd.Context(), build, before) + }, + }) +} + +type ProvisionerJobOptions struct { + Fetch func() (codersdk.ProvisionerJob, error) + Cancel func() error + Logs func() (<-chan codersdk.ProvisionerJobLog, error) + + FetchInterval time.Duration + // Verbose determines whether debug and trace logs will be shown. + Verbose bool +} + +// ProvisionerJob renders a provisioner job with interactive cancellation. +func ProvisionerJob(cmd *cobra.Command, opts ProvisionerJobOptions) error { + if opts.FetchInterval == 0 { + opts.FetchInterval = time.Second + } + + var ( + currentStage = "Queued" + currentStageStartedAt = time.Now().UTC() + didLogBetweenStage = false + ctx, cancelFunc = context.WithCancel(cmd.Context()) + + errChan = make(chan error, 1) + job codersdk.ProvisionerJob + jobMutex sync.Mutex + ) + defer cancelFunc() + + printStage := func() { + _, _ = fmt.Fprintf(cmd.OutOrStdout(), Styles.Prompt.Render("⧗")+"%s\n", Styles.Field.Render(currentStage)) + } + + updateStage := func(stage string, startedAt time.Time) { + if currentStage != "" { + prefix := "" + if !didLogBetweenStage { + prefix = "\033[1A\r" + } + mark := Styles.Checkmark + if job.CompletedAt != nil && job.Status != codersdk.ProvisionerJobSucceeded { + mark = Styles.Crossmark + } + _, _ = fmt.Fprintf(cmd.OutOrStdout(), prefix+mark.String()+Styles.Placeholder.Render(" %s [%dms]")+"\n", currentStage, startedAt.Sub(currentStageStartedAt).Milliseconds()) + } + if stage == "" { + return + } + currentStage = stage + currentStageStartedAt = startedAt + didLogBetweenStage = false + printStage() + } + + updateJob := func() { + var err error + jobMutex.Lock() + defer jobMutex.Unlock() + job, err = opts.Fetch() + if err != nil { + errChan <- xerrors.Errorf("fetch: %w", err) + return + } + if job.StartedAt == nil { + return + } + if currentStage != "Queued" { + // If another stage is already running, there's no need + // for us to notify the user we're running! + return + } + updateStage("Running", *job.StartedAt) + } + updateJob() + + if opts.Cancel != nil { + // Handles ctrl+c to cancel a job. + stopChan := make(chan os.Signal, 1) + signal.Notify(stopChan, os.Interrupt) + go func() { + defer signal.Stop(stopChan) + select { + case <-ctx.Done(): + return + case _, ok := <-stopChan: + if !ok { + return + } + } + _, _ = fmt.Fprintf(cmd.OutOrStdout(), "\033[2K\r\n"+Styles.FocusedPrompt.String()+Styles.Bold.Render("Gracefully canceling...")+"\n\n") + err := opts.Cancel() + if err != nil { + errChan <- xerrors.Errorf("cancel: %w", err) + return + } + updateJob() + }() + } + + // The initial stage needs to print after the signal handler has been registered. + printStage() + + logs, err := opts.Logs() + if err != nil { + return xerrors.Errorf("logs: %w", err) + } + + ticker := time.NewTicker(opts.FetchInterval) + for { + select { + case err = <-errChan: + return err + case <-ctx.Done(): + return ctx.Err() + case <-ticker.C: + updateJob() + case log, ok := <-logs: + if !ok { + updateJob() + jobMutex.Lock() + if job.CompletedAt != nil { + updateStage("", *job.CompletedAt) + } + switch job.Status { + case codersdk.ProvisionerJobCanceled: + jobMutex.Unlock() + return Canceled + case codersdk.ProvisionerJobSucceeded: + jobMutex.Unlock() + return nil + case codersdk.ProvisionerJobFailed: + } + err = xerrors.New(job.Error) + jobMutex.Unlock() + return err + } + output := "" + switch log.Level { + case database.LogLevelTrace, database.LogLevelDebug: + if !opts.Verbose { + continue + } + output = Styles.Placeholder.Render(log.Output) + case database.LogLevelError: + output = defaultStyles.Error.Render(log.Output) + case database.LogLevelWarn: + output = Styles.Warn.Render(log.Output) + case database.LogLevelInfo: + output = log.Output + } + jobMutex.Lock() + if log.Stage != currentStage && log.Stage != "" { + updateStage(log.Stage, log.CreatedAt) + jobMutex.Unlock() + continue + } + _, _ = fmt.Fprintf(cmd.OutOrStdout(), "%s %s\n", Styles.Placeholder.Render(" "), output) + didLogBetweenStage = true + jobMutex.Unlock() + } + } +} diff --git a/cli/cliui/provisionerjob_test.go b/cli/cliui/provisionerjob_test.go new file mode 100644 index 0000000000000..7483e5961fc6b --- /dev/null +++ b/cli/cliui/provisionerjob_test.go @@ -0,0 +1,166 @@ +package cliui_test + +import ( + "context" + "os" + "runtime" + "sync" + "testing" + "time" + + "github.com/spf13/cobra" + "github.com/stretchr/testify/require" + + "github.com/coder/coder/cli/cliui" + "github.com/coder/coder/coderd/database" + "github.com/coder/coder/codersdk" + "github.com/coder/coder/pty/ptytest" +) + +// This cannot be ran in parallel because it uses a signal. +// nolint:tparallel +func TestProvisionerJob(t *testing.T) { + t.Run("NoLogs", func(t *testing.T) { + t.Parallel() + + test := newProvisionerJob(t) + go func() { + <-test.Next + test.JobMutex.Lock() + test.Job.Status = codersdk.ProvisionerJobRunning + now := database.Now() + test.Job.StartedAt = &now + test.JobMutex.Unlock() + <-test.Next + test.JobMutex.Lock() + test.Job.Status = codersdk.ProvisionerJobSucceeded + now = database.Now() + test.Job.CompletedAt = &now + close(test.Logs) + test.JobMutex.Unlock() + }() + test.PTY.ExpectMatch("Queued") + test.Next <- struct{}{} + test.PTY.ExpectMatch("Queued") + test.PTY.ExpectMatch("Running") + test.Next <- struct{}{} + test.PTY.ExpectMatch("Running") + }) + + t.Run("Stages", func(t *testing.T) { + t.Parallel() + + test := newProvisionerJob(t) + go func() { + <-test.Next + test.JobMutex.Lock() + test.Job.Status = codersdk.ProvisionerJobRunning + now := database.Now() + test.Job.StartedAt = &now + test.Logs <- codersdk.ProvisionerJobLog{ + CreatedAt: database.Now(), + Stage: "Something", + } + test.JobMutex.Unlock() + <-test.Next + test.JobMutex.Lock() + test.Job.Status = codersdk.ProvisionerJobSucceeded + now = database.Now() + test.Job.CompletedAt = &now + close(test.Logs) + test.JobMutex.Unlock() + }() + test.PTY.ExpectMatch("Queued") + test.Next <- struct{}{} + test.PTY.ExpectMatch("Queued") + test.PTY.ExpectMatch("Something") + test.Next <- struct{}{} + test.PTY.ExpectMatch("Something") + }) + + // This cannot be ran in parallel because it uses a signal. + // nolint:paralleltest + t.Run("Cancel", func(t *testing.T) { + if runtime.GOOS == "windows" { + // Sending interrupt signal isn't supported on Windows! + t.SkipNow() + } + + test := newProvisionerJob(t) + go func() { + <-test.Next + currentProcess, err := os.FindProcess(os.Getpid()) + require.NoError(t, err) + err = currentProcess.Signal(os.Interrupt) + require.NoError(t, err) + <-test.Next + test.JobMutex.Lock() + test.Job.Status = codersdk.ProvisionerJobCanceled + now := database.Now() + test.Job.CompletedAt = &now + close(test.Logs) + test.JobMutex.Unlock() + }() + test.PTY.ExpectMatch("Queued") + test.Next <- struct{}{} + test.PTY.ExpectMatch("Gracefully canceling") + test.Next <- struct{}{} + test.PTY.ExpectMatch("Queued") + }) +} + +type provisionerJobTest struct { + Next chan struct{} + Job *codersdk.ProvisionerJob + JobMutex *sync.Mutex + Logs chan codersdk.ProvisionerJobLog + PTY *ptytest.PTY +} + +func newProvisionerJob(t *testing.T) provisionerJobTest { + job := &codersdk.ProvisionerJob{ + Status: codersdk.ProvisionerJobPending, + CreatedAt: database.Now(), + } + jobLock := sync.Mutex{} + logs := make(chan codersdk.ProvisionerJobLog, 1) + cmd := &cobra.Command{ + RunE: func(cmd *cobra.Command, args []string) error { + return cliui.ProvisionerJob(cmd, cliui.ProvisionerJobOptions{ + FetchInterval: time.Millisecond, + Fetch: func() (codersdk.ProvisionerJob, error) { + jobLock.Lock() + defer jobLock.Unlock() + return *job, nil + }, + Cancel: func() error { + return nil + }, + Logs: func() (<-chan codersdk.ProvisionerJobLog, error) { + return logs, nil + }, + }) + }, + } + ptty := ptytest.New(t) + cmd.SetOutput(ptty.Output()) + cmd.SetIn(ptty.Input()) + done := make(chan struct{}) + go func() { + defer close(done) + err := cmd.ExecuteContext(context.Background()) + if err != nil { + require.ErrorIs(t, err, cliui.Canceled) + } + }() + t.Cleanup(func() { + <-done + }) + return provisionerJobTest{ + Next: make(chan struct{}), + Job: job, + JobMutex: &jobLock, + Logs: logs, + PTY: ptty, + } +} diff --git a/cli/projectcreate.go b/cli/projectcreate.go index 232b8f571f8d6..1465558369e83 100644 --- a/cli/projectcreate.go +++ b/cli/projectcreate.go @@ -9,7 +9,6 @@ import ( "time" "github.com/briandowns/spinner" - "github.com/fatih/color" "github.com/manifoldco/promptui" "github.com/spf13/cobra" "golang.org/x/xerrors" @@ -126,8 +125,7 @@ func createValidProjectVersion(cmd *cobra.Command, client *codersdk.Client, orga return nil, nil, err } - _, err = cliui.Job(cmd, cliui.JobOptions{ - Title: "Building project...", + err = cliui.ProvisionerJob(cmd, cliui.ProvisionerJobOptions{ Fetch: func() (codersdk.ProvisionerJob, error) { version, err := client.ProjectVersion(cmd.Context(), version.ID) return version.Job, err @@ -140,7 +138,9 @@ func createValidProjectVersion(cmd *cobra.Command, client *codersdk.Client, orga }, }) if err != nil { - return nil, nil, err + if !provisionerd.IsMissingParameterError(err.Error()) { + return nil, nil, err + } } version, err = client.ProjectVersion(cmd.Context(), version.ID) if err != nil { @@ -192,7 +192,7 @@ func createValidProjectVersion(cmd *cobra.Command, client *codersdk.Client, orga return nil, nil, xerrors.New(version.Job.Error) } - _, _ = fmt.Fprintf(cmd.OutOrStdout(), "%s Successfully imported project source!\n", color.HiGreenString("✓")) + _, _ = fmt.Fprintf(cmd.OutOrStdout(), cliui.Styles.Checkmark.String()+" Successfully imported project source!\n") resources, err := client.ProjectVersionResources(cmd.Context(), version.ID) if err != nil { diff --git a/cli/start.go b/cli/start.go index 00e4996dc6905..99260ed78565d 100644 --- a/cli/start.go +++ b/cli/start.go @@ -109,7 +109,7 @@ func start() *cobra.Command { if err != nil { return xerrors.Errorf("create tunnel: %w", err) } - _, _ = fmt.Fprintf(cmd.OutOrStdout(), cliui.Styles.Paragraph.Render(cliui.Styles.Wrap.Render(cliui.Styles.Prompt.String()+`Tunnel started. Your deployment is accessible at:`))+"\n "+cliui.Styles.Field.Render(accessURL)) + _, _ = fmt.Fprintf(cmd.OutOrStdout(), cliui.Styles.Paragraph.Render(cliui.Styles.Wrap.Render(cliui.Styles.Prompt.String()+`Tunnel started. Your deployment is accessible at:`))+"\n "+cliui.Styles.Field.Render(accessURL)+"\n") } } validator, err := idtoken.NewValidator(cmd.Context(), option.WithoutAuthentication()) @@ -262,8 +262,7 @@ func start() *cobra.Command { return xerrors.Errorf("delete workspace: %w", err) } - _, err = cliui.Job(cmd, cliui.JobOptions{ - Title: fmt.Sprintf("Deleting workspace %s...", cliui.Styles.Keyword.Render(workspace.Name)), + err = cliui.ProvisionerJob(cmd, cliui.ProvisionerJobOptions{ Fetch: func() (codersdk.ProvisionerJob, error) { build, err := client.WorkspaceBuild(cmd.Context(), build.ID) return build.Job, err diff --git a/cli/start_test.go b/cli/start_test.go index 2a35f2ca1e713..00366e4792441 100644 --- a/cli/start_test.go +++ b/cli/start_test.go @@ -26,8 +26,9 @@ import ( "github.com/coder/coder/codersdk" ) +// This cannot be ran in parallel because it uses a signal. +// nolint:tparallel func TestStart(t *testing.T) { - t.Parallel() t.Run("Production", func(t *testing.T) { t.Parallel() if runtime.GOOS != "linux" || testing.Short() { diff --git a/cli/workspacecreate.go b/cli/workspacecreate.go index 93b1997047dcd..0ab036909e981 100644 --- a/cli/workspacecreate.go +++ b/cli/workspacecreate.go @@ -146,8 +146,7 @@ func workspaceCreate() *cobra.Command { if err != nil { return err } - _, err = cliui.Job(cmd, cliui.JobOptions{ - Title: "Building workspace...", + err = cliui.ProvisionerJob(cmd, cliui.ProvisionerJobOptions{ Fetch: func() (codersdk.ProvisionerJob, error) { build, err := client.WorkspaceBuild(cmd.Context(), workspace.LatestBuild.ID) return build.Job, err diff --git a/cli/workspacedelete.go b/cli/workspacedelete.go index 4dfd59a57bf1f..b01b75f0dc87a 100644 --- a/cli/workspacedelete.go +++ b/cli/workspacedelete.go @@ -32,8 +32,7 @@ func workspaceDelete() *cobra.Command { if err != nil { return err } - _, err = cliui.Job(cmd, cliui.JobOptions{ - Title: "Deleting workspace...", + err = cliui.ProvisionerJob(cmd, cliui.ProvisionerJobOptions{ Fetch: func() (codersdk.ProvisionerJob, error) { build, err := client.WorkspaceBuild(cmd.Context(), build.ID) return build.Job, err diff --git a/cli/workspacestart.go b/cli/workspacestart.go index f19ceb2aeaa38..a477b222443bc 100644 --- a/cli/workspacestart.go +++ b/cli/workspacestart.go @@ -31,8 +31,7 @@ func workspaceStart() *cobra.Command { if err != nil { return err } - _, err = cliui.Job(cmd, cliui.JobOptions{ - Title: "Starting workspace...", + err = cliui.ProvisionerJob(cmd, cliui.ProvisionerJobOptions{ Fetch: func() (codersdk.ProvisionerJob, error) { build, err := client.WorkspaceBuild(cmd.Context(), build.ID) return build.Job, err diff --git a/cli/workspacestop.go b/cli/workspacestop.go index 4b07b478d7717..28071e4b15ec5 100644 --- a/cli/workspacestop.go +++ b/cli/workspacestop.go @@ -31,8 +31,7 @@ func workspaceStop() *cobra.Command { if err != nil { return err } - _, err = cliui.Job(cmd, cliui.JobOptions{ - Title: "Stopping workspace...", + err = cliui.ProvisionerJob(cmd, cliui.ProvisionerJobOptions{ Fetch: func() (codersdk.ProvisionerJob, error) { build, err := client.WorkspaceBuild(cmd.Context(), build.ID) return build.Job, err diff --git a/cmd/cliui/main.go b/cmd/cliui/main.go index bd8829cc1be00..3f95fcbb5298b 100644 --- a/cmd/cliui/main.go +++ b/cmd/cliui/main.go @@ -94,7 +94,7 @@ func main() { job.Status = codersdk.ProvisionerJobSucceeded }() - _, err := cliui.Job(cmd, cliui.JobOptions{ + err := cliui.ProvisionerJob(cmd, cliui.ProvisionerJobOptions{ Fetch: func() (codersdk.ProvisionerJob, error) { return job, nil }, @@ -102,16 +102,42 @@ func main() { logs := make(chan codersdk.ProvisionerJobLog) go func() { defer close(logs) - ticker := time.NewTicker(500 * time.Millisecond) + ticker := time.NewTicker(100 * time.Millisecond) + defer ticker.Stop() + count := 0 for { select { case <-cmd.Context().Done(): return case <-ticker.C: - logs <- codersdk.ProvisionerJobLog{ - Output: "Some log", - Level: database.LogLevelInfo, + if job.Status == codersdk.ProvisionerJobSucceeded || job.Status == codersdk.ProvisionerJobCanceled { + return } + log := codersdk.ProvisionerJobLog{ + CreatedAt: time.Now(), + Output: fmt.Sprintf("Some log %d", count), + Level: database.LogLevelInfo, + } + switch { + case count == 10: + log.Stage = "Setting Up" + case count == 20: + log.Stage = "Executing Hook" + case count == 30: + log.Stage = "Parsing Variables" + case count == 40: + log.Stage = "Provisioning" + case count == 50: + log.Stage = "Cleaning Up" + } + if count%5 == 0 { + log.Level = database.LogLevelWarn + } + count++ + if log.Output == "" && log.Stage == "" { + continue + } + logs <- log } } }() diff --git a/coderd/database/databasefake/databasefake.go b/coderd/database/databasefake/databasefake.go index 82d1c4a472cbc..618c1c6daf0cd 100644 --- a/coderd/database/databasefake/databasefake.go +++ b/coderd/database/databasefake/databasefake.go @@ -898,6 +898,7 @@ func (q *fakeQuerier) InsertProvisionerJobLogs(_ context.Context, arg database.I CreatedAt: arg.CreatedAt[index], Source: arg.Source[index], Level: arg.Level[index], + Stage: arg.Stage[index], Output: output, }) } @@ -1201,7 +1202,6 @@ func (q *fakeQuerier) UpdateProvisionerJobWithCompleteByID(_ context.Context, ar } job.UpdatedAt = arg.UpdatedAt job.CompletedAt = arg.CompletedAt - job.CanceledAt = arg.CanceledAt job.Error = arg.Error q.provisionerJobs[index] = job return nil diff --git a/coderd/database/dump.sql b/coderd/database/dump.sql index dc3d6a7c6e50d..f0150fb5b825a 100644 --- a/coderd/database/dump.sql +++ b/coderd/database/dump.sql @@ -190,6 +190,7 @@ CREATE TABLE provisioner_job_logs ( created_at timestamp with time zone NOT NULL, source log_source NOT NULL, level log_level NOT NULL, + stage character varying(128) NOT NULL, output character varying(1024) NOT NULL ); diff --git a/coderd/database/migrations/000004_jobs.up.sql b/coderd/database/migrations/000004_jobs.up.sql index ddddeba5c0bec..bf9b731d4e744 100644 --- a/coderd/database/migrations/000004_jobs.up.sql +++ b/coderd/database/migrations/000004_jobs.up.sql @@ -53,6 +53,7 @@ CREATE TABLE IF NOT EXISTS provisioner_job_logs ( created_at timestamptz NOT NULL, source log_source NOT NULL, level log_level NOT NULL, + stage varchar(128) NOT NULL, output varchar(1024) NOT NULL ); diff --git a/coderd/database/models.go b/coderd/database/models.go index 2296fec308c6d..8e4eecd5e4cff 100644 --- a/coderd/database/models.go +++ b/coderd/database/models.go @@ -388,6 +388,7 @@ type ProvisionerJobLog struct { CreatedAt time.Time `db:"created_at" json:"created_at"` Source LogSource `db:"source" json:"source"` Level LogLevel `db:"level" json:"level"` + Stage string `db:"stage" json:"stage"` Output string `db:"output" json:"output"` } diff --git a/coderd/database/query.sql b/coderd/database/query.sql index bb13ade06f94d..7bc2c5f3245b7 100644 --- a/coderd/database/query.sql +++ b/coderd/database/query.sql @@ -482,6 +482,7 @@ SELECT unnest(@created_at :: timestamptz [ ]) AS created_at, unnest(@source :: log_source [ ]) as source, unnest(@level :: log_level [ ]) as level, + unnest(@stage :: varchar(128) [ ]) as stage, unnest(@output :: varchar(1024) [ ]) as output RETURNING *; -- name: InsertOrganization :one @@ -757,8 +758,7 @@ UPDATE SET updated_at = $2, completed_at = $3, - canceled_at = $4, - error = $5 + error = $4 WHERE id = $1; diff --git a/coderd/database/query.sql.go b/coderd/database/query.sql.go index b7f58c1f746c7..38da2dddba6de 100644 --- a/coderd/database/query.sql.go +++ b/coderd/database/query.sql.go @@ -829,7 +829,7 @@ func (q *sqlQuerier) GetProvisionerJobsByIDs(ctx context.Context, ids []uuid.UUI const getProvisionerLogsByIDBetween = `-- name: GetProvisionerLogsByIDBetween :many SELECT - id, job_id, created_at, source, level, output + id, job_id, created_at, source, level, stage, output FROM provisioner_job_logs WHERE @@ -863,6 +863,7 @@ func (q *sqlQuerier) GetProvisionerLogsByIDBetween(ctx context.Context, arg GetP &i.CreatedAt, &i.Source, &i.Level, + &i.Stage, &i.Output, ); err != nil { return nil, err @@ -2121,7 +2122,8 @@ SELECT unnest($3 :: timestamptz [ ]) AS created_at, unnest($4 :: log_source [ ]) as source, unnest($5 :: log_level [ ]) as level, - unnest($6 :: varchar(1024) [ ]) as output RETURNING id, job_id, created_at, source, level, output + unnest($6 :: varchar(128) [ ]) as stage, + unnest($7 :: varchar(1024) [ ]) as output RETURNING id, job_id, created_at, source, level, stage, output ` type InsertProvisionerJobLogsParams struct { @@ -2130,6 +2132,7 @@ type InsertProvisionerJobLogsParams struct { CreatedAt []time.Time `db:"created_at" json:"created_at"` Source []LogSource `db:"source" json:"source"` Level []LogLevel `db:"level" json:"level"` + Stage []string `db:"stage" json:"stage"` Output []string `db:"output" json:"output"` } @@ -2140,6 +2143,7 @@ func (q *sqlQuerier) InsertProvisionerJobLogs(ctx context.Context, arg InsertPro pq.Array(arg.CreatedAt), pq.Array(arg.Source), pq.Array(arg.Level), + pq.Array(arg.Stage), pq.Array(arg.Output), ) if err != nil { @@ -2155,6 +2159,7 @@ func (q *sqlQuerier) InsertProvisionerJobLogs(ctx context.Context, arg InsertPro &i.CreatedAt, &i.Source, &i.Level, + &i.Stage, &i.Output, ); err != nil { return nil, err @@ -2617,8 +2622,7 @@ UPDATE SET updated_at = $2, completed_at = $3, - canceled_at = $4, - error = $5 + error = $4 WHERE id = $1 ` @@ -2627,7 +2631,6 @@ type UpdateProvisionerJobWithCompleteByIDParams struct { ID uuid.UUID `db:"id" json:"id"` UpdatedAt time.Time `db:"updated_at" json:"updated_at"` CompletedAt sql.NullTime `db:"completed_at" json:"completed_at"` - CanceledAt sql.NullTime `db:"canceled_at" json:"canceled_at"` Error sql.NullString `db:"error" json:"error"` } @@ -2636,7 +2639,6 @@ func (q *sqlQuerier) UpdateProvisionerJobWithCompleteByID(ctx context.Context, a arg.ID, arg.UpdatedAt, arg.CompletedAt, - arg.CanceledAt, arg.Error, ) return err diff --git a/coderd/projectversions_test.go b/coderd/projectversions_test.go index 15bc4bfc8e969..7a58600202a2a 100644 --- a/coderd/projectversions_test.go +++ b/coderd/projectversions_test.go @@ -94,9 +94,7 @@ func TestPatchCancelProjectVersion(t *testing.T) { var err error version, err = client.ProjectVersion(context.Background(), version.ID) require.NoError(t, err) - // The echo provisioner doesn't respond to a shutdown request, - // so the job cancel will time out and fail. - return version.Job.Status == codersdk.ProvisionerJobFailed + return version.Job.Status == codersdk.ProvisionerJobCanceled }, 5*time.Second, 25*time.Millisecond) }) } @@ -274,6 +272,10 @@ func TestProjectVersionLogs(t *testing.T) { t.Cleanup(cancelFunc) logs, err := client.ProjectVersionLogsAfter(ctx, version.ID, before) require.NoError(t, err) - log := <-logs - require.Equal(t, "example", log.Output) + for { + _, ok := <-logs + if !ok { + return + } + } } diff --git a/coderd/provisionerdaemons.go b/coderd/provisionerdaemons.go index ce203c283b89e..2c3d3f2ddc961 100644 --- a/coderd/provisionerdaemons.go +++ b/coderd/provisionerdaemons.go @@ -301,6 +301,7 @@ func (server *provisionerdServer) UpdateJob(ctx context.Context, request *proto. insertParams.ID = append(insertParams.ID, uuid.New()) insertParams.CreatedAt = append(insertParams.CreatedAt, time.UnixMilli(log.CreatedAt)) insertParams.Level = append(insertParams.Level, logLevel) + insertParams.Stage = append(insertParams.Stage, log.Stage) insertParams.Source = append(insertParams.Source, logSource) insertParams.Output = append(insertParams.Output, log.Output) } diff --git a/coderd/provisionerjobs.go b/coderd/provisionerjobs.go index 7e5682e65b67a..2fa6f253f8292 100644 --- a/coderd/provisionerjobs.go +++ b/coderd/provisionerjobs.go @@ -224,6 +224,7 @@ func convertProvisionerJobLog(provisionerJobLog database.ProvisionerJobLog) code CreatedAt: provisionerJobLog.CreatedAt, Source: provisionerJobLog.Source, Level: provisionerJobLog.Level, + Stage: provisionerJobLog.Stage, Output: provisionerJobLog.Output, } } diff --git a/coderd/provisionerjobs_test.go b/coderd/provisionerjobs_test.go index c4aef5c7550ca..70afdbf609f80 100644 --- a/coderd/provisionerjobs_test.go +++ b/coderd/provisionerjobs_test.go @@ -45,12 +45,12 @@ func TestProvisionerJobLogs(t *testing.T) { t.Cleanup(cancelFunc) logs, err := client.WorkspaceBuildLogsAfter(ctx, workspace.LatestBuild.ID, before) require.NoError(t, err) - log, ok := <-logs - require.True(t, ok) - require.Equal(t, "log-output", log.Output) - // Make sure the channel automatically closes! - _, ok = <-logs - require.False(t, ok) + for { + _, ok := <-logs + if !ok { + return + } + } }) t.Run("StreamWhileRunning", func(t *testing.T) { @@ -81,10 +81,12 @@ func TestProvisionerJobLogs(t *testing.T) { t.Cleanup(cancelFunc) logs, err := client.WorkspaceBuildLogsAfter(ctx, workspace.LatestBuild.ID, before) require.NoError(t, err) - log := <-logs - require.Equal(t, "log-output", log.Output) - _, ok := <-logs - require.False(t, ok) + for { + _, ok := <-logs + if !ok { + return + } + } }) t.Run("List", func(t *testing.T) { @@ -113,6 +115,6 @@ func TestProvisionerJobLogs(t *testing.T) { coderdtest.AwaitWorkspaceBuildJob(t, client, workspace.LatestBuild.ID) logs, err := client.WorkspaceBuildLogsBefore(context.Background(), workspace.LatestBuild.ID, time.Now()) require.NoError(t, err) - require.Len(t, logs, 1) + require.Greater(t, len(logs), 1) }) } diff --git a/coderd/workspacebuilds_test.go b/coderd/workspacebuilds_test.go index 2e9814cf713b8..a5b1c520db80d 100644 --- a/coderd/workspacebuilds_test.go +++ b/coderd/workspacebuilds_test.go @@ -57,9 +57,7 @@ func TestPatchCancelWorkspaceBuild(t *testing.T) { var err error build, err = client.WorkspaceBuild(context.Background(), build.ID) require.NoError(t, err) - // The echo provisioner doesn't respond to a shutdown request, - // so the job cancel will time out and fail. - return build.Job.Status == codersdk.ProvisionerJobFailed + return build.Job.Status == codersdk.ProvisionerJobCanceled }, 5*time.Second, 25*time.Millisecond) } @@ -159,6 +157,14 @@ func TestWorkspaceBuildLogs(t *testing.T) { t.Cleanup(cancelFunc) logs, err := client.WorkspaceBuildLogsAfter(ctx, workspace.LatestBuild.ID, before) require.NoError(t, err) - log := <-logs - require.Equal(t, "example", log.Output) + for { + log, ok := <-logs + if !ok { + break + } + if log.Output == "example" { + return + } + } + require.Fail(t, "example message never happened") } diff --git a/codersdk/provisionerdaemons.go b/codersdk/provisionerdaemons.go index 6530dab33c9e4..a66f8d3ff2ac2 100644 --- a/codersdk/provisionerdaemons.go +++ b/codersdk/provisionerdaemons.go @@ -49,6 +49,7 @@ type ProvisionerJobLog struct { CreatedAt time.Time `json:"created_at"` Source database.LogSource `json:"log_source"` Level database.LogLevel `json:"log_level"` + Stage string `json:"stage"` Output string `json:"output"` } diff --git a/provisioner/terraform/provision.go b/provisioner/terraform/provision.go index b321d4e6f6131..62ea5ef9b2764 100644 --- a/provisioner/terraform/provision.go +++ b/provisioner/terraform/provision.go @@ -210,6 +210,15 @@ func (t *terraform) Provision(stream proto.DRPCProvisioner_ProvisionStream) erro err = cmd.Run() if err != nil { if start.DryRun { + if shutdown.Err() != nil { + return stream.Send(&proto.Provision_Response{ + Type: &proto.Provision_Response_Complete{ + Complete: &proto.Provision_Complete{ + Error: err.Error(), + }, + }, + }) + } return xerrors.Errorf("plan terraform: %w", err) } errorMessage := err.Error() diff --git a/provisionerd/proto/provisionerd.pb.go b/provisionerd/proto/provisionerd.pb.go index 220c7149d08f2..782bccb8c955f 100644 --- a/provisionerd/proto/provisionerd.pb.go +++ b/provisionerd/proto/provisionerd.pb.go @@ -422,7 +422,8 @@ type Log struct { Source LogSource `protobuf:"varint,1,opt,name=source,proto3,enum=provisionerd.LogSource" json:"source,omitempty"` Level proto.LogLevel `protobuf:"varint,2,opt,name=level,proto3,enum=provisioner.LogLevel" json:"level,omitempty"` CreatedAt int64 `protobuf:"varint,3,opt,name=created_at,json=createdAt,proto3" json:"created_at,omitempty"` - Output string `protobuf:"bytes,4,opt,name=output,proto3" json:"output,omitempty"` + Stage string `protobuf:"bytes,4,opt,name=stage,proto3" json:"stage,omitempty"` + Output string `protobuf:"bytes,5,opt,name=output,proto3" json:"output,omitempty"` } func (x *Log) Reset() { @@ -478,6 +479,13 @@ func (x *Log) GetCreatedAt() int64 { return 0 } +func (x *Log) GetStage() string { + if x != nil { + return x.Stage + } + return "" +} + func (x *Log) GetOutput() string { if x != nil { return x.Output @@ -1026,7 +1034,7 @@ var file_provisionerd_proto_provisionerd_proto_rawDesc = []byte{ 0x65, 0x73, 0x18, 0x02, 0x20, 0x03, 0x28, 0x0b, 0x32, 0x15, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x2e, 0x52, 0x65, 0x73, 0x6f, 0x75, 0x72, 0x63, 0x65, 0x52, 0x0d, 0x73, 0x74, 0x6f, 0x70, 0x52, 0x65, 0x73, 0x6f, 0x75, 0x72, 0x63, 0x65, 0x73, 0x42, 0x06, - 0x0a, 0x04, 0x74, 0x79, 0x70, 0x65, 0x22, 0x9a, 0x01, 0x0a, 0x03, 0x4c, 0x6f, 0x67, 0x12, 0x2f, + 0x0a, 0x04, 0x74, 0x79, 0x70, 0x65, 0x22, 0xb0, 0x01, 0x0a, 0x03, 0x4c, 0x6f, 0x67, 0x12, 0x2f, 0x0a, 0x06, 0x73, 0x6f, 0x75, 0x72, 0x63, 0x65, 0x18, 0x01, 0x20, 0x01, 0x28, 0x0e, 0x32, 0x17, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x4c, 0x6f, 0x67, 0x53, 0x6f, 0x75, 0x72, 0x63, 0x65, 0x52, 0x06, 0x73, 0x6f, 0x75, 0x72, 0x63, 0x65, 0x12, @@ -1034,50 +1042,52 @@ var file_provisionerd_proto_provisionerd_proto_rawDesc = []byte{ 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x2e, 0x4c, 0x6f, 0x67, 0x4c, 0x65, 0x76, 0x65, 0x6c, 0x52, 0x05, 0x6c, 0x65, 0x76, 0x65, 0x6c, 0x12, 0x1d, 0x0a, 0x0a, 0x63, 0x72, 0x65, 0x61, 0x74, 0x65, 0x64, 0x5f, 0x61, 0x74, 0x18, 0x03, 0x20, 0x01, 0x28, 0x03, - 0x52, 0x09, 0x63, 0x72, 0x65, 0x61, 0x74, 0x65, 0x64, 0x41, 0x74, 0x12, 0x16, 0x0a, 0x06, 0x6f, - 0x75, 0x74, 0x70, 0x75, 0x74, 0x18, 0x04, 0x20, 0x01, 0x28, 0x09, 0x52, 0x06, 0x6f, 0x75, 0x74, - 0x70, 0x75, 0x74, 0x22, 0x9b, 0x01, 0x0a, 0x10, 0x55, 0x70, 0x64, 0x61, 0x74, 0x65, 0x4a, 0x6f, - 0x62, 0x52, 0x65, 0x71, 0x75, 0x65, 0x73, 0x74, 0x12, 0x15, 0x0a, 0x06, 0x6a, 0x6f, 0x62, 0x5f, - 0x69, 0x64, 0x18, 0x01, 0x20, 0x01, 0x28, 0x09, 0x52, 0x05, 0x6a, 0x6f, 0x62, 0x49, 0x64, 0x12, - 0x25, 0x0a, 0x04, 0x6c, 0x6f, 0x67, 0x73, 0x18, 0x02, 0x20, 0x03, 0x28, 0x0b, 0x32, 0x11, 0x2e, - 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x4c, 0x6f, 0x67, - 0x52, 0x04, 0x6c, 0x6f, 0x67, 0x73, 0x12, 0x49, 0x0a, 0x11, 0x70, 0x61, 0x72, 0x61, 0x6d, 0x65, - 0x74, 0x65, 0x72, 0x5f, 0x73, 0x63, 0x68, 0x65, 0x6d, 0x61, 0x73, 0x18, 0x03, 0x20, 0x03, 0x28, - 0x0b, 0x32, 0x1c, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x2e, - 0x50, 0x61, 0x72, 0x61, 0x6d, 0x65, 0x74, 0x65, 0x72, 0x53, 0x63, 0x68, 0x65, 0x6d, 0x61, 0x52, - 0x10, 0x70, 0x61, 0x72, 0x61, 0x6d, 0x65, 0x74, 0x65, 0x72, 0x53, 0x63, 0x68, 0x65, 0x6d, 0x61, - 0x73, 0x22, 0x77, 0x0a, 0x11, 0x55, 0x70, 0x64, 0x61, 0x74, 0x65, 0x4a, 0x6f, 0x62, 0x52, 0x65, - 0x73, 0x70, 0x6f, 0x6e, 0x73, 0x65, 0x12, 0x1a, 0x0a, 0x08, 0x63, 0x61, 0x6e, 0x63, 0x65, 0x6c, - 0x65, 0x64, 0x18, 0x01, 0x20, 0x01, 0x28, 0x08, 0x52, 0x08, 0x63, 0x61, 0x6e, 0x63, 0x65, 0x6c, - 0x65, 0x64, 0x12, 0x46, 0x0a, 0x10, 0x70, 0x61, 0x72, 0x61, 0x6d, 0x65, 0x74, 0x65, 0x72, 0x5f, - 0x76, 0x61, 0x6c, 0x75, 0x65, 0x73, 0x18, 0x02, 0x20, 0x03, 0x28, 0x0b, 0x32, 0x1b, 0x2e, 0x70, - 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x2e, 0x50, 0x61, 0x72, 0x61, 0x6d, - 0x65, 0x74, 0x65, 0x72, 0x56, 0x61, 0x6c, 0x75, 0x65, 0x52, 0x0f, 0x70, 0x61, 0x72, 0x61, 0x6d, - 0x65, 0x74, 0x65, 0x72, 0x56, 0x61, 0x6c, 0x75, 0x65, 0x73, 0x2a, 0x34, 0x0a, 0x09, 0x4c, 0x6f, - 0x67, 0x53, 0x6f, 0x75, 0x72, 0x63, 0x65, 0x12, 0x16, 0x0a, 0x12, 0x50, 0x52, 0x4f, 0x56, 0x49, - 0x53, 0x49, 0x4f, 0x4e, 0x45, 0x52, 0x5f, 0x44, 0x41, 0x45, 0x4d, 0x4f, 0x4e, 0x10, 0x00, 0x12, - 0x0f, 0x0a, 0x0b, 0x50, 0x52, 0x4f, 0x56, 0x49, 0x53, 0x49, 0x4f, 0x4e, 0x45, 0x52, 0x10, 0x01, - 0x32, 0x98, 0x02, 0x0a, 0x11, 0x50, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, - 0x44, 0x61, 0x65, 0x6d, 0x6f, 0x6e, 0x12, 0x3c, 0x0a, 0x0a, 0x41, 0x63, 0x71, 0x75, 0x69, 0x72, - 0x65, 0x4a, 0x6f, 0x62, 0x12, 0x13, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, - 0x65, 0x72, 0x64, 0x2e, 0x45, 0x6d, 0x70, 0x74, 0x79, 0x1a, 0x19, 0x2e, 0x70, 0x72, 0x6f, 0x76, - 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x41, 0x63, 0x71, 0x75, 0x69, 0x72, 0x65, - 0x64, 0x4a, 0x6f, 0x62, 0x12, 0x4c, 0x0a, 0x09, 0x55, 0x70, 0x64, 0x61, 0x74, 0x65, 0x4a, 0x6f, - 0x62, 0x12, 0x1e, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, - 0x2e, 0x55, 0x70, 0x64, 0x61, 0x74, 0x65, 0x4a, 0x6f, 0x62, 0x52, 0x65, 0x71, 0x75, 0x65, 0x73, - 0x74, 0x1a, 0x1f, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, - 0x2e, 0x55, 0x70, 0x64, 0x61, 0x74, 0x65, 0x4a, 0x6f, 0x62, 0x52, 0x65, 0x73, 0x70, 0x6f, 0x6e, - 0x73, 0x65, 0x12, 0x37, 0x0a, 0x07, 0x46, 0x61, 0x69, 0x6c, 0x4a, 0x6f, 0x62, 0x12, 0x17, 0x2e, - 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x46, 0x61, 0x69, - 0x6c, 0x65, 0x64, 0x4a, 0x6f, 0x62, 0x1a, 0x13, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, - 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x45, 0x6d, 0x70, 0x74, 0x79, 0x12, 0x3e, 0x0a, 0x0b, 0x43, - 0x6f, 0x6d, 0x70, 0x6c, 0x65, 0x74, 0x65, 0x4a, 0x6f, 0x62, 0x12, 0x1a, 0x2e, 0x70, 0x72, 0x6f, - 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x43, 0x6f, 0x6d, 0x70, 0x6c, 0x65, - 0x74, 0x65, 0x64, 0x4a, 0x6f, 0x62, 0x1a, 0x13, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, - 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x45, 0x6d, 0x70, 0x74, 0x79, 0x42, 0x2b, 0x5a, 0x29, 0x67, - 0x69, 0x74, 0x68, 0x75, 0x62, 0x2e, 0x63, 0x6f, 0x6d, 0x2f, 0x63, 0x6f, 0x64, 0x65, 0x72, 0x2f, - 0x63, 0x6f, 0x64, 0x65, 0x72, 0x2f, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, - 0x72, 0x64, 0x2f, 0x70, 0x72, 0x6f, 0x74, 0x6f, 0x62, 0x06, 0x70, 0x72, 0x6f, 0x74, 0x6f, 0x33, + 0x52, 0x09, 0x63, 0x72, 0x65, 0x61, 0x74, 0x65, 0x64, 0x41, 0x74, 0x12, 0x14, 0x0a, 0x05, 0x73, + 0x74, 0x61, 0x67, 0x65, 0x18, 0x04, 0x20, 0x01, 0x28, 0x09, 0x52, 0x05, 0x73, 0x74, 0x61, 0x67, + 0x65, 0x12, 0x16, 0x0a, 0x06, 0x6f, 0x75, 0x74, 0x70, 0x75, 0x74, 0x18, 0x05, 0x20, 0x01, 0x28, + 0x09, 0x52, 0x06, 0x6f, 0x75, 0x74, 0x70, 0x75, 0x74, 0x22, 0x9b, 0x01, 0x0a, 0x10, 0x55, 0x70, + 0x64, 0x61, 0x74, 0x65, 0x4a, 0x6f, 0x62, 0x52, 0x65, 0x71, 0x75, 0x65, 0x73, 0x74, 0x12, 0x15, + 0x0a, 0x06, 0x6a, 0x6f, 0x62, 0x5f, 0x69, 0x64, 0x18, 0x01, 0x20, 0x01, 0x28, 0x09, 0x52, 0x05, + 0x6a, 0x6f, 0x62, 0x49, 0x64, 0x12, 0x25, 0x0a, 0x04, 0x6c, 0x6f, 0x67, 0x73, 0x18, 0x02, 0x20, + 0x03, 0x28, 0x0b, 0x32, 0x11, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, + 0x72, 0x64, 0x2e, 0x4c, 0x6f, 0x67, 0x52, 0x04, 0x6c, 0x6f, 0x67, 0x73, 0x12, 0x49, 0x0a, 0x11, + 0x70, 0x61, 0x72, 0x61, 0x6d, 0x65, 0x74, 0x65, 0x72, 0x5f, 0x73, 0x63, 0x68, 0x65, 0x6d, 0x61, + 0x73, 0x18, 0x03, 0x20, 0x03, 0x28, 0x0b, 0x32, 0x1c, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, + 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x2e, 0x50, 0x61, 0x72, 0x61, 0x6d, 0x65, 0x74, 0x65, 0x72, 0x53, + 0x63, 0x68, 0x65, 0x6d, 0x61, 0x52, 0x10, 0x70, 0x61, 0x72, 0x61, 0x6d, 0x65, 0x74, 0x65, 0x72, + 0x53, 0x63, 0x68, 0x65, 0x6d, 0x61, 0x73, 0x22, 0x77, 0x0a, 0x11, 0x55, 0x70, 0x64, 0x61, 0x74, + 0x65, 0x4a, 0x6f, 0x62, 0x52, 0x65, 0x73, 0x70, 0x6f, 0x6e, 0x73, 0x65, 0x12, 0x1a, 0x0a, 0x08, + 0x63, 0x61, 0x6e, 0x63, 0x65, 0x6c, 0x65, 0x64, 0x18, 0x01, 0x20, 0x01, 0x28, 0x08, 0x52, 0x08, + 0x63, 0x61, 0x6e, 0x63, 0x65, 0x6c, 0x65, 0x64, 0x12, 0x46, 0x0a, 0x10, 0x70, 0x61, 0x72, 0x61, + 0x6d, 0x65, 0x74, 0x65, 0x72, 0x5f, 0x76, 0x61, 0x6c, 0x75, 0x65, 0x73, 0x18, 0x02, 0x20, 0x03, + 0x28, 0x0b, 0x32, 0x1b, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, + 0x2e, 0x50, 0x61, 0x72, 0x61, 0x6d, 0x65, 0x74, 0x65, 0x72, 0x56, 0x61, 0x6c, 0x75, 0x65, 0x52, + 0x0f, 0x70, 0x61, 0x72, 0x61, 0x6d, 0x65, 0x74, 0x65, 0x72, 0x56, 0x61, 0x6c, 0x75, 0x65, 0x73, + 0x2a, 0x34, 0x0a, 0x09, 0x4c, 0x6f, 0x67, 0x53, 0x6f, 0x75, 0x72, 0x63, 0x65, 0x12, 0x16, 0x0a, + 0x12, 0x50, 0x52, 0x4f, 0x56, 0x49, 0x53, 0x49, 0x4f, 0x4e, 0x45, 0x52, 0x5f, 0x44, 0x41, 0x45, + 0x4d, 0x4f, 0x4e, 0x10, 0x00, 0x12, 0x0f, 0x0a, 0x0b, 0x50, 0x52, 0x4f, 0x56, 0x49, 0x53, 0x49, + 0x4f, 0x4e, 0x45, 0x52, 0x10, 0x01, 0x32, 0x98, 0x02, 0x0a, 0x11, 0x50, 0x72, 0x6f, 0x76, 0x69, + 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x44, 0x61, 0x65, 0x6d, 0x6f, 0x6e, 0x12, 0x3c, 0x0a, 0x0a, + 0x41, 0x63, 0x71, 0x75, 0x69, 0x72, 0x65, 0x4a, 0x6f, 0x62, 0x12, 0x13, 0x2e, 0x70, 0x72, 0x6f, + 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x45, 0x6d, 0x70, 0x74, 0x79, 0x1a, + 0x19, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x41, + 0x63, 0x71, 0x75, 0x69, 0x72, 0x65, 0x64, 0x4a, 0x6f, 0x62, 0x12, 0x4c, 0x0a, 0x09, 0x55, 0x70, + 0x64, 0x61, 0x74, 0x65, 0x4a, 0x6f, 0x62, 0x12, 0x1e, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, + 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x55, 0x70, 0x64, 0x61, 0x74, 0x65, 0x4a, 0x6f, 0x62, + 0x52, 0x65, 0x71, 0x75, 0x65, 0x73, 0x74, 0x1a, 0x1f, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, + 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x55, 0x70, 0x64, 0x61, 0x74, 0x65, 0x4a, 0x6f, 0x62, + 0x52, 0x65, 0x73, 0x70, 0x6f, 0x6e, 0x73, 0x65, 0x12, 0x37, 0x0a, 0x07, 0x46, 0x61, 0x69, 0x6c, + 0x4a, 0x6f, 0x62, 0x12, 0x17, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, + 0x72, 0x64, 0x2e, 0x46, 0x61, 0x69, 0x6c, 0x65, 0x64, 0x4a, 0x6f, 0x62, 0x1a, 0x13, 0x2e, 0x70, + 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x45, 0x6d, 0x70, 0x74, + 0x79, 0x12, 0x3e, 0x0a, 0x0b, 0x43, 0x6f, 0x6d, 0x70, 0x6c, 0x65, 0x74, 0x65, 0x4a, 0x6f, 0x62, + 0x12, 0x1a, 0x2e, 0x70, 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, + 0x43, 0x6f, 0x6d, 0x70, 0x6c, 0x65, 0x74, 0x65, 0x64, 0x4a, 0x6f, 0x62, 0x1a, 0x13, 0x2e, 0x70, + 0x72, 0x6f, 0x76, 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2e, 0x45, 0x6d, 0x70, 0x74, + 0x79, 0x42, 0x2b, 0x5a, 0x29, 0x67, 0x69, 0x74, 0x68, 0x75, 0x62, 0x2e, 0x63, 0x6f, 0x6d, 0x2f, + 0x63, 0x6f, 0x64, 0x65, 0x72, 0x2f, 0x63, 0x6f, 0x64, 0x65, 0x72, 0x2f, 0x70, 0x72, 0x6f, 0x76, + 0x69, 0x73, 0x69, 0x6f, 0x6e, 0x65, 0x72, 0x64, 0x2f, 0x70, 0x72, 0x6f, 0x74, 0x6f, 0x62, 0x06, + 0x70, 0x72, 0x6f, 0x74, 0x6f, 0x33, } var ( diff --git a/provisionerd/proto/provisionerd.proto b/provisionerd/proto/provisionerd.proto index e7c76d228bdad..88bf3fa695356 100644 --- a/provisionerd/proto/provisionerd.proto +++ b/provisionerd/proto/provisionerd.proto @@ -74,7 +74,8 @@ message Log { LogSource source = 1; provisioner.LogLevel level = 2; int64 created_at = 3; - string output = 4; + string stage = 4; + string output = 5; } // This message should be sent periodically as a heartbeat. @@ -107,4 +108,4 @@ service ProvisionerDaemon { // CompleteJob indicates a job has been completed. rpc CompleteJob(CompletedJob) returns (Empty); -} \ No newline at end of file +} diff --git a/provisionerd/provisionerd.go b/provisionerd/provisionerd.go index 3899ac59212c1..ffdcbf1e7df69 100644 --- a/provisionerd/provisionerd.go +++ b/provisionerd/provisionerd.go @@ -298,6 +298,20 @@ func (p *Server) runJob(ctx context.Context, job *proto.AcquiredJob) { return } + _, err = p.client.UpdateJob(ctx, &proto.UpdateJobRequest{ + JobId: job.GetJobId(), + Logs: []*proto.Log{{ + Source: proto.LogSource_PROVISIONER_DAEMON, + Level: sdkproto.LogLevel_INFO, + Stage: "Setting up", + CreatedAt: time.Now().UTC().UnixMilli(), + }}, + }) + if err != nil { + p.failActiveJobf("write log: %s", err) + return + } + p.opts.Logger.Info(ctx, "unpacking project source archive", slog.F("size_bytes", len(job.ProjectSourceArchive))) reader := tar.NewReader(bytes.NewBuffer(job.ProjectSourceArchive)) for { @@ -377,11 +391,39 @@ func (p *Server) runJob(ctx context.Context, job *proto.AcquiredJob) { // Ensure the job is still running to output. // It's possible the job has failed. if p.isRunningJob() { + _, err = p.client.UpdateJob(ctx, &proto.UpdateJobRequest{ + JobId: job.GetJobId(), + Logs: []*proto.Log{{ + Source: proto.LogSource_PROVISIONER_DAEMON, + Level: sdkproto.LogLevel_INFO, + Stage: "Cleaning Up", + CreatedAt: time.Now().UTC().UnixMilli(), + }}, + }) + if err != nil { + p.failActiveJobf("write log: %s", err) + return + } + p.opts.Logger.Info(context.Background(), "completed job", slog.F("id", job.JobId)) } } func (p *Server) runProjectImport(ctx, shutdown context.Context, provisioner sdkproto.DRPCProvisionerClient, job *proto.AcquiredJob) { + _, err := p.client.UpdateJob(ctx, &proto.UpdateJobRequest{ + JobId: job.GetJobId(), + Logs: []*proto.Log{{ + Source: proto.LogSource_PROVISIONER_DAEMON, + Level: sdkproto.LogLevel_INFO, + Stage: "Parse parameters", + CreatedAt: time.Now().UTC().UnixMilli(), + }}, + }) + if err != nil { + p.failActiveJobf("write log: %s", err) + return + } + parameterSchemas, err := p.runProjectImportParse(ctx, provisioner, job) if err != nil { p.failActiveJobf("run parse: %s", err) @@ -409,6 +451,19 @@ func (p *Server) runProjectImport(ctx, shutdown context.Context, provisioner sdk } } + _, err = p.client.UpdateJob(ctx, &proto.UpdateJobRequest{ + JobId: job.GetJobId(), + Logs: []*proto.Log{{ + Source: proto.LogSource_PROVISIONER_DAEMON, + Level: sdkproto.LogLevel_INFO, + Stage: "Detecting resources when started", + CreatedAt: time.Now().UTC().UnixMilli(), + }}, + }) + if err != nil { + p.failActiveJobf("write log: %s", err) + return + } startResources, err := p.runProjectImportProvision(ctx, shutdown, provisioner, job, updateResponse.ParameterValues, &sdkproto.Provision_Metadata{ CoderUrl: job.GetProjectImport().Metadata.CoderUrl, WorkspaceTransition: sdkproto.WorkspaceTransition_START, @@ -422,8 +477,8 @@ func (p *Server) runProjectImport(ctx, shutdown context.Context, provisioner sdk Logs: []*proto.Log{{ Source: proto.LogSource_PROVISIONER_DAEMON, Level: sdkproto.LogLevel_INFO, + Stage: "Detecting resources when stopped", CreatedAt: time.Now().UTC().UnixMilli(), - Output: "Running stop...", }}, }) if err != nil { @@ -574,6 +629,30 @@ func (p *Server) runProjectImportProvision(ctx, shutdown context.Context, provis } func (p *Server) runWorkspaceBuild(ctx, shutdown context.Context, provisioner sdkproto.DRPCProvisionerClient, job *proto.AcquiredJob) { + var stage string + switch job.GetWorkspaceBuild().Metadata.WorkspaceTransition { + case sdkproto.WorkspaceTransition_START: + stage = "Starting workspace" + case sdkproto.WorkspaceTransition_STOP: + stage = "Stopping workspace" + case sdkproto.WorkspaceTransition_DESTROY: + stage = "Destroying workspace" + } + + _, err := p.client.UpdateJob(ctx, &proto.UpdateJobRequest{ + JobId: job.GetJobId(), + Logs: []*proto.Log{{ + Source: proto.LogSource_PROVISIONER_DAEMON, + Level: sdkproto.LogLevel_INFO, + Stage: stage, + CreatedAt: time.Now().UTC().UnixMilli(), + }}, + }) + if err != nil { + p.failActiveJobf("write log: %s", err) + return + } + stream, err := provisioner.Provision(ctx) if err != nil { p.failActiveJobf("provision: %s", err) @@ -675,8 +754,7 @@ func (p *Server) runWorkspaceBuild(ctx, shutdown context.Context, provisioner sd // Return so we stop looping! return default: - p.failActiveJobf("invalid message type %q received from provisioner", - reflect.TypeOf(msg.Type).String()) + p.failActiveJobf("invalid message type %T received from provisioner", msg.Type) return } } diff --git a/provisionerd/provisionerd_test.go b/provisionerd/provisionerd_test.go index 4ce915349a1ce..a15d7e2dd277b 100644 --- a/provisionerd/provisionerd_test.go +++ b/provisionerd/provisionerd_test.go @@ -438,7 +438,7 @@ func TestProvisionerd(t *testing.T) { }, nil }, updateJob: func(ctx context.Context, update *proto.UpdateJobRequest) (*proto.UpdateJobResponse, error) { - if len(update.Logs) > 0 { + if len(update.Logs) > 0 && update.Logs[0].Source == proto.LogSource_PROVISIONER { // Close on a log so we know when the job is in progress! close(updateChan) } @@ -507,7 +507,7 @@ func TestProvisionerd(t *testing.T) { }, nil }, updateJob: func(ctx context.Context, update *proto.UpdateJobRequest) (*proto.UpdateJobResponse, error) { - if len(update.Logs) > 0 { + if len(update.Logs) > 0 && update.Logs[0].Source == proto.LogSource_PROVISIONER { // Close on a log so we know when the job is in progress! close(updateChan) }