Skip to content

Commit 3028185

Browse files
kylecarbskylecarbs
authored
feat: Add buffering to provisioner job logs (#4918)
* feat: Add bufferring to provisioner job logs This should improve overall build performance, and especially under load. It removes the old `id` column on the `provisioner_job_logs` table and replaces it with an auto-incrementing big integer to preserve order. Funny enough, we never had to care about order before because inserts would at minimum be 1ms different. Now they aren't, so the order needs to be preserved. * Fix log bufferring * Fix frontend log streaming * Fix JS test
1 parent 531f7cd commit 3028185

34 files changed

+300
-476
lines changed

‎cli/cliui/provisionerjob.go

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -16,14 +16,14 @@ import (
1616
"github.com/coder/coder/codersdk"
1717
)
1818

19-
func WorkspaceBuild(ctx context.Context, writer io.Writer, client *codersdk.Client, build uuid.UUID, before time.Time) error {
19+
func WorkspaceBuild(ctx context.Context, writer io.Writer, client *codersdk.Client, build uuid.UUID) error {
2020
return ProvisionerJob(ctx, writer, ProvisionerJobOptions{
2121
Fetch: func() (codersdk.ProvisionerJob, error) {
2222
build, err := client.WorkspaceBuild(ctx, build)
2323
return build.Job, err
2424
},
2525
Logs: func() (<-chan codersdk.ProvisionerJobLog, io.Closer, error) {
26-
return client.WorkspaceBuildLogsAfter(ctx, build, before)
26+
return client.WorkspaceBuildLogsAfter(ctx, build, 0)
2727
},
2828
})
2929
}

‎cli/create.go

Lines changed: 2 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -139,7 +139,6 @@ func create() *cobra.Command {
139139
return err
140140
}
141141

142-
after := time.Now()
143142
workspace, err := client.CreateWorkspace(cmd.Context(), organization.ID, codersdk.Me, codersdk.CreateWorkspaceRequest{
144143
TemplateID: template.ID,
145144
Name: workspaceName,
@@ -151,7 +150,7 @@ func create() *cobra.Command {
151150
return err
152151
}
153152

154-
err = cliui.WorkspaceBuild(cmd.Context(), cmd.OutOrStdout(), client, workspace.LatestBuild.ID, after)
153+
err = cliui.WorkspaceBuild(cmd.Context(), cmd.OutOrStdout(), client, workspace.LatestBuild.ID)
155154
if err != nil {
156155
return err
157156
}
@@ -238,7 +237,6 @@ PromptParamLoop:
238237
_, _ = fmt.Fprintln(cmd.OutOrStdout())
239238

240239
// Run a dry-run with the given parameters to check correctness
241-
after := time.Now()
242240
dryRun, err := client.CreateTemplateVersionDryRun(cmd.Context(), templateVersion.ID, codersdk.CreateTemplateVersionDryRunRequest{
243241
WorkspaceName: args.NewWorkspaceName,
244242
ParameterValues: parameters,
@@ -255,7 +253,7 @@ PromptParamLoop:
255253
return client.CancelTemplateVersionDryRun(cmd.Context(), templateVersion.ID, dryRun.ID)
256254
},
257255
Logs: func() (<-chan codersdk.ProvisionerJobLog, io.Closer, error) {
258-
return client.TemplateVersionDryRunLogsAfter(cmd.Context(), templateVersion.ID, dryRun.ID, after)
256+
return client.TemplateVersionDryRunLogsAfter(cmd.Context(), templateVersion.ID, dryRun.ID, 0)
259257
},
260258
// Don't show log output for the dry-run unless there's an error.
261259
Silent: true,

‎cli/delete.go

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -47,7 +47,6 @@ func deleteWorkspace() *cobra.Command {
4747
)
4848
}
4949

50-
before := time.Now()
5150
build, err := client.CreateWorkspaceBuild(cmd.Context(), workspace.ID, codersdk.CreateWorkspaceBuildRequest{
5251
Transition: codersdk.WorkspaceTransitionDelete,
5352
ProvisionerState: state,
@@ -57,7 +56,7 @@ func deleteWorkspace() *cobra.Command {
5756
return err
5857
}
5958

60-
err = cliui.WorkspaceBuild(cmd.Context(), cmd.OutOrStdout(), client, build.ID, before)
59+
err = cliui.WorkspaceBuild(cmd.Context(), cmd.OutOrStdout(), client, build.ID)
6160
if err != nil {
6261
return err
6362
}

‎cli/portforward.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -79,7 +79,7 @@ func portForward() *cobra.Command {
7979
return xerrors.New("workspace must be in start transition to port-forward")
8080
}
8181
if workspace.LatestBuild.Job.CompletedAt == nil {
82-
err = cliui.WorkspaceBuild(ctx, cmd.ErrOrStderr(), client, workspace.LatestBuild.ID, workspace.CreatedAt)
82+
err = cliui.WorkspaceBuild(ctx, cmd.ErrOrStderr(), client, workspace.LatestBuild.ID)
8383
if err != nil {
8484
return err
8585
}

‎cli/ssh.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -250,7 +250,7 @@ func getWorkspaceAndAgent(ctx context.Context, cmd *cobra.Command, client *coder
250250
return codersdk.Workspace{}, codersdk.WorkspaceAgent{}, xerrors.New("workspace must be in start transition to ssh")
251251
}
252252
if workspace.LatestBuild.Job.CompletedAt == nil {
253-
err := cliui.WorkspaceBuild(ctx, cmd.ErrOrStderr(), client, workspace.LatestBuild.ID, workspace.CreatedAt)
253+
err := cliui.WorkspaceBuild(ctx, cmd.ErrOrStderr(), client, workspace.LatestBuild.ID)
254254
if err != nil {
255255
return codersdk.Workspace{}, codersdk.WorkspaceAgent{}, err
256256
}

‎cli/start.go

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -25,15 +25,14 @@ func start() *cobra.Command {
2525
if err != nil {
2626
return err
2727
}
28-
before := time.Now()
2928
build, err := client.CreateWorkspaceBuild(cmd.Context(), workspace.ID, codersdk.CreateWorkspaceBuildRequest{
3029
Transition: codersdk.WorkspaceTransitionStart,
3130
})
3231
if err != nil {
3332
return err
3433
}
3534

36-
err = cliui.WorkspaceBuild(cmd.Context(), cmd.OutOrStdout(), client, build.ID, before)
35+
err = cliui.WorkspaceBuild(cmd.Context(), cmd.OutOrStdout(), client, build.ID)
3736
if err != nil {
3837
return err
3938
}

‎cli/state.go

Lines changed: 1 addition & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,6 @@ import (
55
"io"
66
"os"
77
"strconv"
8-
"time"
98

109
"github.com/spf13/cobra"
1110

@@ -100,7 +99,6 @@ func statePush() *cobra.Command {
10099
return err
101100
}
102101

103-
before := time.Now()
104102
build, err = client.CreateWorkspaceBuild(cmd.Context(), workspace.ID, codersdk.CreateWorkspaceBuildRequest{
105103
TemplateVersionID: build.TemplateVersionID,
106104
Transition: build.Transition,
@@ -109,7 +107,7 @@ func statePush() *cobra.Command {
109107
if err != nil {
110108
return err
111109
}
112-
return cliui.WorkspaceBuild(cmd.Context(), cmd.OutOrStderr(), client, build.ID, before)
110+
return cliui.WorkspaceBuild(cmd.Context(), cmd.OutOrStderr(), client, build.ID)
113111
},
114112
}
115113
cmd.Flags().IntVarP(&buildNumber, "build", "b", 0, "Specify a workspace build to target by name.")

‎cli/stop.go

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -33,15 +33,14 @@ func stop() *cobra.Command {
3333
if err != nil {
3434
return err
3535
}
36-
before := time.Now()
3736
build, err := client.CreateWorkspaceBuild(cmd.Context(), workspace.ID, codersdk.CreateWorkspaceBuildRequest{
3837
Transition: codersdk.WorkspaceTransitionStop,
3938
})
4039
if err != nil {
4140
return err
4241
}
4342

44-
err = cliui.WorkspaceBuild(cmd.Context(), cmd.OutOrStdout(), client, build.ID, before)
43+
err = cliui.WorkspaceBuild(cmd.Context(), cmd.OutOrStdout(), client, build.ID)
4544
if err != nil {
4645
return err
4746
}

‎cli/templatecreate.go

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -160,7 +160,6 @@ type createValidTemplateVersionArgs struct {
160160
}
161161

162162
func createValidTemplateVersion(cmd *cobra.Command, args createValidTemplateVersionArgs, parameters ...codersdk.CreateParameterRequest) (*codersdk.TemplateVersion, []codersdk.CreateParameterRequest, error) {
163-
before := time.Now()
164163
client := args.Client
165164

166165
req := codersdk.CreateTemplateVersionRequest{
@@ -187,7 +186,7 @@ func createValidTemplateVersion(cmd *cobra.Command, args createValidTemplateVers
187186
return client.CancelTemplateVersion(cmd.Context(), version.ID)
188187
},
189188
Logs: func() (<-chan codersdk.ProvisionerJobLog, io.Closer, error) {
190-
return client.TemplateVersionLogsAfter(cmd.Context(), version.ID, before)
189+
return client.TemplateVersionLogsAfter(cmd.Context(), version.ID, 0)
191190
},
192191
})
193192
if err != nil {

‎cli/update.go

Lines changed: 1 addition & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,6 @@ package cli
22

33
import (
44
"fmt"
5-
"time"
65

76
"github.com/spf13/cobra"
87

@@ -57,7 +56,6 @@ func update() *cobra.Command {
5756
return nil
5857
}
5958

60-
before := time.Now()
6159
build, err := client.CreateWorkspaceBuild(cmd.Context(), workspace.ID, codersdk.CreateWorkspaceBuildRequest{
6260
TemplateVersionID: template.ActiveVersionID,
6361
Transition: workspace.LatestBuild.Transition,
@@ -66,7 +64,7 @@ func update() *cobra.Command {
6664
if err != nil {
6765
return err
6866
}
69-
logs, closer, err := client.WorkspaceBuildLogsAfter(cmd.Context(), build.ID, before)
67+
logs, closer, err := client.WorkspaceBuildLogsAfter(cmd.Context(), build.ID, 0)
7068
if err != nil {
7169
return err
7270
}

‎coderd/database/databasefake/databasefake.go

Lines changed: 8 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -2052,17 +2052,14 @@ func (q *fakeQuerier) GetProvisionerLogsByIDBetween(_ context.Context, arg datab
20522052
if jobLog.JobID != arg.JobID {
20532053
continue
20542054
}
2055-
if !arg.CreatedBefore.IsZero() && jobLog.CreatedAt.After(arg.CreatedBefore) {
2055+
if arg.CreatedBefore != 0 && jobLog.ID > arg.CreatedBefore {
20562056
continue
20572057
}
2058-
if !arg.CreatedAfter.IsZero() && jobLog.CreatedAt.Before(arg.CreatedAfter) {
2058+
if arg.CreatedAfter != 0 && jobLog.ID < arg.CreatedAfter {
20592059
continue
20602060
}
20612061
logs = append(logs, jobLog)
20622062
}
2063-
if len(logs) == 0 {
2064-
return nil, sql.ErrNoRows
2065-
}
20662063
return logs, nil
20672064
}
20682065

@@ -2212,10 +2209,15 @@ func (q *fakeQuerier) InsertProvisionerJobLogs(_ context.Context, arg database.I
22122209
defer q.mutex.Unlock()
22132210

22142211
logs := make([]database.ProvisionerJobLog, 0)
2212+
id := int64(1)
2213+
if len(q.provisionerJobLogs) > 0 {
2214+
id = q.provisionerJobLogs[len(q.provisionerJobLogs)-1].ID
2215+
}
22152216
for index, output := range arg.Output {
2217+
id++
22162218
logs = append(logs, database.ProvisionerJobLog{
2219+
ID: id,
22172220
JobID: arg.JobID,
2218-
ID: arg.ID[index],
22192221
CreatedAt: arg.CreatedAt[index],
22202222
Source: arg.Source[index],
22212223
Level: arg.Level[index],

‎coderd/database/dump.sql

Lines changed: 13 additions & 2 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎coderd/database/migrations/000071_provisioner_log_lines.down.sql

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,3 @@
1+
ALTER TABLE provisioner_job_logs DROP COLUMN id;
2+
3+
ALTER TABLE provisioner_job_logs ADD COLUMN id uuid NOT NULL DEFAULT gen_random_uuid();

‎coderd/database/migrations/000071_provisioner_log_lines.up.sql

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,3 @@
1+
ALTER TABLE provisioner_job_logs DROP COLUMN id;
2+
3+
ALTER TABLE provisioner_job_logs ADD COLUMN id BIGSERIAL PRIMARY KEY;

‎coderd/database/models.go

Lines changed: 1 addition & 1 deletion
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎coderd/database/queries.sql.go

Lines changed: 14 additions & 19 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎coderd/database/queries/provisionerjoblogs.sql

Lines changed: 3 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -6,17 +6,14 @@ FROM
66
WHERE
77
job_id = @job_id
88
AND (
9-
created_at >= @created_after
10-
OR created_at <= @created_before
11-
)
12-
ORDER BY
13-
created_at DESC;
9+
id > @created_after
10+
OR id < @created_before
11+
) ORDER BY id;
1412

1513
-- name: InsertProvisionerJobLogs :many
1614
INSERT INTO
1715
provisioner_job_logs
1816
SELECT
19-
unnest(@id :: uuid [ ]) AS id,
2017
@job_id :: uuid AS job_id,
2118
unnest(@created_at :: timestamptz [ ]) AS created_at,
2219
unnest(@source :: log_source [ ]) AS source,

0 commit comments

Comments
 (0)