refactor: adopt slog for structured logging

This commit is contained in:
Ruidy 2025-09-20 14:13:54 +02:00
parent b0399f4109
commit 38b8fa49dc
No known key found for this signature in database
GPG key ID: 705C24D202990805
10 changed files with 174 additions and 23 deletions

View file

@ -37,3 +37,6 @@
- Use `net/http/httptest` to verify happy-path login, signup, logout, invalid credential handling, CSRF failures, and session persistence. - Use `net/http/httptest` to verify happy-path login, signup, logout, invalid credential handling, CSRF failures, and session persistence.
- Run `go test -cover ./...` to ensure the new logic maintains regression coverage. - Run `go test -cover ./...` to ensure the new logic maintains regression coverage.
- Flesh out dedicated service tests for lookup flows and extend dashboard coverage once integration scaffolding is available. - Flesh out dedicated service tests for lookup flows and extend dashboard coverage once integration scaffolding is available.
- Add structured logging: text encoder for development, JSON for production deployments.
- Consolidate templates with a base layout to remove duplication across pages.
- Introduce configuration loading that sources environment variables, validates them, and exposes typed settings at startup.

View file

@ -2,27 +2,34 @@ package main
import ( import (
"fmt" "fmt"
"log" "log/slog"
"net/http" "net/http"
"os"
"github.com/rjnemo/auth/internal/logging"
"github.com/rjnemo/auth/internal/server" "github.com/rjnemo/auth/internal/server"
"gorm.io/gorm/logger"
) )
const listenAddr = ":8000"
func main() { func main() {
if err := run(); err != nil { if err := run(logger); err != nil {
log.Fatalf("run: %v", err) logger.Error("server exited", slog.Any("error", err))
os.Exit(1)
} }
} }
func run() error { func run() error {
srv, err := server.New() logger := logging.New(os.Stdout, logging.ModeText, &slog.HandlerOptions{AddSource: true})
srv, err := server.New(logger)
if err != nil { if err != nil {
return fmt.Errorf("initialise server: %v", err) return fmt.Errorf("initialise server: %w", err)
} }
log.Println("Starting server on http://localhost:8000") logger.Info("starting server", slog.String("addr", listenAddr))
if err := http.ListenAndServe(":8000", srv.Router()); err != nil { if err := http.ListenAndServe(listenAddr, srv.Router()); err != nil {
return fmt.Errorf("listen: %v", err) return fmt.Errorf("listen: %w", err)
} }
return nil return nil

View file

@ -0,0 +1,46 @@
package logging
import (
"io"
"log/slog"
"strings"
)
// Mode selects the output format for structured logs.
type Mode string
const (
// ModeText renders human-friendly key/value lines for development.
ModeText Mode = "text"
// ModeJSON emits JSON objects suited for production ingestion.
ModeJSON Mode = "json"
)
// ParseMode canonicalises textual representations of the logging mode.
func ParseMode(value string) Mode {
switch strings.ToLower(strings.TrimSpace(value)) {
case string(ModeJSON):
return ModeJSON
default:
return ModeText
}
}
// New constructs a slog.Logger with the desired mode and handler options.
func New(out io.Writer, mode Mode, opts *slog.HandlerOptions) *slog.Logger {
if out == nil {
out = io.Discard
}
if opts == nil {
opts = &slog.HandlerOptions{}
}
var handler slog.Handler
if mode == ModeJSON {
handler = slog.NewJSONHandler(out, opts)
} else {
handler = slog.NewTextHandler(out, opts)
}
return slog.New(handler)
}

View file

@ -0,0 +1,77 @@
package logging
import (
"bytes"
"encoding/json"
"log/slog"
"strings"
"testing"
)
func TestParseMode(t *testing.T) {
t.Parallel()
cases := map[string]Mode{
"": ModeText,
"text": ModeText,
"TEXT": ModeText,
"json": ModeJSON,
" json ": ModeJSON,
"unknown": ModeText,
}
for input, want := range cases {
if got := ParseMode(input); got != want {
t.Fatalf("ParseMode(%q) = %q, want %q", input, got, want)
}
}
}
func TestNewTextLogger(t *testing.T) {
var buf bytes.Buffer
opts := &slog.HandlerOptions{ReplaceAttr: dropTime}
logger := New(&buf, ModeText, opts)
logger.Info("server start", slog.String("component", "http"))
output := strings.TrimSpace(buf.String())
if !strings.Contains(output, "level=INFO") || !strings.Contains(output, "component=http") {
t.Fatalf("unexpected text output: %s", output)
}
if strings.Contains(output, slog.TimeKey) {
t.Fatalf("expected time attribute to be stripped: %s", output)
}
}
func TestNewJSONLogger(t *testing.T) {
var buf bytes.Buffer
opts := &slog.HandlerOptions{ReplaceAttr: dropTime}
logger := New(&buf, ModeJSON, opts)
logger.Error("save failed", slog.String("component", "auth"))
var payload map[string]any
if err := json.Unmarshal(buf.Bytes(), &payload); err != nil {
t.Fatalf("failed to decode json log: %v", err)
}
if payload["msg"] != "save failed" {
t.Fatalf("unexpected message: %v", payload["msg"])
}
if payload["component"] != "auth" {
t.Fatalf("unexpected component: %v", payload["component"])
}
if payload["level"] != "ERROR" {
t.Fatalf("unexpected level: %v", payload["level"])
}
if _, ok := payload[slog.TimeKey]; ok {
t.Fatalf("expected time key to be stripped")
}
}
func dropTime(_ []string, attr slog.Attr) slog.Attr {
if attr.Key == slog.TimeKey {
return slog.Attr{}
}
return attr
}

View file

@ -1,7 +1,7 @@
package server package server
import ( import (
"log" "log/slog"
"net/http" "net/http"
"time" "time"
@ -12,6 +12,7 @@ const dashboardTimeDisplayLayout = "02 Jan 2006 15:04 MST"
func (s *Server) dashboardPageHandler() http.HandlerFunc { func (s *Server) dashboardPageHandler() http.HandlerFunc {
return func(w http.ResponseWriter, r *http.Request) { return func(w http.ResponseWriter, r *http.Request) {
logger := s.logger.With(slog.String("component", "dashboard"))
state := sessionFromContext(r.Context()) state := sessionFromContext(r.Context())
if !state.Authenticated { if !state.Authenticated {
@ -22,14 +23,14 @@ func (s *Server) dashboardPageHandler() http.HandlerFunc {
email, err := auth.NewUserEmail(state.Email) email, err := auth.NewUserEmail(state.Email)
if err != nil { if err != nil {
log.Printf("dashboard: invalid session email: %v", err) logger.Warn("invalid session email", slog.Any("error", err))
http.Error(w, "session invalid", http.StatusUnauthorized) http.Error(w, "session invalid", http.StatusUnauthorized)
return return
} }
account, err := s.authService.LookupByEmail(r.Context(), email) account, err := s.authService.LookupByEmail(r.Context(), email)
if err != nil { if err != nil {
log.Printf("dashboard: lookup failed: %v", err) logger.Error("lookup failed", slog.Any("error", err))
http.Error(w, "unable to load account", http.StatusInternalServerError) http.Error(w, "unable to load account", http.StatusInternalServerError)
return return
} }

View file

@ -2,7 +2,7 @@ package server
import ( import (
"errors" "errors"
"log" "log/slog"
"net/http" "net/http"
"github.com/rjnemo/auth/internal/service/auth" "github.com/rjnemo/auth/internal/service/auth"
@ -21,6 +21,7 @@ func (s *Server) loginPageHandler() http.HandlerFunc {
func (s *Server) loginHandler() http.HandlerFunc { func (s *Server) loginHandler() http.HandlerFunc {
return func(w http.ResponseWriter, r *http.Request) { return func(w http.ResponseWriter, r *http.Request) {
logger := s.logger.With(slog.String("component", "login"))
state := sessionFromContext(r.Context()) state := sessionFromContext(r.Context())
if err := r.ParseForm(); err != nil { if err := r.ParseForm(); err != nil {
@ -44,7 +45,7 @@ func (s *Server) loginHandler() http.HandlerFunc {
state.Authenticated = true state.Authenticated = true
state.Email = account.Email.String() state.Email = account.Email.String()
if err := s.sessions.Save(w, state); err != nil { if err := s.sessions.Save(w, state); err != nil {
log.Printf("session: save failed: %v", err) logger.Warn("session save failed", slog.Any("error", err))
} }
http.Redirect(w, r, "/dashboard", http.StatusSeeOther) http.Redirect(w, r, "/dashboard", http.StatusSeeOther)
@ -57,7 +58,7 @@ func (s *Server) loginHandler() http.HandlerFunc {
case errors.Is(err, auth.ErrInvalidCredentials): case errors.Is(err, auth.ErrInvalidCredentials):
s.renderLoginFailure(w, email, state.CSRFToken) s.renderLoginFailure(w, email, state.CSRFToken)
default: default:
log.Printf("auth: authenticate failed: %v", err) logger.Error("authenticate failed", slog.Any("error", err))
http.Error(w, "unexpected error", http.StatusInternalServerError) http.Error(w, "unexpected error", http.StatusInternalServerError)
} }
} }

View file

@ -2,7 +2,7 @@ package server
import ( import (
"errors" "errors"
"log" "log/slog"
"net/http" "net/http"
"github.com/rjnemo/auth/internal/service/auth" "github.com/rjnemo/auth/internal/service/auth"
@ -30,6 +30,7 @@ func (s *Server) signupPageHandler() http.HandlerFunc {
func (s *Server) signupHandler() http.HandlerFunc { func (s *Server) signupHandler() http.HandlerFunc {
return func(w http.ResponseWriter, r *http.Request) { return func(w http.ResponseWriter, r *http.Request) {
logger := s.logger.With(slog.String("component", "signup"))
state := sessionFromContext(r.Context()) state := sessionFromContext(r.Context())
if err := r.ParseForm(); err != nil { if err := r.ParseForm(); err != nil {
@ -53,7 +54,7 @@ func (s *Server) signupHandler() http.HandlerFunc {
state.Authenticated = true state.Authenticated = true
state.Email = account.Email.String() state.Email = account.Email.String()
if err := s.sessions.Save(w, state); err != nil { if err := s.sessions.Save(w, state); err != nil {
log.Printf("session: save failed: %v", err) logger.Warn("session save failed", slog.Any("error", err))
} }
http.Redirect(w, r, "/dashboard", http.StatusSeeOther) http.Redirect(w, r, "/dashboard", http.StatusSeeOther)
case errors.Is(err, auth.ErrWeakPassword): case errors.Is(err, auth.ErrWeakPassword):
@ -66,7 +67,7 @@ func (s *Server) signupHandler() http.HandlerFunc {
w.WriteHeader(http.StatusConflict) w.WriteHeader(http.StatusConflict)
s.render(w, "signup.html", newSignupData(email.String(), duplicateEmailMsg, state.CSRFToken)) s.render(w, "signup.html", newSignupData(email.String(), duplicateEmailMsg, state.CSRFToken))
default: default:
log.Printf("auth: register failed: %v", err) logger.Error("register failed", slog.Any("error", err))
http.Error(w, "unexpected error", http.StatusInternalServerError) http.Error(w, "unexpected error", http.StatusInternalServerError)
} }
} }

View file

@ -3,7 +3,7 @@ package server
import ( import (
"context" "context"
"crypto/subtle" "crypto/subtle"
"log" "log/slog"
"net/http" "net/http"
) )
@ -11,17 +11,19 @@ type sessionContextKey struct{}
func (s *Server) sessionMiddleware(next http.Handler) http.Handler { func (s *Server) sessionMiddleware(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
logger := s.logger.With(slog.String("component", "session"))
state := s.sessions.Load(r) state := s.sessions.Load(r)
updated, err := ensureCSRFToken(state) updated, err := ensureCSRFToken(state)
if err != nil { if err != nil {
log.Printf("session: csrf token generation failed: %v", err) logger.Error("csrf token generation failed", slog.Any("error", err))
http.Error(w, "session error", http.StatusInternalServerError) http.Error(w, "session error", http.StatusInternalServerError)
return return
} }
state = updated state = updated
if err := s.sessions.Save(w, state); err != nil { if err := s.sessions.Save(w, state); err != nil {
log.Printf("session: save failed: %v", err) logger.Warn("session save failed", slog.Any("error", err))
} }
ctx := withSession(r.Context(), state) ctx := withSession(r.Context(), state)

View file

@ -5,8 +5,11 @@ import (
"crypto/rand" "crypto/rand"
"fmt" "fmt"
"html/template" "html/template"
"io"
"log/slog"
"time" "time"
"github.com/rjnemo/auth/internal/logging"
"github.com/rjnemo/auth/internal/service/auth" "github.com/rjnemo/auth/internal/service/auth"
"github.com/rjnemo/auth/web" "github.com/rjnemo/auth/web"
) )
@ -21,10 +24,11 @@ type Server struct {
templates *template.Template templates *template.Template
authService *auth.Service authService *auth.Service
sessions *SessionStore sessions *SessionStore
logger *slog.Logger
} }
// New constructs a Server with parsed templates and default state. // New constructs a Server with parsed templates and default state.
func New() (*Server, error) { func New(logger *slog.Logger) (*Server, error) {
tmpl, err := template.ParseFS( tmpl, err := template.ParseFS(
web.Templates, web.Templates,
"templates/login.html", "templates/login.html",
@ -51,10 +55,16 @@ func New() (*Server, error) {
return nil, fmt.Errorf("session store: %w", err) return nil, fmt.Errorf("session store: %w", err)
} }
if logger == nil {
logger = logging.New(io.Discard, logging.ModeText, nil)
}
logger = logger.With(slog.String("service", "http"))
return &Server{ return &Server{
templates: tmpl, templates: tmpl,
authService: auth.NewService(store), authService: auth.NewService(store),
sessions: sessionStore, sessions: sessionStore,
logger: logger,
}, nil }, nil
} }

View file

@ -1,13 +1,16 @@
package server package server
import ( import (
"log" "log/slog"
"net/http" "net/http"
) )
func (s *Server) render(w http.ResponseWriter, name string, data any) { func (s *Server) render(w http.ResponseWriter, name string, data any) {
if err := s.templates.ExecuteTemplate(w, name, data); err != nil { if err := s.templates.ExecuteTemplate(w, name, data); err != nil {
log.Printf("render %s: %v", name, err) s.logger.With(
slog.String("component", "templates"),
slog.String("template", name),
).Error("render failed", slog.Any("error", err))
http.Error(w, "template render failed", http.StatusInternalServerError) http.Error(w, "template render failed", http.StatusInternalServerError)
} }
} }