feat: raft event logging (#4292)

backend/schemaservice/events.go

@@ -20,6 +20,8 @@ import (
 
 // ApplyEvent applies an event to the schema state
 func (r SchemaState) ApplyEvent(ctx context.Context, event schema.Event) error {
+	logger := log.FromContext(ctx)
+	logger.Debugf("Applying Raft event %s", event.DebugString())
 	if err := event.Validate(); err != nil {
 		return fmt.Errorf("invalid event: %w", err)
 	}

common/schema/events.go → common/schema/raftevents.go

@@ -16,6 +16,8 @@ import (
 type Event interface {
 	event()
 	Validate() error
+	// DebugString returns a string representation of the event for debugging purposes
+	DebugString() string
 }
 
 // deployment events
@@ -43,6 +45,10 @@ type DeploymentCreatedEvent struct {
 	Changeset *key.Changeset `protobuf:"3"`
 }
 
+func (r *DeploymentCreatedEvent) DebugString() string {
+	return fmt.Sprintf("DeploymentCreatedEvent{key: %s, changeset: %s}", r.Key.String(), r.Changeset.String())
+}
+
 func (r *DeploymentCreatedEvent) event() {}
 
 func (r *DeploymentCreatedEvent) Validate() error {
@@ -59,6 +65,10 @@ type DeploymentSchemaUpdatedEvent struct {
 	Changeset key.Changeset  `protobuf:"3"`
 }
 
+func (r *DeploymentSchemaUpdatedEvent) DebugString() string {
+	return fmt.Sprintf("DeploymentSchemaUpdatedEvent{key: %s, changeset: %s}", r.Key.String(), r.Changeset.String())
+}
+
 func (r *DeploymentSchemaUpdatedEvent) event() {}
 
 func (r *DeploymentSchemaUpdatedEvent) Validate() error {
@@ -72,6 +82,10 @@ type DeploymentReplicasUpdatedEvent struct {
 	Changeset *key.Changeset `protobuf:"3"`
 }
 
+func (r *DeploymentReplicasUpdatedEvent) DebugString() string {
+	return fmt.Sprintf("DeploymentReplicasUpdatedEvent{key: %s, changeset: %s, replicas: %d}", r.Key.String(), r.Changeset.String(), r.Replicas)
+}
+
 func (r *DeploymentReplicasUpdatedEvent) event() {}
 
 func (r *DeploymentReplicasUpdatedEvent) Validate() error {
@@ -86,6 +100,10 @@ type DeploymentActivatedEvent struct {
 	Changeset   *key.Changeset `protobuf:"4"`
 }
 
+func (r *DeploymentActivatedEvent) DebugString() string {
+	return fmt.Sprintf("DeploymentActivatedEvent{key: %s, changeset: %s, minReplicas: %d}", r.Key.String(), r.Changeset.String(), r.MinReplicas)
+}
+
 func (r *DeploymentActivatedEvent) event() {}
 
 func (r *DeploymentActivatedEvent) Validate() error {
@@ -99,6 +117,10 @@ type DeploymentDeactivatedEvent struct {
 	Changeset     *key.Changeset `protobuf:"3"`
 }
 
+func (r *DeploymentDeactivatedEvent) DebugString() string {
+	return fmt.Sprintf("DeploymentDeactivatedEvent{key: %s, changeset: %s, moduleRemoved: %v}", r.Key.String(), r.Changeset.String(), r.ModuleRemoved)
+}
+
 func (r *DeploymentDeactivatedEvent) event() {}
 
 func (r *DeploymentDeactivatedEvent) Validate() error {
@@ -113,6 +135,10 @@ type VerbRuntimeEvent struct {
 	Subscription optional.Option[VerbRuntimeSubscription] `protobuf:"4"`
 }
 
+func (e *VerbRuntimeEvent) DebugString() string {
+	return fmt.Sprintf("VerbRuntimeEvent{module: %s, changeset: %s, id: %v, subscription: %v}", e.Module, e.Changeset.String(), e.ID, e.Subscription)
+}
+
 func (e *VerbRuntimeEvent) event() {}
 
 func (e *VerbRuntimeEvent) Validate() error {
@@ -127,6 +153,10 @@ type TopicRuntimeEvent struct {
 	Payload   *TopicRuntime `protobuf:"4"`
 }
 
+func (e *TopicRuntimeEvent) DebugString() string {
+	return fmt.Sprintf("TopicRuntimeEvent{module: %s, changeset: %s, id: %v, payload: %v}", e.Module, e.Changeset.String(), e.ID, e.Payload)
+}
+
 func (e *TopicRuntimeEvent) event() {}
 
 func (e *TopicRuntimeEvent) Validate() error {
@@ -141,6 +171,10 @@ type DatabaseRuntimeEvent struct {
 	Connections *DatabaseRuntimeConnections `protobuf:"4"`
 }
 
+func (e *DatabaseRuntimeEvent) DebugString() string {
+	return fmt.Sprintf("DatabaseRuntimeEvent{module: %s, changeset: %s, id: %v, connections: %v}", e.Module, e.Changeset.String(), e.ID, e.Connections)
+}
+
 func (e *DatabaseRuntimeEvent) event() {}
 
 func (e *DatabaseRuntimeEvent) Validate() error {
@@ -156,6 +190,10 @@ type ModuleRuntimeEvent struct {
 	Deployment    optional.Option[ModuleRuntimeDeployment] `protobuf:"5"`
 }
 
+func (e *ModuleRuntimeEvent) DebugString() string {
+	return fmt.Sprintf("ModuleRuntimeEvent{deployment: %s, changeset: %s, deployment %v}", e.DeploymentKey.String(), e.Changeset.String(), e.Deployment)
+}
+
 func (e *ModuleRuntimeEvent) event() {}
 
 func (e *ModuleRuntimeEvent) Validate() error {
@@ -167,6 +205,18 @@ type ChangesetCreatedEvent struct {
 	Changeset *Changeset `protobuf:"1"`
 }
 
+func (e *ChangesetCreatedEvent) DebugString() string {
+	ret := fmt.Sprintf("ChangesetCreatedEvent{key: %s", e.Changeset.Key.String())
+	for _, m := range e.Changeset.Modules {
+		if m.Runtime == nil || m.Runtime.Deployment == nil {
+			ret += fmt.Sprintf(", invalid module: %s", m.Name)
+		} else {
+			ret += fmt.Sprintf(", deployment: %s", m.Runtime.Deployment.DeploymentKey.String())
+		}
+	}
+	return ret + "}"
+}
+
 func (e *ChangesetCreatedEvent) event() {}
 
 func (e *ChangesetCreatedEvent) Validate() error {
@@ -181,6 +231,10 @@ type ChangesetPreparedEvent struct {
 	Key key.Changeset `protobuf:"1"`
 }
 
+func (e *ChangesetPreparedEvent) DebugString() string {
+	return fmt.Sprintf("ChangesetPreparedEvent{changeset: %s}", e.Key.String())
+}
+
 func (e *ChangesetPreparedEvent) event() {}
 
 func (e *ChangesetPreparedEvent) Validate() error {
@@ -192,6 +246,10 @@ type ChangesetCommittedEvent struct {
 	Key key.Changeset `protobuf:"1"`
 }
 
+func (e *ChangesetCommittedEvent) DebugString() string {
+	return fmt.Sprintf("ChangesetCommittedEvent{changeset: %s}", e.Key.String())
+}
+
 func (e *ChangesetCommittedEvent) event() {}
 
 func (e *ChangesetCommittedEvent) Validate() error {
@@ -203,6 +261,10 @@ type ChangesetDrainedEvent struct {
 	Key key.Changeset `protobuf:"1"`
 }
 
+func (e *ChangesetDrainedEvent) DebugString() string {
+	return fmt.Sprintf("ChangesetDrainedEvent{changeset: %s}", e.Key.String())
+}
+
 func (e *ChangesetDrainedEvent) event() {}
 
 func (e *ChangesetDrainedEvent) Validate() error {
@@ -214,6 +276,10 @@ type ChangesetFinalizedEvent struct {
 	Key key.Changeset `protobuf:"1"`
 }
 
+func (e *ChangesetFinalizedEvent) DebugString() string {
+	return fmt.Sprintf("ChangesetFinalizedEvent{changeset: %s}", e.Key.String())
+}
+
 func (e *ChangesetFinalizedEvent) event() {}
 
 func (e *ChangesetFinalizedEvent) Validate() error {
@@ -226,6 +292,10 @@ type ChangesetFailedEvent struct {
 	Error string        `protobuf:"2"`
 }
 
+func (e *ChangesetFailedEvent) DebugString() string {
+	return fmt.Sprintf("ChangesetFailedEvent{changeset: %s, Error: %s}", e.Key.String(), e.Error)
+}
+
 func (e *ChangesetFailedEvent) event() {}
 
 func (e *ChangesetFailedEvent) Validate() error {

internal/routing/routing.go

@@ -110,7 +110,7 @@ func extractRoutes(ctx context.Context, sch *schema.Schema) RouteView {
 		}
 		rt := module.Runtime.Deployment
 		if rt.Endpoint == "" {
-			logger.Debugf("Skipping route for %s/%s as it is not ready yet", module.Name, rt.DeploymentKey)
+			logger.Tracef("Skipping route for %s/%s as it is not ready yet", module.Name, rt.DeploymentKey)
 			continue
 		}
 		u, err := url.Parse(rt.Endpoint)