fix: add debug logging to the provisioner (#3208)

TBD54566975 · Oct 28, 2024 · d0ec90c · d0ec90c
1 parent ac6ebec
commit d0ec90c
Show file tree

Hide file tree

Showing 4 changed files with 26 additions and 15 deletions.
diff --git a/backend/provisioner/deployment_test.go b/backend/provisioner/deployment_test.go
@@ -9,6 +9,7 @@ import (
 	proto "github.com/TBD54566975/ftl/backend/protos/xyz/block/ftl/v1beta1/provisioner"
 	"github.com/TBD54566975/ftl/backend/protos/xyz/block/ftl/v1beta1/provisioner/provisionerconnect"
 	"github.com/TBD54566975/ftl/backend/provisioner"
+	"github.com/TBD54566975/ftl/internal/log"
 	"github.com/alecthomas/assert/v2"
 )
 
@@ -55,7 +56,7 @@ func (m *MockProvisioner) Status(ctx context.Context, req *connect.Request[proto
 }
 
 func TestDeployment_Progress(t *testing.T) {
-	ctx := context.Background()
+	ctx := log.ContextWithNewDefaultLogger(context.Background())
 
 	t.Run("no tasks", func(t *testing.T) {
 		deployment := &provisioner.Deployment{}
@@ -73,7 +74,7 @@ func TestDeployment_Progress(t *testing.T) {
 		graph.AddNode(&proto.Resource{ResourceId: "a", Resource: &proto.Resource_Mysql{}})
 		graph.AddNode(&proto.Resource{ResourceId: "b", Resource: &proto.Resource_Postgres{}})
 
-		dpl := registry.CreateDeployment("test-module", graph, &provisioner.ResourceGraph{})
+		dpl := registry.CreateDeployment(ctx, "test-module", graph, &provisioner.ResourceGraph{})
 
 		assert.Equal(t, 2, len(dpl.State().Pending))
 

diff --git a/backend/provisioner/registry.go b/backend/provisioner/registry.go
@@ -43,23 +43,24 @@ func (cfg *provisionerPluginConfig) Validate() error {
 // ProvisionerBinding is a Provisioner and the types it supports
 type ProvisionerBinding struct {
 	Provisioner provisionerconnect.ProvisionerPluginServiceClient
+	ID          string
 	Types       []ResourceType
 }
 
 // ProvisionerRegistry contains all known resource handlers in the order they should be executed
 type ProvisionerRegistry struct {
-	Default      provisionerconnect.ProvisionerPluginServiceClient
+	Default      *ProvisionerBinding
 	Provisioners []*ProvisionerBinding
 }
 
 // listProvisioners in the order they should be executed
-func (reg *ProvisionerRegistry) listProvisioners() []provisionerconnect.ProvisionerPluginServiceClient {
-	result := []provisionerconnect.ProvisionerPluginServiceClient{}
+func (reg *ProvisionerRegistry) listProvisioners() []*ProvisionerBinding {
+	result := []*ProvisionerBinding{}
 	if reg.Default != nil {
 		result = append(result, reg.Default)
 	}
 	for _, p := range reg.Provisioners {
-		result = append(result, p.Provisioner)
+		result = append(result, p)
 	}
 	return result
 }
@@ -73,7 +74,7 @@ func registryFromConfig(ctx context.Context, cfg *provisionerPluginConfig, contr
 		}
 		def = d
 	}
-	result := &ProvisionerRegistry{Default: def}
+	result := &ProvisionerRegistry{Default: &ProvisionerBinding{Provisioner: def, ID: cfg.Default}}
 	if err := cfg.Validate(); err != nil {
 		return nil, fmt.Errorf("error validating provisioner config: %w", err)
 	}
@@ -119,23 +120,28 @@ func (reg *ProvisionerRegistry) Register(handler provisionerconnect.ProvisionerP
 }
 
 // CreateDeployment to take the system to the desired state
-func (reg *ProvisionerRegistry) CreateDeployment(module string, desiredResources, existingResources *ResourceGraph) *Deployment {
+func (reg *ProvisionerRegistry) CreateDeployment(ctx context.Context, module string, desiredResources, existingResources *ResourceGraph) *Deployment {
+	logger := log.FromContext(ctx)
+
 	var result []*Task
 
 	existingByHandler := reg.groupByProvisioner(existingResources.Resources())
 	desiredByHandler := reg.groupByProvisioner(desiredResources.Resources())
 
-	for _, handler := range reg.listProvisioners() {
-		desired := desiredByHandler[handler]
-		existing := existingByHandler[handler]
+	for _, binding := range reg.listProvisioners() {
+		desired := desiredByHandler[binding.Provisioner]
+		existing := existingByHandler[binding.Provisioner]
 
 		if !resourcesEqual(desired, existing) {
+			logger.Debugf("Adding task for module %s with provisioner %s", module, binding.ID)
 			result = append(result, &Task{
 				module:   module,
-				handler:  handler,
+				handler:  binding.Provisioner,
 				desired:  desiredResources.WithDirectDependencies(desired),
 				existing: existingResources.WithDirectDependencies(existing),
 			})
+		} else {
+			logger.Debugf("Skipping task for module %s with provisioner %s", module, binding.ID)
 		}
 	}
 	return &Deployment{Tasks: result, Module: module}
@@ -241,7 +247,7 @@ func (reg *ProvisionerRegistry) groupByProvisioner(resources []*provisioner.Reso
 			}
 		}
 		if !found && reg.Default != nil {
-			result[reg.Default] = append(result[reg.Default], r)
+			result[reg.Default.Provisioner] = append(result[reg.Default.Provisioner], r)
 		}
 	}
 	return result

diff --git a/backend/provisioner/service.go b/backend/provisioner/service.go
@@ -71,7 +71,7 @@ func (s *Service) CreateDeployment(ctx context.Context, req *connect.Request[ftl
 		return nil, err
 	}
 
-	deployment := s.registry.CreateDeployment(moduleName, desiredGraph, existingResources)
+	deployment := s.registry.CreateDeployment(ctx, moduleName, desiredGraph, existingResources)
 	running := true
 	logger.Debugf("Running deployment for module %s", moduleName)
 	for running {

diff --git a/frontend/cli/cmd_serve.go b/frontend/cli/cmd_serve.go
@@ -222,8 +222,12 @@ func (s *serveCmd) run(ctx context.Context, projConfig projectconfig.Config, ini
 			Provisioners: []*provisioner.ProvisionerBinding{{
 				Provisioner: provisioner.NewControllerProvisioner(controllerClient),
 				Types:       []provisioner.ResourceType{provisioner.ResourceTypeModule},
+				ID:          "controller",
 			}},
-			Default: provisioner.NewDevProvisioner(s.DBPort),
+			Default: &provisioner.ProvisionerBinding{
+				Provisioner: provisioner.NewDevProvisioner(s.DBPort),
+				ID:          "dev",
+			},
 		}
 
 		// read provisioners from a config file if provided