spindle: improve the logging situation

Signed-off-by: oppiliappan <[e-mail]>

cmd/spindle/main.go

···
 
 	tlog "tangled.org/core/log"
 	"tangled.org/core/spindle"
-	_ "tangled.org/core/tid"
 )
 
 func main() {
-	logger := tlog.New("spindl3")
+	logger := tlog.New("spindle")
 	slog.SetDefault(logger)
 
 	ctx := context.Background()

spindle/middleware.go

···
+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)),
+			),
+		)
+	})
+}

spindle/server.go

···
 		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)
 	}
···
 	// 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
···
 }
 
 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,
···
 
 		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,

spindle/stream.go

···
 	"strconv"
 	"time"
 
+	"tangled.org/core/log"
 	"tangled.org/core/spindle/models"
 
 	"github.com/go-chi/chi/v5"
···
 }
 
 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)
···
 			}
 		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)
 			}
···
 		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