feat: Enable workspace debug logging (#6838)

* feat: Enable workspace debug logging

* Fix

* Fix

* Fix

* fix

* fix

* Enable RBAC

* unit tests

* Fix

* fix

* fix

* fix

* more tests

* fix: workspacebuild_test use roles

* fix: swagger comment

* fix: ctx.Done

* fix: address PR comments

* break loop

provisioner/echo/serve.go

@@ -192,7 +192,12 @@ func (e *echo) Provision(stream proto.DRPCProvisioner_ProvisionStream) error {
 		if err != nil {
 			return xerrors.Errorf("unmarshal: %w", err)
 		}
-		err = stream.Send(&response)
+		r, ok := filterLogResponses(config, &response)
+		if !ok {
+			continue
+		}
+
+		err = stream.Send(r)
 		if err != nil {
 			return err
 		}
@@ -282,3 +287,23 @@ func Tar(responses *Responses) ([]byte, error) {
 	}
 	return buffer.Bytes(), nil
 }
+
+func filterLogResponses(config *proto.Provision_Config, response *proto.Provision_Response) (*proto.Provision_Response, bool) {
+	responseLog, ok := response.Type.(*proto.Provision_Response_Log)
+	if !ok {
+		// Pass all non-log responses
+		return response, true
+	}
+
+	if config.ProvisionerLogLevel == "" {
+		// Don't change the default behavior of "echo"
+		return response, true
+	}
+
+	provisionerLogLevel := proto.LogLevel_value[strings.ToUpper(config.ProvisionerLogLevel)]
+	if int32(responseLog.Log.Level) < provisionerLogLevel {
+		// Log level is not enabled
+		return nil, false
+	}
+	return response, true
+}

provisioner/echo/serve_test.go

@@ -79,6 +79,7 @@ func TestEcho(t *testing.T) {
 		responses := []*proto.Provision_Response{{
 			Type: &proto.Provision_Response_Log{
 				Log: &proto.Log{
+					Level:  proto.LogLevel_INFO,
 					Output: "log-output",
 				},
 			},
@@ -115,6 +116,59 @@ func TestEcho(t *testing.T) {
 		require.Equal(t, responses[1].GetComplete().Resources[0].Name,
 			complete.GetComplete().Resources[0].Name)
 	})
+
+	t.Run("ProvisionWithLogLevel", func(t *testing.T) {
+		t.Parallel()
+
+		responses := []*proto.Provision_Response{{
+			Type: &proto.Provision_Response_Log{
+				Log: &proto.Log{
+					Level:  proto.LogLevel_TRACE,
+					Output: "log-output-trace",
+				},
+			},
+		}, {
+			Type: &proto.Provision_Response_Log{
+				Log: &proto.Log{
+					Level:  proto.LogLevel_INFO,
+					Output: "log-output-info",
+				},
+			},
+		}, {
+			Type: &proto.Provision_Response_Complete{
+				Complete: &proto.Provision_Complete{
+					Resources: []*proto.Resource{{
+						Name: "resource",
+					}},
+				},
+			},
+		}}
+		data, err := echo.Tar(&echo.Responses{
+			ProvisionApply: responses,
+		})
+		require.NoError(t, err)
+		client, err := api.Provision(ctx)
+		require.NoError(t, err)
+		err = client.Send(&proto.Provision_Request{
+			Type: &proto.Provision_Request_Plan{
+				Plan: &proto.Provision_Plan{
+					Config: &proto.Provision_Config{
+						Directory:           unpackTar(t, fs, data),
+						ProvisionerLogLevel: "debug",
+					},
+				},
+			},
+		})
+		require.NoError(t, err)
+		log, err := client.Recv()
+		require.NoError(t, err)
+		// Skip responses[0] as it's trace level
+		require.Equal(t, responses[1].GetLog().Output, log.GetLog().Output)
+		complete, err := client.Recv()
+		require.NoError(t, err)
+		require.Equal(t, responses[2].GetComplete().Resources[0].Name,
+			complete.GetComplete().Resources[0].Name)
+	})
 }
 
 func unpackTar(t *testing.T, fs afero.Fs, data []byte) string {

provisioner/terraform/executor.go

@@ -473,7 +473,11 @@ func readAndLog(sink logSink, r io.Reader, done chan<- any, level proto.LogLevel
 
 		logLevel := convertTerraformLogLevel(log.Level, sink)
 		if logLevel == proto.LogLevel_TRACE {
-			continue // skip TRACE log entries as they produce a lot of noise
+			// Skip TRACE log entries as they produce a lot of noise.
+			//
+			// FIXME consider config.ProvisionerLogLevel to enable custom level logging
+			// instead of "just-debug-level" mode.
+			continue
 		}
 
 		// Degrade JSON log entries marked as INFO as these are logs produced in debug mode.

provisioner/terraform/provision.go

@@ -236,7 +236,12 @@ func provisionEnv(config *proto.Provision_Config, params []*proto.ParameterValue
 	for _, gitAuth := range gitAuth {
 		env = append(env, provider.GitAuthAccessTokenEnvironmentVariable(gitAuth.Id)+"="+gitAuth.AccessToken)
 	}
-	// FIXME env = append(env, "TF_LOG=JSON")
+
+	if config.ProvisionerLogLevel != "" {
+		// TF_LOG=JSON enables all kind of logging: trace-debug-info-warn-error.
+		// The idea behind using TF_LOG=JSON instead of TF_LOG=debug is ensuring the proper log format.
+		env = append(env, "TF_LOG=JSON")
+	}
 	return env, nil
 }