From 6ff68f62f6f5dab3156d52984f0dda4a37f75481 Mon Sep 17 00:00:00 2001
From: oppiliappan <me@oppi.li>
Date: Thu, 9 Oct 2025 14:04:19 +0100
Subject: [PATCH] spindle: improve the logging situation
Change-Id: nsovyllpxlwkuuvnnnnzxlmwpqpsqouo

Signed-off-by: oppiliappan <me@oppi.li>
---
 cmd/spindle/main.go   | 10 ++++++----
 spindle/middleware.go | 35 +++++++++++++++++++++++++++++++++++
 spindle/server.go     | 12 ++++++------
 spindle/stream.go     |  6 +++---
 4 files changed, 50 insertions(+), 13 deletions(-)
 create mode 100644 spindle/middleware.go

diff --git a/cmd/spindle/main.go b/cmd/spindle/main.go
index 95d6ce33..550b3a84 100644
--- a/cmd/spindle/main.go
+++ b/cmd/spindle/main.go
@@ -4,16 +4,18 @@ import (
 	"context"
 	"os"
 
-	"tangled.org/core/log"
+	tlog "tangled.org/core/log"
 	"tangled.org/core/spindle"
-	_ "tangled.org/core/tid"
 )
 
 func main() {
-	ctx := log.NewContext(context.Background(), "spindle")
+	ctx := context.Background()
+	logger := tlog.New("spindle")
+	ctx = tlog.IntoContext(ctx, logger)
+
 	err := spindle.Run(ctx)
 	if err != nil {
-		log.FromContext(ctx).Error("error running spindle", "error", err)
+		logger.Error("error running spindle", "error", err)
 		os.Exit(-1)
 	}
 }
diff --git a/spindle/middleware.go b/spindle/middleware.go
new file mode 100644
index 00000000..42a831ab
--- /dev/null
+++ b/spindle/middleware.go
@@ -0,0 +1,35 @@
+package spindle
+
+import (
+	"log/slog"
+	"net/http"
+	"time"
+)
+
+func (s *Spindle) RequestLogger(next http.Handler) http.Handler {
+	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		start := time.Now()
+
+		next.ServeHTTP(w, r)
+
+		// Build query params as slog.Attrs for the group
+		queryParams := r.URL.Query()
+		queryAttrs := make([]any, 0, len(queryParams))
+		for key, values := range queryParams {
+			if len(values) == 1 {
+				queryAttrs = append(queryAttrs, slog.String(key, values[0]))
+			} else {
+				queryAttrs = append(queryAttrs, slog.Any(key, values))
+			}
+		}
+
+		s.l.LogAttrs(r.Context(), slog.LevelInfo, "",
+			slog.Group("request",
+				slog.String("method", r.Method),
+				slog.String("path", r.URL.Path),
+				slog.Group("query", queryAttrs...),
+				slog.Duration("duration", time.Since(start)),
+			),
+		)
+	})
+}
diff --git a/spindle/server.go b/spindle/server.go
index 72446bb9..1b989967 100644
--- a/spindle/server.go
+++ b/spindle/server.go
@@ -108,7 +108,7 @@ func Run(ctx context.Context) error {
 		tangled.RepoNSID,
 		tangled.RepoCollaboratorNSID,
 	}
-	jc, err := jetstream.NewJetstreamClient(cfg.Server.JetstreamEndpoint, "spindle", collections, nil, logger, d, true, true)
+	jc, err := jetstream.NewJetstreamClient(cfg.Server.JetstreamEndpoint, "spindle", collections, nil, log.SubLogger(logger, "jetstream"), d, true, true)
 	if err != nil {
 		return fmt.Errorf("failed to setup jetstream client: %w", err)
 	}
@@ -171,7 +171,7 @@ func Run(ctx context.Context) error {
 	// spindle.processPipeline, which in turn enqueues the pipeline
 	// job in the above registered queue.
 	ccfg := eventconsumer.NewConsumerConfig()
-	ccfg.Logger = logger
+	ccfg.Logger = log.SubLogger(logger, "eventconsumer")
 	ccfg.Dev = cfg.Server.Dev
 	ccfg.ProcessFunc = spindle.processPipeline
 	ccfg.CursorStore = cursorStore
@@ -210,12 +210,12 @@ func (s *Spindle) Router() http.Handler {
 }
 
 func (s *Spindle) XrpcRouter() http.Handler {
-	logger := s.l.With("route", "xrpc")
-
 	serviceAuth := serviceauth.NewServiceAuth(s.l, s.res, s.cfg.Server.Did().String())
 
+	l := log.SubLogger(s.l, "xrpc")
+
 	x := xrpc.Xrpc{
-		Logger:      logger,
+		Logger:      l,
 		Db:          s.db,
 		Enforcer:    s.e,
 		Engines:     s.engs,
@@ -305,7 +305,7 @@ func (s *Spindle) processPipeline(ctx context.Context, src eventconsumer.Source,
 
 		ok := s.jq.Enqueue(queue.Job{
 			Run: func() error {
-				engine.StartWorkflows(s.l, s.vault, s.cfg, s.db, s.n, ctx, &models.Pipeline{
+				engine.StartWorkflows(log.SubLogger(s.l, "engine"), s.vault, s.cfg, s.db, s.n, ctx, &models.Pipeline{
 					RepoOwner: tpl.TriggerMetadata.Repo.Did,
 					RepoName:  tpl.TriggerMetadata.Repo.Repo,
 					Workflows: workflows,
diff --git a/spindle/stream.go b/spindle/stream.go
index dd615926..dec76c5a 100644
--- a/spindle/stream.go
+++ b/spindle/stream.go
@@ -10,6 +10,7 @@ import (
 	"strconv"
 	"time"
 
+	"tangled.org/core/log"
 	"tangled.org/core/spindle/models"
 
 	"github.com/go-chi/chi/v5"
@@ -23,7 +24,8 @@ var upgrader = websocket.Upgrader{
 }
 
 func (s *Spindle) Events(w http.ResponseWriter, r *http.Request) {
-	l := s.l.With("handler", "Events")
+	l := log.SubLogger(s.l, "eventstream")
+
 	l.Debug("received new connection")
 
 	conn, err := upgrader.Upgrade(w, r, nil)
@@ -82,7 +84,6 @@ func (s *Spindle) Events(w http.ResponseWriter, r *http.Request) {
 			}
 		case <-time.After(30 * time.Second):
 			// send a keep-alive
-			l.Debug("sent keepalive")
 			if err = conn.WriteControl(websocket.PingMessage, []byte{}, time.Now().Add(time.Second)); err != nil {
 				l.Error("failed to write control", "err", err)
 			}
@@ -222,7 +223,6 @@ func (s *Spindle) streamPipelines(conn *websocket.Conn, cursor *int64) error {
 		s.l.Debug("err", "err", err)
 		return err
 	}
-	s.l.Debug("ops", "ops", events)
 
 	for _, event := range events {
 		// first extract the inner json into a map
-- 
2.43.0