installed logger

go.mod

@@ -10,6 +10,7 @@ require (
 	github.com/angelbeltran/templater v0.1.0
 	github.com/coreos/go-oidc/v3 v3.8.0
 	github.com/google/uuid v1.5.0
+	github.com/lmittmann/tint v1.1.2
 	github.com/oapi-codegen/runtime v1.1.2
 	golang.org/x/oauth2 v0.15.0
 )

go.sum

@@ -89,6 +89,8 @@ github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY=
 github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE=
 github.com/lib/pq v1.10.9 h1:YXG7RB+JIjhP29X+OtkiDnYaXQwpS4JEWq7dtCCRUEw=
 github.com/lib/pq v1.10.9/go.mod h1:AlVN5x4E4T544tWzH6hKfbfQvm3HdbOxrmggDNAPY9o=
+github.com/lmittmann/tint v1.1.2 h1:2CQzrL6rslrsyjqLDwD11bZ5OpLBPU+g3G/r5LSfS8w=
+github.com/lmittmann/tint v1.1.2/go.mod h1:HIS3gSy7qNwGCj+5oRjAutErFBl4BzdQP6cJZ0NfMwE=
 github.com/mailru/easyjson v0.7.7 h1:UGYAvKxe3sBsEDzO8ZeWOSlIQfWFlxbzLZe7hwFURr0=
 github.com/mailru/easyjson v0.7.7/go.mod h1:xzfreul335JAWq5oZzymOObrkdz5UnU4kGfJJLY9Nlc=
 github.com/mohae/deepcopy v0.0.0-20170929034955-c48cc78d4826 h1:RWengNIwukTxcDr9M+97sNutRR1RKhG96O6jWumTTnw=

internal/server/response/body.go

@@ -59,12 +59,12 @@ func (b bodyRes) Cookie(ck http.Cookie) Response {
 	return Cookie(ck).wrap(b)
 }
 
-func (b bodyRes) getStatus() (int, bool) {
+func (b bodyRes) GetStatus() (int, bool) {
 	if b.res == nil {
 		return 0, false
 	}
 
-	return b.res.getStatus()
+	return b.res.GetStatus()
 }
 
 func (b bodyRes) getRedirect() (code redirect.Code, to string, ok bool) {

internal/server/response/cookie.go

@@ -58,12 +58,12 @@ func (c cookieRes) Cookie(ck http.Cookie) Response {
 	return Cookie(ck).wrap(c)
 }
 
-func (c cookieRes) getStatus() (int, bool) {
+func (c cookieRes) GetStatus() (int, bool) {
 	if c.res == nil {
 		return 0, false
 	}
 
-	return c.res.getStatus()
+	return c.res.GetStatus()
 }
 
 func (c cookieRes) getRedirect() (code redirect.Code, to string, ok bool) {

internal/server/response/html.go

@@ -60,12 +60,12 @@ func (h htmlRes) Cookie(ck http.Cookie) Response {
 	return Cookie(ck).wrap(h)
 }
 
-func (h htmlRes) getStatus() (int, bool) {
+func (h htmlRes) GetStatus() (int, bool) {
 	if h.res == nil {
 		return 0, false
 	}
 
-	return h.res.getStatus()
+	return h.res.GetStatus()
 }
 
 func (h htmlRes) getRedirect() (code redirect.Code, to string, ok bool) {

internal/server/response/json.go

@@ -61,12 +61,12 @@ func (j jsonRes) Cookie(ck http.Cookie) Response {
 	return Cookie(ck).wrap(j)
 }
 
-func (j jsonRes) getStatus() (int, bool) {
+func (j jsonRes) GetStatus() (int, bool) {
 	if j.res == nil {
 		return 0, false
 	}
 
-	return j.res.getStatus()
+	return j.res.GetStatus()
 }
 
 func (j jsonRes) getRedirect() (code redirect.Code, to string, ok bool) {

internal/server/response/redirect.go

@@ -99,12 +99,12 @@ func (r redirectRes) Cookie(ck http.Cookie) Response {
 	return Cookie(ck).wrap(r)
 }
 
-func (r redirectRes) getStatus() (int, bool) {
+func (r redirectRes) GetStatus() (int, bool) {
 	if r.res == nil {
 		return 0, false
 	}
 
-	return r.res.getStatus()
+	return r.res.GetStatus()
 }
 
 func (r redirectRes) getRedirect() (code redirect.Code, to string, ok bool) {

internal/server/response/response.go

@@ -16,7 +16,7 @@ type (
 		JSON(any) Response
 		Cookie(http.Cookie) Response
 
-		getStatus() (code int, ok bool)
+		GetStatus() (code int, ok bool)
 		getBody() (body io.ReadCloser, ok bool, err error)
 		getRedirect() (code redirect.Code, to string, ok bool)
 		getCookies() []http.Cookie

internal/server/response/status.go

@@ -60,7 +60,7 @@ func (s statusRes) Cookie(ck http.Cookie) Response {
 	return Cookie(ck).wrap(s)
 }
 
-func (s statusRes) getStatus() (int, bool) {
+func (s statusRes) GetStatus() (int, bool) {
 	return s.code, true
 }
 

internal/server/response/write.go

@@ -36,7 +36,7 @@ func Write(w http.ResponseWriter, r *http.Request, res Response) {
 		return
 	}
 
-	if status, ok := res.getStatus(); ok {
+	if status, ok := res.GetStatus(); ok {
 		w.WriteHeader(status)
 	}
 	if bodySet {

internal/server/server.go

@@ -1,6 +1,7 @@
 package server
 
 import (
+	"context"
 	"encoding/json"
 	"fmt"
 	"html/template"
@@ -9,6 +10,7 @@ import (
 	"path"
 	"strconv"
 	"strings"
+	"time"
 
 	"github.com/angelbeltran/templater"
 
@@ -36,6 +38,7 @@ type Server struct {
 }
 
 func NewServer(
+	ctx context.Context,
 	logger *slog.Logger,
 	contentDir string,
 	rawEvents *raw_events.Store,
@@ -43,14 +46,49 @@ func NewServer(
 	etsy *etsy_platform.Platform,
 	auth *authentication.Authenticator,
 ) *Server {
+	reqIDCh := newRequestIDProvider(ctx)
+
+	reqLog := logger.WithGroup("request")
 	mux := response.NewMux(func(fn response.HandlerFunc) response.HandlerFunc {
 		return func(r *http.Request) (response.Response, error) {
-			res, err := fn(r)
+			start := time.Now()
-			if err != nil {
-				status := response.GetStatusFromError(err)
 
-				// TODO: get better logger
+			args := []any{
-				fmt.Printf("[ERROR]: %d: %s; %s\n", status, r.URL, err)
+				"id", <-reqIDCh,
+				"url", r.URL,
+			}
+
+			reqLog.Debug("Request", args...)
+
+			res, err := fn(r)
+			end := time.Now()
+
+			var status int
+			if err != nil {
+				status = response.GetStatusFromError(err)
+			} else {
+				var ok bool
+				if status, ok = res.GetStatus(); !ok {
+					status = http.StatusOK
+				}
+			}
+
+			args = append(args,
+				"status", status,
+				"elapsed", time.Duration(end.UnixNano()-start.UnixNano()),
+			)
+
+			switch status / 100 {
+			case 1:
+				reqLog.Debug("Response", args...)
+			case 2:
+				reqLog.Debug("Response", args...)
+			case 3:
+				reqLog.Debug("Response", args...)
+			case 4:
+				reqLog.Warn("Response", args...)
+			default:
+				reqLog.Error("Response", args...)
 			}
 
 			return res, err
@@ -223,3 +261,24 @@ func mapConstantErrorsToHTTPErrors(err error) error {
 	}
 	return err
 }
+
+func newRequestIDProvider(ctx context.Context) <-chan int {
+	reqIDCh := make(chan int)
+
+	go func() {
+		defer close(reqIDCh)
+
+		nextReqID := 1
+
+		for {
+			select {
+			case reqIDCh <- nextReqID:
+				nextReqID += 1
+			case <-ctx.Done():
+				return
+			}
+		}
+	}()
+
+	return reqIDCh
+}

main.go

@@ -13,10 +13,12 @@ import (
 	"net/http"
 	"os"
 	"os/signal"
+	"strings"
 	"syscall"
 	"time"
 
 	"github.com/jackc/pgx/v5/pgxpool"
+	"github.com/lmittmann/tint"
 
 	"ruben/inventory2/internal/domains/accounts"
 	"ruben/inventory2/internal/domains/authentication"
@@ -31,27 +33,36 @@ const (
 )
 
 func main() {
-	if err := runApp(context.Background()); err != nil {
+	logger := slog.New(tint.NewHandler(os.Stderr, &tint.Options{
-		panic(err)
-	}
-	fmt.Println("application shutdown")
-}
-
-func runApp(ctx context.Context) error {
-	ctx, shutdown := context.WithCancel(ctx)
-	defer shutdown()
-
-	logger := slog.New(slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{
 		AddSource: true,
 		Level:     slog.LevelDebug,
 		ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
-			fmt.Println("slog groups:", groups)
+			// this can perform general key=value log cleanup
-			fmt.Println("slog attr:", a)
+
-			// TODO: not sure if this will be needed, but keep around until known.
+			if a.Key == slog.SourceKey && len(groups) == 0 {
+				source := a.Value.Any().(*slog.Source)
+				source.File = strings.TrimPrefix(source.File, "/home/angel/go/src/ruben/inventory2/internal")
+			}
+
 			return a
 		},
+		// Time format (Default: time.StampMilli)
+		//TimeFormat: "",
 	}))
 
+	logger.Info("application starting")
+
+	if err := runApp(context.Background(), logger); err != nil {
+		panic(err)
+	}
+
+	logger.Info("application shutdown")
+}
+
+func runApp(ctx context.Context, logger *slog.Logger) error {
+	ctx, shutdown := context.WithCancel(ctx)
+	defer shutdown()
+
 	// connect to the database
 
 	connPool, err := newPool(ctx)
@@ -61,7 +72,7 @@ func runApp(ctx context.Context) error {
 
 	// start background processes
 
-	auth, err := authentication.New(ctx, connPool, logger.WithGroup("*authentication.Authenticator"))
+	auth, err := authentication.New(ctx, connPool, logger.WithGroup("authenticator"))
 	if err != nil {
 		return fmt.Errorf("failed to construct authenticator: %w", err)
 	}
@@ -85,19 +96,19 @@ func runApp(ctx context.Context) error {
 	)
 	select {
 	case s := <-osSignalCh:
-		fmt.Println("application received shutdown signal:", s)
+		logger.Info("application received shutdown signal", "signal", s)
-		fmt.Println("shutting down")
+		logger.Info("shutting down")
 	case err := <-authErrCh:
 		alreadyShutdown.authProcesses = true
-		fmt.Println("auth processes shutdown unexpectedly")
+		logger.Error("auth processes shutdown unexpectedly")
 		if err != nil {
-			fmt.Println("auth processes encountered error:", err)
+			logger.Error("auth processes encountered error", "error", err)
 		}
 	case err := <-srvErrCh:
 		alreadyShutdown.server = true
-		fmt.Println("server shutdown unexpectedly")
+		logger.Error("server shutdown unexpectedly")
 		if err != nil {
-			fmt.Println("server encountered error:", err)
+			logger.Error("server encountered error", "error", err)
 		}
 	}
 
@@ -111,14 +122,14 @@ func runApp(ctx context.Context) error {
 		if err := <-authErrCh; err != nil {
 			errs = append(errs, fmt.Errorf("auth processes experienced an error: %w", err))
 		}
-		fmt.Println("auth processes shut down")
+		logger.Info("auth processes shut down")
 	}
 
 	if !alreadyShutdown.server {
 		if err := <-srvErrCh; err != nil {
 			errs = append(errs, fmt.Errorf("server experienced an error: %w", err))
 		}
-		fmt.Println("server shut down")
+		logger.Info("server shut down")
 	}
 
 	return errors.Join(errs...)
@@ -141,6 +152,7 @@ func runServer(ctx context.Context, logger *slog.Logger, connPool *pgxpool.Pool,
 	srv := &http.Server{
 		Addr: ":8082", // local
 		Handler: server.NewServer(
+			ctx,
 			logger.WithGroup("server"),
 			"./",
 			raw_events.NewStore(logger.WithGroup("raw-event-store"), connPool),
@@ -167,7 +179,7 @@ func runServer(ctx context.Context, logger *slog.Logger, connPool *pgxpool.Pool,
 		defer cancel()
 		defer close(alreadyShutdownCh)
 
-		fmt.Println("server running on 8082...")
+		logger.Info("server running on 8082...")
 		if err := srv.ListenAndServe(); err != nil {
 			if !errors.Is(err, http.ErrServerClosed) {
 				runningErrCh <- fmt.Errorf("server experienced error: %w", err)