feat: Provisioner logs to timeline

backend/provisioner/dev_provisioner.go

@@ -33,11 +33,11 @@ func NewDevProvisioner(postgresPort int, mysqlPort int, recreate bool) *InMemPro
 }
 func provisionMysql(mysqlPort int, recreate bool) InMemResourceProvisionerFn {
 	return func(ctx context.Context, changeset key.Changeset, deployment key.Deployment, res schema.Provisioned) (*schema.RuntimeElement, error) {
-		logger := log.FromContext(ctx)
+		logger := log.FromContext(ctx).Deployment(deployment)
 
 		dbName := strcase.ToLowerSnake(deployment.Payload.Module) + "_" + strcase.ToLowerSnake(res.ResourceID())
 
-		logger.Debugf("Provisioning mysql database: %s", dbName)
+		logger.Infof("Provisioning mysql database: %s", dbName) //nolint
 
 		// We assume that the DB hsas already been started when running in dev mode
 		mysqlDSN, err := dev.SetupMySQL(ctx, mysqlPort)
@@ -125,10 +125,10 @@ func ProvisionMySQLForTest(ctx context.Context, moduleName string, id string) (s
 
 func provisionPostgres(postgresPort int, recreate bool) InMemResourceProvisionerFn {
 	return func(ctx context.Context, changeset key.Changeset, deployment key.Deployment, resource schema.Provisioned) (*schema.RuntimeElement, error) {
-		logger := log.FromContext(ctx)
+		logger := log.FromContext(ctx).Deployment(deployment)
 
 		dbName := strcase.ToLowerSnake(deployment.Payload.Module) + "_" + strcase.ToLowerSnake(resource.ResourceID())
-		logger.Debugf("Provisioning postgres database: %s", dbName)
+		logger.Infof("Provisioning postgres database: %s", dbName) //nolint
 
 		// We assume that the DB has already been started when running in dev mode
 		postgresDSN := dsn.PostgresDSN("ftl", dsn.Port(postgresPort))

backend/provisioner/service.go

@@ -24,6 +24,7 @@ import (
 	"github.com/block/ftl/internal/key"
 	"github.com/block/ftl/internal/log"
 	"github.com/block/ftl/internal/schema/schemaeventsource"
+	timeline "github.com/block/ftl/internal/timelineclient"
 )
 
 // CommonProvisionerConfig is shared config between the production controller and development server.
@@ -35,6 +36,7 @@ type CommonProvisionerConfig struct {
 type Config struct {
 	ControllerEndpoint *url.URL `name:"ftl-controller-endpoint" help:"Controller endpoint." env:"FTL_CONTROLLER_ENDPOINT" default:"http://127.0.0.1:8893"`
 	SchemaEndpoint     *url.URL `help:"Schema service endpoint." env:"FTL_SCHEMA_ENDPOINT" default:"http://127.0.0.1:8897"`
+	TimelineEndpoint   *url.URL `help:"Timeline endpoint." env:"FTL_TIMELINE_ENDPOINT" default:"http://127.0.0.1:8894"`
 	CommonProvisionerConfig
 }
 
@@ -75,9 +77,15 @@ func Start(
 	ctx context.Context,
 	registry *ProvisionerRegistry,
 	schemaClient schemaconnect.SchemaServiceClient,
+	timelineClient *timeline.Client,
 ) error {
 
-	logger := log.FromContext(ctx)
+	timelineLogSink := timeline.NewLogSink(timelineClient, log.Trace)
+	go timelineLogSink.RunLogLoop(ctx)
+
+	logger := log.FromContext(ctx).AddSink(timelineLogSink)
+	ctx = log.ContextWithLogger(ctx, logger)
+
 	logger.Debugf("Starting FTL provisioner")
 
 	svc, err := New(ctx, registry, schemaClient)
@@ -185,6 +193,7 @@ func RegistryFromConfigFile(ctx context.Context, workingDir string, file *os.Fil
 
 	return registry, nil
 }
+
 func (s *Service) HandleChangesetPrepared(ctx context.Context, req key.Changeset) error {
 
 	_, err := s.schemaClient.CommitChangeset(ctx, connect.NewRequest(&ftlv1.CommitChangesetRequest{Changeset: req.String()}))
@@ -193,6 +202,7 @@ func (s *Service) HandleChangesetPrepared(ctx context.Context, req key.Changeset
 	}
 	return nil
 }
+
 func (s *Service) HandleChangesetCommitted(ctx context.Context, req *schema.Changeset) error {
 	go func() {
 		time.Sleep(time.Second * 5)

charts/ftl/templates/provisioner-deployment.yaml

@@ -44,6 +44,8 @@ spec:
               value: "/working"
             - name: FTL_CONTROLLER_ENDPOINT
               value: "http://{{ include "ftl.fullname" . }}-controller:{{ .Values.controller.port }}"
+            - name: FTL_TIMELINE_ENDPOINT
+              value: "http://{{ include "ftl.fullname" . }}-timeline:{{ .Values.timeline.port }}"
             - name: FTL_SCHEMA_ENDPOINT
               value: "http://{{ include "ftl.fullname" . }}-schema:{{ $.Values.schema.services.schema.port }}"
             - name: LOG_LEVEL

cmd/ftl-provisioner-cloudformation/provisioner.go

@@ -117,7 +117,7 @@ func (c *CloudformationProvisioner) Provision(ctx context.Context, req *connect.
 		return nil, fmt.Errorf("provisioner already running: %s", stackID)
 	}
 	logger.Debugf("Starting task for module %s: %s", req.Msg.DesiredModule.Name, stackID)
-	task.Start(ctx, module.Name)
+	task.Start(ctx, module.Name, module.Runtime.Deployment.DeploymentKey)
 	return connect.NewResponse(&provisionerpb.ProvisionResponse{
 		Status:            provisionerpb.ProvisionResponse_PROVISION_RESPONSE_STATUS_SUBMITTED,
 		ProvisioningToken: stackID,

cmd/ftl-provisioner-cloudformation/status.go

@@ -23,7 +23,11 @@ func (c *CloudformationProvisioner) Status(ctx context.Context, req *connect.Req
 	// in that case, we start a new task to query the existing stack
 	task, loaded := c.running.LoadOrStore(token, &provisioner.Task{})
 	if !loaded {
-		task.Start(ctx, req.Msg.DesiredModule.Name)
+		dk, err := key.ParseDeploymentKey(token)
+		if err != nil {
+			return nil, fmt.Errorf("failed to parse deployment key: %w", err)
+		}
+		task.Start(ctx, req.Msg.DesiredModule.Name, dk)
 	}
 
 	if task.Err() != nil {

cmd/ftl-provisioner-sandbox/provisioner.go

@@ -88,7 +88,7 @@ func (c *SandboxProvisioner) Provision(ctx context.Context, req *connect.Request
 		return nil, fmt.Errorf("provisioner already running: %s", token)
 	}
 	logger.Debugf("Starting task %s", token)
-	task.Start(ctx, module.Name)
+	task.Start(ctx, module.Name, module.Runtime.Deployment.DeploymentKey)
 	return connect.NewResponse(&provisionerpb.ProvisionResponse{
 		Status:            provisionerpb.ProvisionResponse_PROVISION_RESPONSE_STATUS_SUBMITTED,
 		ProvisioningToken: token,

cmd/ftl-provisioner/main.go

@@ -17,6 +17,7 @@ import (
 	"github.com/block/ftl/internal/observability"
 	_ "github.com/block/ftl/internal/prodinit"
 	"github.com/block/ftl/internal/rpc"
+	timeline "github.com/block/ftl/internal/timelineclient"
 )
 
 var cli struct {
@@ -36,6 +37,8 @@ func main() {
 	)
 	cli.ProvisionerConfig.SetDefaults()
 
+	timelineClient := timeline.NewClient(context.Background(), cli.ProvisionerConfig.TimelineEndpoint)
+
 	logger := log.Configure(os.Stderr, cli.LogConfig)
 	ctx := log.ContextWithLogger(context.Background(), logger)
 	err := observability.Init(ctx, false, "", "ftl-provisioner", ftl.Version, cli.ObservabilityConfig)
@@ -69,6 +72,6 @@ func main() {
 		logger.Debugf("Registered provisioner %s as fallback for runner", runnerBinding)
 	}
 
-	err = provisioner.Start(ctx, registry, schemaClient)
+	err = provisioner.Start(ctx, registry, schemaClient, timelineClient)
 	kctx.FatalIfErrorf(err, "failed to start provisioner")
 }

cmd/ftl/cmd_serve.go

@@ -324,7 +324,7 @@ func (s *serveCommonConfig) run(
 	}
 
 	wg.Go(func() error {
-		if err := provisioner.Start(provisionerCtx, provisionerRegistry, schemaClient); err != nil {
+		if err := provisioner.Start(provisionerCtx, provisionerRegistry, schemaClient, timelineClient); err != nil {
 			logger.Errorf(err, "provisionerfailed: %v", err)
 			return fmt.Errorf("provisionerfailed: %w", err)
 		}

internal/log/logger.go

@@ -11,12 +11,15 @@ import (
 	"github.com/alecthomas/atomic"
 	"github.com/alecthomas/types/optional"
 	"github.com/benbjohnson/clock"
+
+	"github.com/block/ftl/internal/key"
 )
 
 var _ Interface = (*Logger)(nil)
 
 const scopeKey = "scope"
 const moduleKey = "module"
+const deploymentKey = "deployment"
 
 type Entry struct {
 	Time       time.Time         `json:"-"`
@@ -54,6 +57,10 @@ func (l Logger) Module(module string) *Logger {
 	return l.Attrs(map[string]string{moduleKey: module})
 }
 
+func (l Logger) Deployment(deployment key.Deployment) *Logger {
+	return l.Attrs(map[string]string{deploymentKey: deployment.String()})
+}
+
 // Attrs creates a new logger with the given attributes.
 func (l Logger) Attrs(attributes map[string]string) *Logger {
 	attr := make(map[string]string, len(l.attributes)+len(attributes))

internal/provisioner/executor_test.go

@@ -53,7 +53,7 @@ func TestExecutorSelection(t *testing.T) {
 		},
 	}
 
-	states, err := runner.Run(ctx, "test")
+	states, err := runner.Run(ctx)
 	assert.NoError(t, err)
 	assert.Equal(t, 2, len(states))
 

internal/provisioner/runner.go

@@ -8,6 +8,7 @@ import (
 	"github.com/alecthomas/atomic"
 	"golang.org/x/sync/errgroup"
 
+	"github.com/block/ftl/internal/key"
 	"github.com/block/ftl/internal/log"
 	"github.com/block/ftl/internal/provisioner/state"
 )
@@ -41,8 +42,8 @@ type Runner struct {
 	Stages []RunnerStage
 }
 
-func (r *Runner) Run(ctx context.Context, module string) ([]state.State, error) {
-	logger := log.FromContext(ctx).Module(module)
+func (r *Runner) Run(ctx context.Context) ([]state.State, error) {
+	logger := log.FromContext(ctx)
 
 	for _, stage := range r.Stages {
 		logger.Debugf("running stage %s", stage.Name)
@@ -120,11 +121,12 @@ func (r *Runner) execute(ctx context.Context, stage *RunnerStage) ([]state.State
 	return result, nil
 }
 
-func (t *Task) Start(oldCtx context.Context, module string) {
+func (t *Task) Start(oldCtx context.Context, module string, deployment key.Deployment) {
 	ctx := context.WithoutCancel(oldCtx)
-	logger := log.FromContext(ctx).Module(module)
+	logger := log.FromContext(ctx).Module(module).Deployment(deployment)
+	ctx = log.ContextWithLogger(ctx, logger)
 	go func() {
-		outputs, err := t.runner.Run(ctx, module)
+		outputs, err := t.runner.Run(ctx)
 		if err != nil {
 			logger.Errorf(err, "failed to execute provisioner")
 			t.err.Store(err)