fix(core): rewrite logger with singleton approach (#21)

* fix: rewrite logger with singleton approach

* test: remove e2e scripts

* fix(core): handle security handler errors in error handler

core/cmd/start.go

@@ -22,9 +22,9 @@ import (
 	"github.com/medama-io/medama/migrations"
 	"github.com/medama-io/medama/services"
 	"github.com/medama-io/medama/util"
+	"github.com/medama-io/medama/util/logger"
 	"github.com/ogen-go/ogen/middleware"
 	"github.com/rs/cors"
-	"github.com/rs/zerolog"
 )
 
 type StartCommand struct {
@@ -75,11 +75,10 @@ func (s *StartCommand) ParseFlags(args []string) error {
 
 // Run executes the start command.
 func (s *StartCommand) Run(ctx context.Context) error {
-	ctx, err := util.SetupLogger(ctx, s.Server.Logger, s.Server.Level)
+	log, err := logger.Init(s.Server.Logger, s.Server.Level)
 	if err != nil {
 		return errors.Wrap(err, "failed to setup logger")
 	}
-	log := zerolog.Ctx(ctx)
 	log.Info().Msg(GetVersion())
 
 	// Setup database
@@ -117,14 +116,13 @@ func (s *StartCommand) Run(ctx context.Context) error {
 		return errors.Wrap(err, "failed to create handlers")
 	}
 
-	authMiddleware := middlewares.NewAuthHandler(auth)
 	mw := []middleware.Middleware{
 		middlewares.RequestLogger(),
 		middlewares.RequestContext(),
 		middlewares.Recovery(),
 	}
 	apiHandler, err := api.NewServer(service,
-		authMiddleware,
+		middlewares.NewAuthHandler(auth),
 		api.WithMiddleware(mw...),
 		api.WithErrorHandler(middlewares.ErrorHandler),
 		api.WithNotFound(middlewares.NotFound()),

core/db/sqlite/websites.go

@@ -6,8 +6,8 @@ import (
 
 	"github.com/go-faster/errors"
 	"github.com/medama-io/medama/model"
+	"github.com/medama-io/medama/util/logger"
 	"github.com/ncruces/go-sqlite3"
-	"github.com/rs/zerolog"
 )
 
 func (c *Client) CreateWebsite(ctx context.Context, website *model.Website) error {
@@ -23,8 +23,8 @@ func (c *Client) CreateWebsite(ctx context.Context, website *model.Website) erro
 			return model.ErrUserNotFound
 		}
 
-		zerolog.Ctx(ctx).
-			Error().
+		log := logger.Get()
+		log.Error().
 			Str("user_id", website.UserID).
 			Str("hostname", website.Hostname).
 			Int64("date_created", website.DateCreated).
@@ -39,14 +39,14 @@ func (c *Client) CreateWebsite(ctx context.Context, website *model.Website) erro
 
 func (c *Client) ListWebsites(ctx context.Context, userID string) ([]*model.Website, error) {
 	var websites []*model.Website
+	log := logger.Get()
 
 	query := `--sql
 	SELECT user_id, hostname, name, date_created, date_updated FROM websites WHERE user_id = ?`
 
 	err := c.SelectContext(ctx, &websites, query, userID)
 	if err != nil {
-		zerolog.Ctx(ctx).
-			Error().
+		log.Error().
 			Str("user_id", userID).
 			Err(err).
 			Msg("failed to list websites")
@@ -55,7 +55,7 @@ func (c *Client) ListWebsites(ctx context.Context, userID string) ([]*model.Webs
 	}
 
 	if len(websites) == 0 {
-		zerolog.Ctx(ctx).Debug().Str("user_id", userID).Msg("no websites found")
+		log.Debug().Str("user_id", userID).Msg("no websites found")
 		return nil, model.ErrWebsiteNotFound
 	}
 
@@ -69,14 +69,16 @@ func (c *Client) ListAllHostnames(ctx context.Context) ([]string, error) {
 	var hostnames []string
 	err := c.SelectContext(ctx, &hostnames, query)
 	if err != nil {
-		zerolog.Ctx(ctx).Error().Err(err).Msg("failed to list all hostnames")
+		log := logger.Get()
+		log.Error().Err(err).Msg("failed to list all hostnames")
 		return nil, errors.Wrap(err, "db")
 	}
 
 	return hostnames, nil
 }
 
 func (c *Client) UpdateWebsite(ctx context.Context, website *model.Website) error {
+	log := logger.Get()
 	// Update all values except user_id
 	exec := `--sql
 	UPDATE websites SET hostname = ?, name = ?, date_updated = ? WHERE hostname = ?`
@@ -87,8 +89,7 @@ func (c *Client) UpdateWebsite(ctx context.Context, website *model.Website) erro
 			return model.ErrWebsiteExists
 		}
 
-		zerolog.Ctx(ctx).
-			Error().
+		log.Error().
 			Str("hostname", website.Hostname).
 			Str("name", website.Name).
 			Int64("date_updated", website.DateUpdated).
@@ -100,8 +101,7 @@ func (c *Client) UpdateWebsite(ctx context.Context, website *model.Website) erro
 
 	rowsAffected, err := res.RowsAffected()
 	if err != nil {
-		zerolog.Ctx(ctx).
-			Error().
+		log.Error().
 			Str("hostname", website.Hostname).
 			Str("name", website.Name).
 			Int64("date_updated", website.DateUpdated).
@@ -112,7 +112,7 @@ func (c *Client) UpdateWebsite(ctx context.Context, website *model.Website) erro
 	}
 
 	if rowsAffected == 0 {
-		zerolog.Ctx(ctx).Debug().Str("hostname", website.Hostname).Msg("website not found")
+		log.Debug().Str("hostname", website.Hostname).Msg("website not found")
 		return model.ErrWebsiteNotFound
 	}
 
@@ -121,13 +121,13 @@ func (c *Client) UpdateWebsite(ctx context.Context, website *model.Website) erro
 
 func (c *Client) GetWebsite(ctx context.Context, hostname string) (*model.Website, error) {
 	var website model.Website
+	log := logger.Get()
 
 	query := `--sql
 	SELECT user_id, hostname, name, date_created, date_updated FROM websites WHERE hostname = ?`
 
 	err := c.QueryRowxContext(ctx, query, hostname).StructScan(&website)
 	if err != nil {
-		log := zerolog.Ctx(ctx)
 		if errors.Is(err, sql.ErrNoRows) {
 			log.Debug().Str("hostname", hostname).Msg("website not found")
 			return nil, model.ErrWebsiteNotFound
@@ -142,13 +142,13 @@ func (c *Client) GetWebsite(ctx context.Context, hostname string) (*model.Websit
 }
 
 func (c *Client) DeleteWebsite(ctx context.Context, hostname string) error {
+	log := logger.Get()
 	exec := `--sql
 	DELETE FROM websites WHERE hostname = ?`
 
 	res, err := c.DB.ExecContext(ctx, exec, hostname)
 	if err != nil {
-		zerolog.Ctx(ctx).
-			Error().
+		log.Error().
 			Str("hostname", hostname).
 			Err(err).
 			Msg("failed to delete website")
@@ -158,8 +158,7 @@ func (c *Client) DeleteWebsite(ctx context.Context, hostname string) error {
 
 	rowsAffected, err := res.RowsAffected()
 	if err != nil {
-		zerolog.Ctx(ctx).
-			Error().
+		log.Error().
 			Str("hostname", hostname).
 			Err(err).
 			Msg("failed to get rows affected")
@@ -168,7 +167,7 @@ func (c *Client) DeleteWebsite(ctx context.Context, hostname string) error {
 	}
 
 	if rowsAffected == 0 {
-		zerolog.Ctx(ctx).Debug().Str("hostname", hostname).Msg("website not found")
+		log.Debug().Str("hostname", hostname).Msg("website not found")
 		return model.ErrWebsiteNotFound
 	}
 

core/middlewares/404.go

@@ -4,7 +4,7 @@ import (
 	"net/http"
 
 	"github.com/go-faster/jx"
-	"github.com/rs/zerolog"
+	"github.com/medama-io/medama/util/logger"
 )
 
 const errMessage = "api path not found"
@@ -27,8 +27,9 @@ func NotFound() func(w http.ResponseWriter, req *http.Request) {
 
 		_, _ = w.Write(e.Bytes())
 
-		zerolog.Ctx(req.Context()).
-			Info().
+		log := logger.Get()
+
+		log.Info().
 			Str("path", req.URL.Path).
 			Str("method", req.Method).
 			Int("status_code", http.StatusNotFound).

core/middlewares/errors.go

@@ -7,26 +7,31 @@ import (
 	"strings"
 
 	"github.com/go-faster/jx"
+	"github.com/medama-io/medama/model"
+	"github.com/medama-io/medama/util/logger"
 	"github.com/ogen-go/ogen/ogenerrors"
-	"github.com/rs/zerolog"
 )
 
 // ErrorHandler is a middleware that handles any unhandled errors by ogen.
 func ErrorHandler(ctx context.Context, w http.ResponseWriter, req *http.Request, err error) {
 	code := ogenerrors.ErrorCode(err)
 	errMessage := strings.ReplaceAll(err.Error(), "\"", "'")
 
-	zerolog.Ctx(ctx).
-		Error().
+	log := logger.Get().With().
 		Str("path", req.URL.Path).
 		Str("method", req.Method).
 		Int("status_code", code).
 		Str("message", errMessage).
 		Str("Connection", req.Header.Get("Connection")).
 		Str("Content-Type", req.Header.Get("Content-Type")).
 		Str("Content-Length", req.Header.Get("Content-Length")).
-		Str("User-Agent", req.Header.Get("User-Agent")).
-		Msg("Error 500")
+		Str("User-Agent", req.Header.Get("User-Agent")).Logger()
+
+	if errors.Is(err, model.ErrUnauthorised) || code == http.StatusUnauthorized {
+		log.Warn().Msg("unauthorised")
+	} else {
+		log.Error().Msg(err.Error())
+	}
 
 	if errors.Is(err, ogenerrors.ErrSecurityRequirementIsNotSatisfied) {
 		errMessage = "missing security token or cookie"

core/middlewares/logger.go

@@ -5,8 +5,8 @@ import (
 	"time"
 
 	"github.com/medama-io/medama/api"
+	"github.com/medama-io/medama/util/logger"
 	"github.com/ogen-go/ogen/middleware"
-	"github.com/rs/zerolog"
 )
 
 // getCode returns the http status code from the error type.
@@ -40,12 +40,15 @@ func RequestLogger() middleware.Middleware {
 		req middleware.Request,
 		next func(req middleware.Request) (middleware.Response, error),
 	) (middleware.Response, error) {
+		// Add the logger to request context
+		log := logger.Get()
+
 		startTime := time.Now()
 		resp, err := next(req)
 		duration := time.Since(startTime)
 
 		if err == nil {
-			log := zerolog.Ctx(req.Context).With().
+			log = log.With().
 				Str("operation", req.OperationName).
 				Str("operationId", req.OperationID).
 				Str("method", req.Raw.Method).

core/middlewares/recover.go

@@ -4,9 +4,8 @@ import (
 	"errors"
 	"net/http"
 
+	"github.com/medama-io/medama/util/logger"
 	"github.com/ogen-go/ogen/middleware"
-	"github.com/rs/zerolog"
-	"github.com/rs/zerolog/pkgerrors"
 )
 
 // Recovery is a middleware that recovers from panics.
@@ -23,10 +22,8 @@ func Recovery() middleware.Middleware {
 					panic(rvr)
 				}
 
-				//nolint: reassign // We need to reassign the stack marshaler.
-				zerolog.ErrorStackMarshaler = pkgerrors.MarshalStack
-				zerolog.Ctx(req.Context).
-					Error().
+				log := logger.Get()
+				log.Error().
 					Str("path", req.Raw.URL.Path).
 					Str("method", req.Raw.Method).
 					Str("User-Agent", req.Raw.Header.Get("User-Agent")).

core/migrations/migrations.go

@@ -7,7 +7,7 @@ import (
 	"github.com/go-faster/errors"
 	"github.com/medama-io/medama/db/duckdb"
 	"github.com/medama-io/medama/db/sqlite"
-	"github.com/rs/zerolog"
+	"github.com/medama-io/medama/util/logger"
 )
 
 type MigrationType string
@@ -55,7 +55,7 @@ func NewMigrationsService(ctx context.Context, sqliteC *sqlite.Client, duckdbC *
 		{ID: 2, Name: "0002_duckdb_schema.go", Type: DuckDB, Up: Up0002, Down: Down0002},
 	}
 
-	log := zerolog.Ctx(ctx)
+	log := logger.Get()
 	err := CreateMigrationsTable(sqliteC)
 	if err != nil {
 		log.Error().Err(err).Msg("failed to create migrations table")
@@ -78,7 +78,7 @@ func runMigrator[Client sqlite.Client | duckdb.Client](ctx context.Context, sqli
 		var id int
 		err := sqlite.GetContext(ctx, &id, "SELECT id FROM migrations WHERE id = ?", migration.ID)
 
-		log := zerolog.Ctx(ctx).With().
+		log := logger.Get().With().
 			Int("id", migration.ID).
 			Str("name", migration.Name).
 			Str("type", string(migration.Type)).

core/services/event.go

@@ -9,7 +9,7 @@ import (
 
 	"github.com/medama-io/medama/api"
 	"github.com/medama-io/medama/model"
-	"github.com/rs/zerolog"
+	"github.com/medama-io/medama/util/logger"
 	"golang.org/x/text/language"
 	"golang.org/x/text/language/display"
 )
@@ -45,7 +45,8 @@ func (h *Handler) GetEventPing(ctx context.Context, params api.GetEventPingParam
 	// Parse the if-modified-since header and check if it is older than a day.
 	lastModifiedTime, err := time.Parse(http.TimeFormat, ifModified)
 	if err != nil {
-		zerolog.Ctx(ctx).Error().Err(err).Msg("failed to parse if-modified-since header")
+		log := logger.Get()
+		log.Error().Err(err).Msg("failed to parse if-modified-since header")
 		return ErrBadRequest(err), nil
 	}
 
@@ -80,11 +81,12 @@ func (h *Handler) GetEventPing(ctx context.Context, params api.GetEventPingParam
 }
 
 func (h *Handler) PostEventHit(ctx context.Context, req api.EventHit, params api.PostEventHitParams) (api.PostEventHitRes, error) {
+	log := logger.Get()
 	switch req.Type {
 	case api.EventLoadEventHit:
 		hostname := req.EventLoad.U.Hostname()
 		pathname := req.EventLoad.U.Path
-		log := zerolog.Ctx(ctx).With().Str("hostname", hostname).Logger()
+		log = log.With().Str("hostname", hostname).Logger()
 
 		// Verify hostname exists
 		exists := h.hostnames.Has(hostname)
@@ -206,7 +208,7 @@ func (h *Handler) PostEventHit(ctx context.Context, req api.EventHit, params api
 			DurationMs: req.EventUnload.M,
 		}
 
-		log := zerolog.Ctx(ctx).With().
+		log = log.With().
 			Str("bid", event.BID).
 			Str("event_type", string(req.Type)).
 			Int("duration_ms", event.DurationMs).
@@ -222,7 +224,7 @@ func (h *Handler) PostEventHit(ctx context.Context, req api.EventHit, params api
 		log.Debug().Msg("hit: updated page view")
 
 	default:
-		zerolog.Ctx(ctx).Error().Str("type", string(req.Type)).Msg("hit: invalid event hit type")
+		log.Error().Str("type", string(req.Type)).Msg("hit: invalid event hit type")
 		return ErrBadRequest(model.ErrInvalidTrackerEvent), nil
 	}