fix(provisionerd): add more detailed workspace build logging (#6331)

johnstcn · web-flow · commit 282507f0fb2a · 2023-02-24T00:03:12.000Z
diff --git a/provisionerd/provisionerd.go b/provisionerd/provisionerd.go
@@ -345,7 +345,23 @@ func (p *Server) acquireJob(ctx context.Context) {
 	))
 	defer span.End()
 
+	fields := []slog.Field{
+		slog.F("initiator_username", job.UserName),
+		slog.F("provisioner", job.Provisioner),
+		slog.F("job_id", job.JobId),
+	}
+
 	if build := job.GetWorkspaceBuild(); build != nil {
+		fields = append(fields,
+			slog.F("action", build.Metadata.WorkspaceTransition.String()),
+			slog.F("owner_email", build.Metadata.WorkspaceOwnerEmail),
+			slog.F("template_name", build.Metadata.TemplateName),
+			slog.F("template_version", build.Metadata.TemplateVersion),
+			slog.F("workspace_build_id", build.WorkspaceBuildId),
+			slog.F("workspace_id", build.Metadata.WorkspaceId),
+			slog.F("workspace_name", build.WorkspaceName),
+		)
+
 		span.SetAttributes(
 			attribute.String("workspace_build_id", build.WorkspaceBuildId),
 			attribute.String("workspace_id", build.Metadata.WorkspaceId),
@@ -356,11 +372,7 @@ func (p *Server) acquireJob(ctx context.Context) {
 		)
 	}
 
-	p.opts.Logger.Info(ctx, "acquired job",
-		slog.F("initiator_username", job.UserName),
-		slog.F("provisioner", job.Provisioner),
-		slog.F("job_id", job.JobId),
-	)
+	p.opts.Logger.Info(ctx, "acquired job", fields...)
 
 	provisioner, ok := p.opts.Provisioners[job.Provisioner]
 	if !ok {
diff --git a/provisionerd/runner/runner.go b/provisionerd/runner/runner.go
@@ -115,13 +115,26 @@ func New(
 	forceStopContext, forceStopFunc := context.WithCancel(ctx)
 	gracefulContext, cancelFunc := context.WithCancel(forceStopContext)
 
+	logger := opts.Logger.With(slog.F("job_id", job.JobId))
+	if build := job.GetWorkspaceBuild(); build != nil {
+		logger = logger.With(
+			slog.F("action", build.Metadata.WorkspaceTransition.String()),
+			slog.F("owner_email", build.Metadata.WorkspaceOwnerEmail),
+			slog.F("template_name", build.Metadata.TemplateName),
+			slog.F("template_version", build.Metadata.TemplateVersion),
+			slog.F("workspace_build_id", build.WorkspaceBuildId),
+			slog.F("workspace_id", build.Metadata.WorkspaceId),
+			slog.F("workspace_name", build.Metadata.WorkspaceName),
+		)
+	}
+
 	return &Runner{
 		tracer:              opts.Tracer,
 		metrics:             opts.Metrics,
 		job:                 job,
 		sender:              opts.Updater,
 		quotaCommitter:      opts.QuotaCommitter,
-		logger:              opts.Logger.With(slog.F("job_id", job.JobId)),
+		logger:              logger,
 		filesystem:          opts.Filesystem,
 		workDirectory:       opts.WorkDirectory,
 		provisioner:         opts.Provisioner,
@@ -856,7 +869,7 @@ func (r *Runner) buildWorkspace(ctx context.Context, stage string, req *sdkproto
 		}
 		switch msgType := msg.Type.(type) {
 		case *sdkproto.Provision_Response_Log:
-			r.logger.Debug(context.Background(), "workspace provision job logged",
+			r.logger.Info(context.Background(), "workspace provision job logged",
 				slog.F("level", msgType.Log.Level),
 				slog.F("output", msgType.Log.Output),
 				slog.F("workspace_build_id", r.job.GetWorkspaceBuild().WorkspaceBuildId),
@@ -886,7 +899,6 @@ func (r *Runner) buildWorkspace(ctx context.Context, stage string, req *sdkproto
 				}
 			}
 
-			r.logger.Debug(context.Background(), "provision complete no error")
 			r.logger.Info(context.Background(), "provision successful",
 				slog.F("resource_count", len(msgType.Complete.Resources)),
 				slog.F("resources", msgType.Complete.Resources),
