logging and middleware chaining

cmd/main.go

@@ -4,6 +4,7 @@ import (
 	"database/sql"
 	"log"
 	"net/http"
+	"os"
 
 	"gitea.michaelthomson.dev/mthomson/habits/internal/logging"
 	"gitea.michaelthomson.dev/mthomson/habits/internal/middleware"
@@ -22,16 +23,22 @@ func main() {
 	contextMiddleware := middleware.ContextMiddleware(logger)
 	loggingMiddleware := middleware.LoggingMiddleware(logger)
 
+	stack := []middleware.Middleware{
+		contextMiddleware,
+		loggingMiddleware,
+	}
+
 	// create db pool
 	postgresUrl := "postgres://todo:password@localhost:5432/todo"
 	db, err := sql.Open("pgx", postgresUrl)
 	if err != nil {
-		log.Fatalf("Failed to open db pool: %v", err)
+		logger.Error(err.Error())
+		os.Exit(1);
 	}
 	defer db.Close()
 
 	// run migrations
-	migrate.Migrate(db)
+	migrate.Migrate(logger, db)
 
 	// create repos
 	todoRepository := todorepository.NewPostgresTodoRepository(logger, db)
@@ -43,10 +50,10 @@ func main() {
 	mux := http.NewServeMux()
 
 	// register handlers
-	mux.Handle("GET /todo/{id}", contextMiddleware(loggingMiddleware(todohandler.HandleTodoGet(logger, todoService))))
+	mux.Handle("GET /todo/{id}", middleware.CompileMiddleware(todohandler.HandleTodoGet(logger, todoService), stack))
-	mux.Handle("POST /todo", contextMiddleware(loggingMiddleware(todohandler.HandleTodoCreate(logger, todoService))))
+	mux.Handle("POST /todo", middleware.CompileMiddleware(todohandler.HandleTodoCreate(logger, todoService), stack))
-	mux.Handle("DELETE /todo/{id}", contextMiddleware(loggingMiddleware(todohandler.HandleTodoDelete(logger, todoService))))
+	mux.Handle("DELETE /todo/{id}", middleware.CompileMiddleware(todohandler.HandleTodoDelete(logger, todoService), stack))
-	mux.Handle("PUT /todo/{id}", contextMiddleware(loggingMiddleware(todohandler.HandleTodoUpdate(logger, todoService))))
+	mux.Handle("PUT /todo/{id}", middleware.CompileMiddleware(todohandler.HandleTodoUpdate(logger, todoService), stack))
 
 	// create server
 	server := &http.Server{

flake.nix

@@ -36,6 +36,7 @@
 
             docker
             docker-compose
+			gopls
           ];
         };
       });

internal/logging/logging.go

@@ -4,6 +4,8 @@ import (
 	"context"
 	"log/slog"
 	"os"
+
+	"gitea.michaelthomson.dev/mthomson/habits/internal/middleware"
 )
 
 type ContextHandler struct {
@@ -11,8 +13,8 @@ type ContextHandler struct {
 }
 
 func (h *ContextHandler) Handle(ctx context.Context, r slog.Record) error {
-	if requestID, ok := ctx.Value("trace_id").(string); ok {
+	if requestID, ok := ctx.Value(middleware.TraceIdKey).(string); ok {
-		r.AddAttrs(slog.String("trace_id", requestID))
+		r.AddAttrs(slog.String(string(middleware.TraceIdKey), requestID))
 	}
 	return h.Handler.Handle(ctx, r)
 }

internal/middleware/context.go

@@ -8,11 +8,14 @@ import (
 	"github.com/google/uuid"
 )
 
+type contextKey string
+const TraceIdKey contextKey = "trace_id"
+
 func ContextMiddleware(logger *slog.Logger) func(http.Handler) http.Handler {
 	return func(next http.Handler) http.Handler {
 		return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 			traceid := uuid.NewString()
-			ctx := context.WithValue(r.Context(), "trace_id", traceid)
+			ctx := context.WithValue(r.Context(), TraceIdKey, traceid)
 			newReq := r.WithContext(ctx)
 
 			next.ServeHTTP(w, newReq)

internal/middleware/util.go

@@ -0,0 +1,19 @@
+package middleware
+
+import "net/http"
+
+type Middleware func(http.Handler) http.Handler
+
+func CompileMiddleware(h http.Handler, m []Middleware) http.Handler {
+	if len(m) < 1 {
+		return h
+	}
+
+	wrapped := h
+
+	for i := len(m) - 1; i >= 0; i-- {
+		wrapped = m[i](wrapped)
+	}
+
+	return wrapped
+}

internal/migrate/migrate.go

@@ -7,7 +7,7 @@ import (
 	"log"
 	"log/slog"
 
-	_ "github.com/mattn/go-sqlite3"
+	_ "github.com/jackc/pgx/v5/stdlib"
 )
 
 //go:embed migrations/*.sql
@@ -18,8 +18,8 @@ type Migration struct {
 	Name    string
 }
 
-func Migrate(db *sql.DB) {
+func Migrate(logger *slog.Logger, db *sql.DB) {
-	slog.Info("Running migrations...")
+	logger.Info("Running migrations...")
 	migrationTableSql := `
 	CREATE TABLE IF NOT EXISTS migrations(
 	  version SERIAL PRIMARY KEY,
@@ -41,7 +41,7 @@ func Migrate(db *sql.DB) {
 		row := db.QueryRow("SELECT * FROM migrations WHERE name = $1;", file.Name())
 		err = row.Scan(&migration.Version, &migration.Name)
 		if err == sql.ErrNoRows {
-			slog.Info(fmt.Sprintf("Running migration: %s", file.Name()))
+			logger.Info(fmt.Sprintf("Running migration: %s", file.Name()))
 			migrationSql, err := migrations.ReadFile(fmt.Sprintf("migrations/%s", file.Name()))
 			if err != nil {
 				log.Fatal(err)
@@ -58,5 +58,5 @@ func Migrate(db *sql.DB) {
 			}
 		}
 	}
-	slog.Info("Migrations completed")
+	logger.Info("Migrations completed")
 }

internal/test/test_database.go

@@ -0,0 +1,62 @@
+package test
+
+import (
+	"context"
+	"database/sql"
+	"log/slog"
+	"testing"
+	"time"
+
+	"gitea.michaelthomson.dev/mthomson/habits/internal/migrate"
+	"github.com/testcontainers/testcontainers-go"
+	"github.com/testcontainers/testcontainers-go/modules/postgres"
+	"github.com/testcontainers/testcontainers-go/wait"
+)
+
+type TestDatabase struct {
+	Db        *sql.DB
+	container testcontainers.Container
+}
+
+func NewTestDatabase(tb testing.TB) *TestDatabase {
+	tb.Helper()
+	ctx := context.Background()
+	// create container
+	postgresContainer, err := postgres.Run(ctx,
+		"postgres:16-alpine",
+		postgres.WithDatabase("todo"),
+		postgres.WithUsername("todo"),
+		postgres.WithPassword("password"),
+		testcontainers.WithWaitStrategy(
+			wait.ForLog("database system is ready to accept connections").
+				WithOccurrence(2).
+				WithStartupTimeout(5*time.Second)),
+	)
+
+	if err != nil {
+		tb.Fatalf("Failed to create postgres container, %v", err)
+	}
+
+	connectionString, err := postgresContainer.ConnectionString(ctx)
+	if err != nil {
+		tb.Fatalf("Failed to get connection string: %v", err)
+	}
+
+	// create db pool
+	db, err := sql.Open("pgx", connectionString)
+	if err != nil {
+		tb.Fatalf("Failed to open db pool: %v", err)
+	}
+
+	migrate.Migrate(slog.Default(), db)
+
+	return &TestDatabase{
+		Db:        db,
+		container: postgresContainer,
+	}
+}
+
+func (tdb *TestDatabase) TearDown() {
+	tdb.Db.Close()
+	_ = tdb.container.Terminate(context.Background())
+}

internal/todo/repository/postgres/postgres.go

@@ -1,6 +1,7 @@
 package postgres
 
 import (
+	"context"
 	"database/sql"
 	"log/slog"
 
@@ -19,7 +20,7 @@ func NewPostgresTodoRepository(logger *slog.Logger, db *sql.DB) *PostgresTodoRep
 	}
 }
 
-func (r *PostgresTodoRepository) GetById(id int64) (repository.TodoRow, error) {
+func (r *PostgresTodoRepository) GetById(ctx context.Context, id int64) (repository.TodoRow, error) {
 	todo := repository.TodoRow{}
 
 	err := r.db.QueryRow("SELECT * FROM todo WHERE id = $1;", id).Scan(&todo.Id, &todo.Name, &todo.Done)
@@ -29,33 +30,37 @@ func (r *PostgresTodoRepository) GetById(id int64) (repository.TodoRow, error) {
 			return todo, repository.ErrNotFound
 		}
 
+		r.logger.ErrorContext(ctx, err.Error())
 		return todo, err
 	}
 
 	return todo, nil
 }
 
-func (r *PostgresTodoRepository) Create(todo repository.TodoRow) (repository.TodoRow, error) {
+func (r *PostgresTodoRepository) Create(ctx context.Context, todo repository.TodoRow) (repository.TodoRow, error) {
 	result := r.db.QueryRow("INSERT INTO todo (name, done) VALUES ($1, $2) RETURNING id;", todo.Name, todo.Done)
 	err := result.Scan(&todo.Id)
 
 	if err != nil {
+		r.logger.ErrorContext(ctx, err.Error())
 		return repository.TodoRow{}, err
 	}
 
 	return todo, nil
 }
 
-func (r *PostgresTodoRepository) Update(todo repository.TodoRow) error {
+func (r *PostgresTodoRepository) Update(ctx context.Context, todo repository.TodoRow) error {
 	result, err := r.db.Exec("UPDATE todo SET name = $1, done = $2 WHERE id = $3;", todo.Name, todo.Done, todo.Id)
 
 	if err != nil {
+		r.logger.ErrorContext(ctx, err.Error())
 		return err
 	}
 
 	rowsAffected, err := result.RowsAffected()
 
 	if err != nil {
+		r.logger.ErrorContext(ctx, err.Error())
 		return err
 	}
 
@@ -66,16 +71,18 @@ func (r *PostgresTodoRepository) Update(todo repository.TodoRow) error {
 	return nil
 }
 
-func (r *PostgresTodoRepository) Delete(id int64) error {
+func (r *PostgresTodoRepository) Delete(ctx context.Context, id int64) error {
 	result, err := r.db.Exec("DELETE FROM todo WHERE id = $1;", id)
 
 	if err != nil {
+		r.logger.ErrorContext(ctx, err.Error())
 		return err
 	}
 
 	rowsAffected, err := result.RowsAffected()
 
 	if err != nil {
+		r.logger.ErrorContext(ctx, err.Error())
 		return err
 	}
 

internal/todo/repository/postgres/postgres_test.go

@@ -2,105 +2,53 @@ package postgres
 
 import (
 	"context"
-	"database/sql"
 	"errors"
 	"log/slog"
 	"testing"
-	"time"
 
-	"gitea.michaelthomson.dev/mthomson/habits/internal/migrate"
+	"gitea.michaelthomson.dev/mthomson/habits/internal/test"
 	"gitea.michaelthomson.dev/mthomson/habits/internal/todo/repository"
 	_ "github.com/jackc/pgx/v5/stdlib"
-	"github.com/testcontainers/testcontainers-go"
-	"github.com/testcontainers/testcontainers-go/modules/postgres"
-	"github.com/testcontainers/testcontainers-go/wait"
 )
 
-type TestDatabase struct {
-	Db        *sql.DB
-	container testcontainers.Container
-}
-
-func NewTestDatabase(tb testing.TB) *TestDatabase {
-	tb.Helper()
-	ctx := context.Background()
-	// create container
-	postgresContainer, err := postgres.Run(ctx,
-		"postgres:16-alpine",
-		postgres.WithDatabase("todo"),
-		postgres.WithUsername("todo"),
-		postgres.WithPassword("password"),
-		testcontainers.WithWaitStrategy(
-			wait.ForLog("database system is ready to accept connections").
-				WithOccurrence(2).
-				WithStartupTimeout(5*time.Second)),
-	)
-
-	if err != nil {
-		tb.Fatalf("Failed to create postgres container, %v", err)
-	}
-
-	connectionString, err := postgresContainer.ConnectionString(ctx)
-	if err != nil {
-		tb.Fatalf("Failed to get connection string: %v", err)
-	}
-
-	// create db pool
-	db, err := sql.Open("pgx", connectionString)
-	if err != nil {
-		tb.Fatalf("Failed to open db pool: %v", err)
-	}
-
-	migrate.Migrate(db)
-
-	return &TestDatabase{
-		Db:        db,
-		container: postgresContainer,
-	}
-}
-
-func (tdb *TestDatabase) TearDown() {
-	tdb.Db.Close()
-	_ = tdb.container.Terminate(context.Background())
-}
-
 func TestCRUD(t *testing.T) {
+	ctx := context.Background()
 	logger := slog.Default()
-	tdb := NewTestDatabase(t)
+	tdb := test.NewTestDatabase(t)
 	defer tdb.TearDown()
 	r := NewPostgresTodoRepository(logger, tdb.Db)
 
 	t.Run("creates new todo", func(t *testing.T) {
 		want := repository.TodoRow{Id: 1, Name: "clean dishes", Done: false}
 		newTodo := repository.TodoRow{Name: "clean dishes", Done: false}
-		got, err := r.Create(newTodo)
+		got, err := r.Create(ctx, newTodo)
 		AssertNoError(t, err)
 		AssertTodoRows(t, got, want)
 	})
 
 	t.Run("gets todo", func(t *testing.T) {
 		want := repository.TodoRow{Id: 1, Name: "clean dishes", Done: false}
-		got, err := r.GetById(1)
+		got, err := r.GetById(ctx, 1)
 		AssertNoError(t, err)
 		AssertTodoRows(t, got, want)
 	})
 
 	t.Run("updates todo", func(t *testing.T) {
 		want := repository.TodoRow{Id: 1, Name: "clean dishes", Done: true}
-		err := r.Update(want)
+		err := r.Update(ctx, want)
 		AssertNoError(t, err)
 
-		got, err := r.GetById(1)
+		got, err := r.GetById(ctx, 1)
 		AssertNoError(t, err)
 		AssertTodoRows(t, got, want)
 	})
 
 	t.Run("deletes todo", func(t *testing.T) {
-		err := r.Delete(1)
+		err := r.Delete(ctx, 1)
 		AssertNoError(t, err)
 
 		want := repository.ErrNotFound
-		_, got := r.GetById(1)
+		_, got := r.GetById(ctx, 1)
 
 		AssertErrors(t, got, want)
 	})

internal/todo/service/service.go

@@ -35,10 +35,10 @@ func (t Todo) Equal(todo Todo) bool {
 }
 
 type TodoRepository interface {
-	Create(todo repository.TodoRow) (repository.TodoRow, error)
+	Create(ctx context.Context, todo repository.TodoRow) (repository.TodoRow, error)
-	GetById(id int64) (repository.TodoRow, error)
+	GetById(ctx context.Context, id int64) (repository.TodoRow, error)
-	Update(todo repository.TodoRow) error
+	Update(ctx context.Context, todo repository.TodoRow) error
-	Delete(id int64) error
+	Delete(ctx context.Context, id int64) error
 }
 
 type TodoService struct {
@@ -54,7 +54,7 @@ func NewTodoService(logger *slog.Logger, todoRepo TodoRepository) *TodoService {
 }
 
 func (s *TodoService) GetTodo(ctx context.Context, id int64) (Todo, error) {
-	todo, err := s.repo.GetById(id)
+	todo, err := s.repo.GetById(ctx, id)
 
 	if err != nil {
 		if err == repository.ErrNotFound {
@@ -71,7 +71,7 @@ func (s *TodoService) GetTodo(ctx context.Context, id int64) (Todo, error) {
 func (s *TodoService) CreateTodo(ctx context.Context, todo Todo) (Todo, error) {
 	todoRow := TodoRowFromTodo(todo)
 
-	newTodoRow, err := s.repo.Create(todoRow)
+	newTodoRow, err := s.repo.Create(ctx, todoRow)
 
 	if err != nil {
 		s.logger.ErrorContext(ctx, err.Error())
@@ -82,7 +82,7 @@ func (s *TodoService) CreateTodo(ctx context.Context, todo Todo) (Todo, error) {
 }
 
 func (s *TodoService) DeleteTodo(ctx context.Context, id int64) error {
-	err := s.repo.Delete(id)
+	err := s.repo.Delete(ctx, id)
 
 	if err == repository.ErrNotFound {
 		return ErrNotFound
@@ -98,7 +98,7 @@ func (s *TodoService) DeleteTodo(ctx context.Context, id int64) error {
 func (s *TodoService) UpdateTodo(ctx context.Context, todo Todo) error {
 	todoRow := TodoRowFromTodo(todo)
 
-	err := s.repo.Update(todoRow)
+	err := s.repo.Update(ctx, todoRow)
 
 	if err == repository.ErrNotFound {
 		return ErrNotFound

internal/todo/service/service_test.go

@@ -5,18 +5,22 @@ import (
 	"log/slog"
 	"testing"
 
+	"gitea.michaelthomson.dev/mthomson/habits/internal/test"
 	"gitea.michaelthomson.dev/mthomson/habits/internal/todo/repository"
-	"gitea.michaelthomson.dev/mthomson/habits/internal/todo/repository/inmemory"
+	"gitea.michaelthomson.dev/mthomson/habits/internal/todo/repository/postgres"
 	"gitea.michaelthomson.dev/mthomson/habits/internal/todo/service"
+	_ "github.com/jackc/pgx/v5/stdlib"
 )
 
 func TestCreateTodo(t *testing.T) {
+	t.Parallel()
 	ctx := context.Background()
 	logger := slog.Default()
+	tdb := test.NewTestDatabase(t)
+	defer tdb.TearDown()
+	r := postgres.NewPostgresTodoRepository(logger, tdb.Db)
 
-	todoRepository := inmemory.NewInMemoryTodoRepository()
+	todoService := service.NewTodoService(logger, r)
-
-	todoService := service.NewTodoService(logger, &todoRepository)
 
 	t.Run("Create todo", func(t *testing.T) {
 		todo := service.NewTodo("clean dishes", false)
@@ -28,13 +32,18 @@ func TestCreateTodo(t *testing.T) {
 }
 
 func TestGetTodo(t *testing.T) {
+	t.Parallel()
 	ctx := context.Background()
 	logger := slog.Default()
-	todoRepository := inmemory.NewInMemoryTodoRepository()
+	tdb := test.NewTestDatabase(t)
+	defer tdb.TearDown()
+	r := postgres.NewPostgresTodoRepository(logger, tdb.Db)
 
-	todoRepository.Db[1] = repository.TodoRow{Id: 1, Name: "clean dishes", Done: false}
+	row := repository.TodoRow{Id: 1, Name: "clean dishes", Done: false}
+	_, err := r.Create(ctx, row)
+	AssertNoError(t, err);
 
-	todoService := service.NewTodoService(logger, &todoRepository)
+	todoService := service.NewTodoService(logger, r)
 
 	t.Run("Get exisiting todo", func(t *testing.T) {
 		_, err := todoService.GetTodo(ctx, 1)
@@ -50,13 +59,18 @@ func TestGetTodo(t *testing.T) {
 }
 
 func TestDeleteTodo(t *testing.T) {
+	t.Parallel()
 	ctx := context.Background()
 	logger := slog.Default()
-	todoRepository := inmemory.NewInMemoryTodoRepository()
+	tdb := test.NewTestDatabase(t)
+	defer tdb.TearDown()
+	r := postgres.NewPostgresTodoRepository(logger, tdb.Db)
 
-	todoRepository.Db[1] = repository.TodoRow{Id: 1, Name: "clean dishes", Done: false}
+	row := repository.TodoRow{Id: 1, Name: "clean dishes", Done: false}
+	_, err := r.Create(ctx, row)
+	AssertNoError(t, err);
 
-	todoService := service.NewTodoService(logger, &todoRepository)
+	todoService := service.NewTodoService(logger, r)
 
 	t.Run("Delete exisiting todo", func(t *testing.T) {
 		err := todoService.DeleteTodo(ctx, 1)
@@ -72,13 +86,18 @@ func TestDeleteTodo(t *testing.T) {
 }
 
 func TestUpdateTodo(t *testing.T) {
+	t.Parallel()
 	ctx := context.Background()
 	logger := slog.Default()
-	todoRepository := inmemory.NewInMemoryTodoRepository()
+	tdb := test.NewTestDatabase(t)
+	defer tdb.TearDown()
+	r := postgres.NewPostgresTodoRepository(logger, tdb.Db)
 
-	todoRepository.Db[1] = repository.TodoRow{Id: 1, Name: "clean dishes", Done: false}
+	row := repository.TodoRow{Id: 1, Name: "clean dishes", Done: false}
+	_, err := r.Create(ctx, row)
+	AssertNoError(t, err);
 
-	todoService := service.NewTodoService(logger, &todoRepository)
+	todoService := service.NewTodoService(logger, r)
 
 	t.Run("Update exisiting todo", func(t *testing.T) {
 		todo := service.Todo{1, "clean dishes", true}