Skip to content

Commit d4b4418

Browse files
spikecurtisspikecurtis
authored
chore: add database dump and dbfake logging (#19144)
relates to #778 Somehow in `TestWorkspaceAgent` the agent with the test instance identifier is not being added to the database, or is getting deleted. I'm adding some additional logging to `dbfake` and setting the affected tests to dump postgres on error, to see if we can get to the bottom of the issue.
1 parent e80f91e commit d4b4418

File tree

4 files changed

+86
-10
lines changed

4 files changed

+86
-10
lines changed

‎.github/workflows/ci.yaml

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -490,6 +490,12 @@ jobs:
490490
gotestsum --format standard-quiet --packages "$PACKAGES" \
491491
-- -timeout=20m -v -p $NUM_PARALLEL_PACKAGES -parallel=$NUM_PARALLEL_TESTS $TESTCOUNT
492492
493+
- name: Upload failed test db dumps
494+
uses: actions/upload-artifact@ea165f8d65b6e75b540449e92b4886f43607fa02 # v4.6.2
495+
with:
496+
name: failed-test-db-dump-${{matrix.os}}
497+
path: "**/*.test.sql"
498+
493499
- name: Upload Go Build Cache
494500
uses: ./.github/actions/test-cache/upload
495501
with:

‎cli/agent_test.go

Lines changed: 19 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ import (
2121
"github.com/coder/coder/v2/coderd/coderdtest"
2222
"github.com/coder/coder/v2/coderd/database"
2323
"github.com/coder/coder/v2/coderd/database/dbfake"
24+
"github.com/coder/coder/v2/coderd/database/dbtestutil"
2425
"github.com/coder/coder/v2/codersdk"
2526
"github.com/coder/coder/v2/codersdk/workspacesdk"
2627
"github.com/coder/coder/v2/provisionersdk/proto"
@@ -67,7 +68,12 @@ func TestWorkspaceAgent(t *testing.T) {
6768
t.Parallel()
6869
instanceID := "instanceidentifier"
6970
certificates, metadataClient := coderdtest.NewAzureInstanceIdentity(t, instanceID)
70-
client, db := coderdtest.NewWithDatabase(t, &coderdtest.Options{
71+
db, ps := dbtestutil.NewDB(t,
72+
dbtestutil.WithDumpOnFailure(),
73+
)
74+
client := coderdtest.New(t, &coderdtest.Options{
75+
Database: db,
76+
Pubsub: ps,
7177
AzureCertificates: certificates,
7278
})
7379
user := coderdtest.CreateFirstUser(t, client)
@@ -106,7 +112,12 @@ func TestWorkspaceAgent(t *testing.T) {
106112
t.Parallel()
107113
instanceID := "instanceidentifier"
108114
certificates, metadataClient := coderdtest.NewAWSInstanceIdentity(t, instanceID)
109-
client, db := coderdtest.NewWithDatabase(t, &coderdtest.Options{
115+
db, ps := dbtestutil.NewDB(t,
116+
dbtestutil.WithDumpOnFailure(),
117+
)
118+
client := coderdtest.New(t, &coderdtest.Options{
119+
Database: db,
120+
Pubsub: ps,
110121
AWSCertificates: certificates,
111122
})
112123
user := coderdtest.CreateFirstUser(t, client)
@@ -146,7 +157,12 @@ func TestWorkspaceAgent(t *testing.T) {
146157
t.Parallel()
147158
instanceID := "instanceidentifier"
148159
validator, metadataClient := coderdtest.NewGoogleInstanceIdentity(t, instanceID, false)
149-
client, db := coderdtest.NewWithDatabase(t, &coderdtest.Options{
160+
db, ps := dbtestutil.NewDB(t,
161+
dbtestutil.WithDumpOnFailure(),
162+
)
163+
client := coderdtest.New(t, &coderdtest.Options{
164+
Database: db,
165+
Pubsub: ps,
150166
GoogleTokenValidator: validator,
151167
})
152168
owner := coderdtest.CreateFirstUser(t, client)

‎coderd/database/dbfake/dbfake.go

Lines changed: 60 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,9 @@ import (
1212
"github.com/sqlc-dev/pqtype"
1313
"github.com/stretchr/testify/require"
1414

15+
"cdr.dev/slog"
16+
"cdr.dev/slog/sloggers/slogtest"
17+
1518
"github.com/coder/coder/v2/coderd/database"
1619
"github.com/coder/coder/v2/coderd/database/dbauthz"
1720
"github.com/coder/coder/v2/coderd/database/dbgen"
@@ -43,6 +46,7 @@ type WorkspaceResponse struct {
4346
// resources.
4447
type WorkspaceBuildBuilder struct {
4548
t testing.TB
49+
logger slog.Logger
4650
db database.Store
4751
ps pubsub.Pubsub
4852
ws database.WorkspaceTable
@@ -62,7 +66,10 @@ type workspaceBuildDisposition struct {
6266
// Omitting the template ID on a workspace will also generate a new template
6367
// with a template version.
6468
func WorkspaceBuild(t testing.TB, db database.Store, ws database.WorkspaceTable) WorkspaceBuildBuilder {
65-
return WorkspaceBuildBuilder{t: t, db: db, ws: ws}
69+
return WorkspaceBuildBuilder{
70+
t: t, db: db, ws: ws,
71+
logger: slogtest.Make(t, &slogtest.Options{}).Named("dbfake").Leveled(slog.LevelDebug),
72+
}
6673
}
6774

6875
func (b WorkspaceBuildBuilder) Pubsub(ps pubsub.Pubsub) WorkspaceBuildBuilder {
@@ -131,6 +138,7 @@ func (b WorkspaceBuildBuilder) Do() WorkspaceResponse {
131138
AgentToken: b.agentToken,
132139
}
133140
if b.ws.TemplateID == uuid.Nil {
141+
b.logger.Debug(context.Background(), "creating template and version")
134142
resp.TemplateVersionResponse = TemplateVersion(b.t, b.db).
135143
Resources(b.resources...).
136144
Pubsub(b.ps).
@@ -145,6 +153,7 @@ func (b WorkspaceBuildBuilder) Do() WorkspaceResponse {
145153

146154
// If no template version is set assume the active version.
147155
if b.seed.TemplateVersionID == uuid.Nil {
156+
b.logger.Debug(context.Background(), "assuming active template version")
148157
template, err := b.db.GetTemplateByID(ownerCtx, b.ws.TemplateID)
149158
require.NoError(b.t, err)
150159
require.NotNil(b.t, template.ActiveVersionID, "active version ID unexpectedly nil")
@@ -156,6 +165,9 @@ func (b WorkspaceBuildBuilder) Do() WorkspaceResponse {
156165
// nolint: revive
157166
b.ws = dbgen.Workspace(b.t, b.db, b.ws)
158167
resp.Workspace = b.ws
168+
b.logger.Debug(context.Background(), "created workspace",
169+
slog.F("name", resp.Workspace.Name),
170+
slog.F("workspace_id", resp.Workspace.ID))
159171
}
160172
b.seed.WorkspaceID = b.ws.ID
161173
b.seed.InitiatorID = takeFirst(b.seed.InitiatorID, b.ws.OwnerID)
@@ -182,10 +194,12 @@ func (b WorkspaceBuildBuilder) Do() WorkspaceResponse {
182194
LogsOverflowed: false,
183195
})
184196
require.NoError(b.t, err, "insert job")
197+
b.logger.Debug(context.Background(), "inserted provisioner job", slog.F("job_id", job.ID))
185198

186199
if b.dispo.starting {
187200
// might need to do this multiple times if we got a template version
188201
// import job as well
202+
b.logger.Debug(context.Background(), "looping to acquire provisioner job")
189203
for {
190204
j, err := b.db.AcquireProvisionerJob(ownerCtx, database.AcquireProvisionerJobParams{
191205
OrganizationID: job.OrganizationID,
@@ -202,10 +216,12 @@ func (b WorkspaceBuildBuilder) Do() WorkspaceResponse {
202216
})
203217
require.NoError(b.t, err, "acquire starting job")
204218
if j.ID == job.ID {
219+
b.logger.Debug(context.Background(), "acquired provisioner job", slog.F("job_id", job.ID))
205220
break
206221
}
207222
}
208223
} else {
224+
b.logger.Debug(context.Background(), "completing the provisioner job")
209225
err = b.db.UpdateProvisionerJobWithCompleteByID(ownerCtx, database.UpdateProvisionerJobWithCompleteByIDParams{
210226
ID: job.ID,
211227
UpdatedAt: dbtime.Now(),
@@ -221,18 +237,24 @@ func (b WorkspaceBuildBuilder) Do() WorkspaceResponse {
221237
}
222238

223239
resp.Build = dbgen.WorkspaceBuild(b.t, b.db, b.seed)
240+
b.logger.Debug(context.Background(), "created workspace build",
241+
slog.F("build_id", resp.Build.ID),
242+
slog.F("workspace_id", resp.Workspace.ID),
243+
slog.F("build_number", resp.Build.BuildNumber))
224244

225245
for i := range b.params {
226246
b.params[i].WorkspaceBuildID = resp.Build.ID
227247
}
228-
_ = dbgen.WorkspaceBuildParameters(b.t, b.db, b.params)
248+
params := dbgen.WorkspaceBuildParameters(b.t, b.db, b.params)
249+
b.logger.Debug(context.Background(), "created workspace build parameters", slog.F("count", len(params)))
229250

230251
if b.ws.Deleted {
231252
err = b.db.UpdateWorkspaceDeletedByID(ownerCtx, database.UpdateWorkspaceDeletedByIDParams{
232253
ID: b.ws.ID,
233254
Deleted: true,
234255
})
235256
require.NoError(b.t, err)
257+
b.logger.Debug(context.Background(), "deleted workspace", slog.F("workspace_id", resp.Workspace.ID))
236258
}
237259

238260
if b.ps != nil {
@@ -243,6 +265,9 @@ func (b WorkspaceBuildBuilder) Do() WorkspaceResponse {
243265
require.NoError(b.t, err)
244266
err = b.ps.Publish(wspubsub.WorkspaceEventChannel(resp.Workspace.OwnerID), msg)
245267
require.NoError(b.t, err)
268+
b.logger.Debug(context.Background(), "published workspace event",
269+
slog.F("owner_id", resp.Workspace.ID),
270+
slog.F("owner_id", resp.Workspace.OwnerID))
246271
}
247272

248273
agents, err := b.db.GetWorkspaceAgentsByWorkspaceAndBuildNumber(ownerCtx, database.GetWorkspaceAgentsByWorkspaceAndBuildNumberParams{
@@ -260,7 +285,12 @@ func (b WorkspaceBuildBuilder) Do() WorkspaceResponse {
260285
err = b.db.DeleteWorkspaceSubAgentByID(ownerCtx, subAgent.ID)
261286
require.NoError(b.t, err, "delete workspace agent subagent antagonist")
262287

263-
b.t.Logf("inserted deleted subagent antagonist %s (%v) for workspace agent %s (%v)", subAgent.Name, subAgent.ID, agent.Name, agent.ID)
288+
b.logger.Debug(context.Background(), "inserted deleted subagent antagonist",
289+
slog.F("subagent_name", subAgent.Name),
290+
slog.F("subagent_id", subAgent.ID),
291+
slog.F("agent_name", agent.Name),
292+
slog.F("agent_id", agent.ID),
293+
)
264294
}
265295
}
266296

@@ -269,6 +299,7 @@ func (b WorkspaceBuildBuilder) Do() WorkspaceResponse {
269299

270300
type ProvisionerJobResourcesBuilder struct {
271301
t testing.TB
302+
logger slog.Logger
272303
db database.Store
273304
jobID uuid.UUID
274305
transition database.WorkspaceTransition
@@ -281,6 +312,7 @@ func ProvisionerJobResources(
281312
) ProvisionerJobResourcesBuilder {
282313
return ProvisionerJobResourcesBuilder{
283314
t: t,
315+
logger: slogtest.Make(t, &slogtest.Options{}).Named("dbfake").Leveled(slog.LevelDebug).With(slog.F("job_id", jobID)),
284316
db: db,
285317
jobID: jobID,
286318
transition: transition,
@@ -292,13 +324,17 @@ func (b ProvisionerJobResourcesBuilder) Do() {
292324
b.t.Helper()
293325
transition := b.transition
294326
if transition == "" {
295-
// Default to start!
327+
b.logger.Debug(context.Background(), "setting default transition to start")
296328
transition = database.WorkspaceTransitionStart
297329
}
298330
for _, resource := range b.resources {
299331
//nolint:gocritic // This is only used by tests.
300332
err := provisionerdserver.InsertWorkspaceResource(ownerCtx, b.db, b.jobID, transition, resource, &telemetry.Snapshot{})
301333
require.NoError(b.t, err)
334+
b.logger.Debug(context.Background(), "created workspace resource",
335+
slog.F("resource_name", resource.Name),
336+
slog.F("agent_count", len(resource.Agents)),
337+
)
302338
}
303339
}
304340

@@ -309,6 +345,7 @@ type TemplateVersionResponse struct {
309345

310346
type TemplateVersionBuilder struct {
311347
t testing.TB
348+
logger slog.Logger
312349
db database.Store
313350
seed database.TemplateVersion
314351
fileID uuid.UUID
@@ -326,6 +363,7 @@ type TemplateVersionBuilder struct {
326363
func TemplateVersion(t testing.TB, db database.Store) TemplateVersionBuilder {
327364
return TemplateVersionBuilder{
328365
t: t,
366+
logger: slogtest.Make(t, &slogtest.Options{}).Named("dbfake").Leveled(slog.LevelDebug),
329367
db: db,
330368
promote: true,
331369
autoCreateTemplate: true,
@@ -396,20 +434,30 @@ func (t TemplateVersionBuilder) Do() TemplateVersionResponse {
396434
Valid: true,
397435
UUID: resp.Template.ID,
398436
}
437+
t.logger.Debug(context.Background(), "created template",
438+
slog.F("organization_id", resp.Template.OrganizationID),
439+
slog.F("template_id", resp.Template.CreatedBy),
440+
)
399441
}
400442

401443
version := dbgen.TemplateVersion(t.t, t.db, t.seed)
444+
t.logger.Debug(context.Background(), "created template version",
445+
slog.F("template_version_id", version.ID),
446+
)
402447
if t.promote {
403448
err := t.db.UpdateTemplateActiveVersionByID(ownerCtx, database.UpdateTemplateActiveVersionByIDParams{
404449
ID: t.seed.TemplateID.UUID,
405450
ActiveVersionID: t.seed.ID,
406451
UpdatedAt: dbtime.Now(),
407452
})
408453
require.NoError(t.t, err)
454+
t.logger.Debug(context.Background(), "promoted template version",
455+
slog.F("template_version_id", t.seed.ID),
456+
)
409457
}
410458

411459
for _, preset := range t.presets {
412-
dbgen.Preset(t.t, t.db, database.InsertPresetParams{
460+
prst := dbgen.Preset(t.t, t.db, database.InsertPresetParams{
413461
ID: preset.ID,
414462
TemplateVersionID: version.ID,
415463
Name: preset.Name,
@@ -421,14 +469,19 @@ func (t TemplateVersionBuilder) Do() TemplateVersionResponse {
421469
Description: preset.Description,
422470
Icon: preset.Icon,
423471
})
472+
t.logger.Debug(context.Background(), "added preset",
473+
slog.F("preset_id", prst.ID),
474+
slog.F("preset_name", prst.Name),
475+
)
424476
}
425477

426478
for _, presetParam := range t.presetParams {
427-
dbgen.PresetParameter(t.t, t.db, database.InsertPresetParametersParams{
479+
prm := dbgen.PresetParameter(t.t, t.db, database.InsertPresetParametersParams{
428480
TemplateVersionPresetID: presetParam.TemplateVersionPresetID,
429481
Names: []string{presetParam.Name},
430482
Values: []string{presetParam.Value},
431483
})
484+
t.logger.Debug(context.Background(), "added preset parameter", slog.F("param_name", prm[0].Name))
432485
}
433486

434487
payload, err := json.Marshal(provisionerdserver.TemplateVersionImportJob{
@@ -448,6 +501,7 @@ func (t TemplateVersionBuilder) Do() TemplateVersionResponse {
448501
},
449502
FileID: t.fileID,
450503
})
504+
t.logger.Debug(context.Background(), "added template version import job", slog.F("job_id", job.ID))
451505

452506
t.seed.JobID = job.ID
453507

‎coderd/database/dbtestutil/db.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -206,7 +206,7 @@ func DumpOnFailure(t testing.TB, connectionURL string) {
206206
outPath := filepath.Join(cwd, snakeCaseName+"."+timeSuffix+".test.sql")
207207
dump, err := PGDump(connectionURL)
208208
if err != nil {
209-
t.Errorf("dump on failure: failed to run pg_dump")
209+
t.Errorf("dump on failure: failed to run pg_dump: %s", err.Error())
210210
return
211211
}
212212
if err := os.WriteFile(outPath, normalizeDump(dump), 0o600); err != nil {

0 commit comments

Comments
 (0)