feat: Add stage to build logs (#577)

* feat: Add stage to build logs

This adds a stage property to logs, and refactors the job logs
cliui.

It also adds tests to the cliui for build logs!

* Fix comments
This commit is contained in:
Kyle Carberry 2022-03-28 12:43:22 -06:00 committed by GitHub
parent eb18925f11
commit b33dec9d38
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
29 changed files with 604 additions and 262 deletions

View File

@ -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,

View File

@ -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()
}
}
}

191
cli/cliui/provisionerjob.go Normal file
View File

@ -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()
}
}
}

View File

@ -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,
}
}

View File

@ -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 {

View File

@ -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

View File

@ -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() {

View File

@ -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

View File

@ -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

View File

@ -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

View File

@ -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

View File

@ -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
}
}
}()

View File

@ -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

View File

@ -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
);

View File

@ -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
);

View File

@ -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"`
}

View File

@ -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;

View File

@ -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

View File

@ -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
}
}
}

View File

@ -303,6 +303,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)
}

View File

@ -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,
}
}

View File

@ -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)
})
}

View File

@ -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")
}

View File

@ -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"`
}

View File

@ -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()

View File

@ -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 (

View File

@ -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);
}
}

View File

@ -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
}
}

View File

@ -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)
}