fix: provisionerd: add more context to logs emitted, fix log level (#6508)

johnstcn · web-flow · commit 26a725f86d2e · 2023-03-08T15:12:52.000Z
- Previously, we were logging all provision response logs at level INFO, regardless of the log level of the log streamed from the provisioner. We now log these at the original level (defaulting to INFO).
- Now logging "provision failed" message at level ERROR WARN and including the error field in the message.
diff --git a/provisionerd/runner/runner.go b/provisionerd/runner/runner.go
@@ -880,7 +880,7 @@ func (r *Runner) buildWorkspace(ctx context.Context, stage string, req *sdkproto
 		}
 		switch msgType := msg.Type.(type) {
 		case *sdkproto.Provision_Response_Log:
-			r.logger.Info(context.Background(), "workspace provision job logged",
+			r.logProvisionerJobLog(context.Background(), msgType.Log.Level, "workspace provisioner job logged",
 				slog.F("level", msgType.Log.Level),
 				slog.F("output", msgType.Log.Output),
 				slog.F("workspace_build_id", r.job.GetWorkspaceBuild().WorkspaceBuildId),
@@ -895,8 +895,9 @@ func (r *Runner) buildWorkspace(ctx context.Context, stage string, req *sdkproto
 			})
 		case *sdkproto.Provision_Response_Complete:
 			if msgType.Complete.Error != "" {
-				r.logger.Info(context.Background(), "provision failed; updating state",
+				r.logger.Warn(context.Background(), "provision failed; updating state",
 					slog.F("state_length", len(msgType.Complete.State)),
+					slog.F("error", msgType.Complete.Error),
 				)
 
 				return nil, &proto.FailedJob{
@@ -1120,3 +1121,21 @@ func redactVariableValues(variableValues []*sdkproto.VariableValue) []*sdkproto.
 	}
 	return redacted
 }
+
+// logProvisionerJobLog logs a message from the provisioner daemon at the appropriate level.
+func (r *Runner) logProvisionerJobLog(ctx context.Context, logLevel sdkproto.LogLevel, msg string, fields ...slog.Field) {
+	switch logLevel {
+	case sdkproto.LogLevel_TRACE:
+		r.logger.Debug(ctx, msg, fields...) // There's no trace, so we'll just use debug.
+	case sdkproto.LogLevel_DEBUG:
+		r.logger.Debug(ctx, msg, fields...)
+	case sdkproto.LogLevel_INFO:
+		r.logger.Info(ctx, msg, fields...)
+	case sdkproto.LogLevel_WARN:
+		r.logger.Warn(ctx, msg, fields...)
+	case sdkproto.LogLevel_ERROR:
+		r.logger.Error(ctx, msg, fields...)
+	default: // should never happen, but we should not explode either.
+		r.logger.Info(ctx, msg, fields...)
+	}
+}
