Merge pull request #384 from green-ecolution/feature/improve-log-mess…

…ages

feat: improve log messages

Makefile

@@ -1,4 +1,4 @@
-ENV ?= dev
+export ENV ?= dev
 MAIN_PACKAGE_PATH := .
 BINARY_NAME := green-ecolution-backend
 APP_VERSION ?= $(shell git describe --tags --always --dirty)

internal/logger/logger.go

@@ -1,15 +1,25 @@
 package logger
 
 import (
+	"context"
+	"fmt"
 	"io"
+	"log"
 	"log/slog"
+	"path/filepath"
+	"runtime"
+	"strings"
+	"time"
+
+	"github.com/green-ecolution/green-ecolution-backend/internal/utils"
 )
 
 type LogFormat string
 
 const (
-	JSON LogFormat = "json"
-	Text LogFormat = "text"
+	JSON    LogFormat = "json"
+	Text    LogFormat = "text"
+	Console LogFormat = "console"
 )
 
 type LogLevel string
@@ -21,6 +31,20 @@ const (
 	Error LogLevel = "error"
 )
 
+var _ slog.LogValuer = (*TimeSince)(nil)
+
+type TimeSince struct {
+	startTime time.Time
+}
+
+func NewTimeSince() *TimeSince {
+	return &TimeSince{startTime: time.Now()}
+}
+
+func (t *TimeSince) LogValue() slog.Value {
+	return slog.StringValue(time.Since(t.startTime).String())
+}
+
 func (l LogLevel) ToSLog() slog.Level {
 	switch l {
 	case Debug:
@@ -36,21 +60,151 @@ func (l LogLevel) ToSLog() slog.Level {
 	}
 }
 
-func CreateLogger(out io.Writer, format LogFormat, level LogLevel) *slog.Logger {
-	options := &slog.HandlerOptions{
-		AddSource: true,
-		Level:     level.ToSLog(),
+type GroupOrAttrs struct {
+	attr  slog.Attr
+	group string
+}
+
+type PrettyHandlerOptions struct {
+	SlogOpts slog.HandlerOptions
+}
+
+type PrettyHandler struct {
+	opts PrettyHandlerOptions
+	slog.Handler
+	l   *log.Logger
+	goa []GroupOrAttrs
+}
+
+func NewPrettyHandler(out io.Writer, opts PrettyHandlerOptions) *PrettyHandler {
+	h := &PrettyHandler{
+		Handler: slog.NewTextHandler(out, &opts.SlogOpts),
+		l:       log.New(out, "", 0),
+		opts:    opts,
+		goa:     make([]GroupOrAttrs, 0),
+	}
+
+	return h
+}
+
+func (h *PrettyHandler) WithGroup(group string) slog.Handler {
+	lCopy := log.New(h.l.Writer(), h.l.Prefix(), h.l.Flags())
+	return &PrettyHandler{
+		Handler: h.Handler.WithGroup(group),
+		l:       lCopy,
+		opts:    h.opts,
+		goa:     append(h.goa, GroupOrAttrs{group: group}),
 	}
+}
 
-	var handler slog.Handler
-	switch format {
-	case JSON:
-		handler = slog.NewJSONHandler(out, options)
-	case Text:
-		handler = slog.NewTextHandler(out, options)
-	default:
-		handler = slog.NewTextHandler(out, options)
+func (h *PrettyHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
+	newAttrs := make([]GroupOrAttrs, len(attrs))
+
+	for i, attr := range attrs {
+		newAttrs[i] = GroupOrAttrs{attr: attr}
+	}
+
+	lCopy := log.New(h.l.Writer(), h.l.Prefix(), h.l.Flags())
+	return &PrettyHandler{
+		Handler: h.Handler.WithAttrs(attrs),
+		l:       lCopy,
+		opts:    h.opts,
+		goa:     append(h.goa, newAttrs...),
+	}
+}
+
+//nolint:gocritic // ignored because this has to implement slog handler
+func (h *PrettyHandler) Handle(_ context.Context, r slog.Record) error {
+	level := r.Level.String()
+	switch r.Level {
+	case slog.LevelDebug:
+		level = fmt.Sprintf("\033[35;1m%s\033[0m", level) // Magenta
+	case slog.LevelInfo:
+		level = fmt.Sprintf("\033[34;1m%s\033[0m", level) // Blue
+	case slog.LevelWarn:
+		level = fmt.Sprintf("\033[33;1m%s\033[0m", level) // Yellow
+	case slog.LevelError:
+		level = fmt.Sprintf("\033[31;1m%s\033[0m", level) // Red
+	}
+
+	fields := make([]slog.Attr, 0)
+	lastGroup := ""
+	for _, goa := range h.goa {
+		if goa.group != "" {
+			lastGroup += goa.group + "."
+		} else {
+			attr := goa.attr
+			attr.Value = attr.Value.Resolve()
+			if lastGroup != "" {
+				attr.Key = lastGroup + attr.Key
+			}
+
+			fields = append(fields, attr)
+		}
+	}
+
+	r.Attrs(func(a slog.Attr) bool {
+		a.Value = a.Value.Resolve()
+		if lastGroup != "" {
+			a.Key = lastGroup + a.Key
+		}
+		fields = append(fields, a)
+		return true
+	})
+
+	logFields := make([]string, 0, len(fields))
+	for _, attr := range fields {
+		keyColorSeq := "\033[38;5;249;1m" // gray bold
+		valueColorSeq := "\033[38;5;249m" // gray
+
+		if attr.Key == "err" || attr.Key == "error" {
+			keyColorSeq = "\033[31;1m" // red bold
+			valueColorSeq = "\033[31m" // red
+		}
+
+		logFields = append(logFields, fmt.Sprintf("%s%s=\033[0m%s\"%v\"\033[0m", keyColorSeq, attr.Key, valueColorSeq, attr.Value.Any()))
+	}
+
+	var source string
+	if h.opts.SlogOpts.AddSource {
+		frame, _ := runtime.CallersFrames([]uintptr{r.PC}).Next()
+		dir, file := filepath.Split(frame.File)
+		rootDir := utils.RootDir()
+		relativeDir, err := filepath.Rel(rootDir, filepath.Dir(dir))
+		if err != nil {
+			return err
+		}
+
+		source = fmt.Sprintf("\033[38;5;98;1;4m%s:%d\033[0m", filepath.Join(relativeDir, file), frame.Line)
 	}
 
-	return slog.New(handler)
+	timeStr := fmt.Sprintf("[%s]", r.Time.Format(time.Stamp))
+	msg := fmt.Sprintf("\033[36m%s\033[0m", r.Message) // Cyan
+
+	h.l.Println(timeStr, level, source, msg, strings.Join(logFields, " "))
+
+	return nil
+}
+
+func CreateLogger(out io.Writer, format LogFormat, level LogLevel) func() *slog.Logger {
+	return func() *slog.Logger {
+		options := &slog.HandlerOptions{
+			AddSource: true,
+			Level:     level.ToSLog(),
+		}
+
+		var handler slog.Handler
+		switch format {
+		case JSON:
+			handler = slog.NewJSONHandler(out, options)
+		case Text:
+			handler = slog.NewTextHandler(out, options)
+		case Console:
+			handler = NewPrettyHandler(out, PrettyHandlerOptions{SlogOpts: *options})
+		default:
+			handler = slog.NewTextHandler(out, options)
+		}
+
+		return slog.New(handler)
+	}
 }

internal/logger/utils.go

@@ -0,0 +1,38 @@
+package logger
+
+import (
+	"context"
+	"log/slog"
+)
+
+// GetLogger retrieves a logger instance from the given context.
+//
+// This function attempts to extract a logger from the context using the key "logger".
+// If the key is not present or the value is not of type *slog.Logger, it falls back
+// to returning the default logger provided by slog.
+//
+// Usage:
+//  1. To use this function effectively, ensure that the context has a logger stored
+//     using context.WithValue, with the key "logger" and a value of type *slog.Logger.
+//  2. If no logger is found in the context, slog.Default() is returned.
+//
+// Parameters:
+// - ctx (context.Context): The context from which the logger will be extracted.
+//
+// Returns:
+// - *slog.Logger: The logger instance extracted from the context or the default logger.
+//
+// Example:
+// ```go
+// logger := slog.New(slog.WithLevel(slog.LevelInfo))
+// ctx := context.WithValue(context.Background(), "logger", logger)
+// retrievedLogger := GetLogger(ctx)
+// retrievedLogger.Info("Logger successfully retrieved!")
+// ```
+func GetLogger(ctx context.Context) *slog.Logger {
+	log, ok := ctx.Value("logger").(*slog.Logger)
+	if !ok {
+		log = slog.Default()
+	}
+	return log
+}

internal/server/http/handler/v1/errorhandler/error_handler.go

@@ -6,22 +6,8 @@ import (
 
 	"github.com/gofiber/fiber/v2"
 	"github.com/green-ecolution/green-ecolution-backend/internal/service"
-	"github.com/green-ecolution/green-ecolution-backend/internal/storage"
 )
 
-var notFoundErrors = []error{
-	storage.ErrRegionNotFound,
-	storage.ErrIDNotFound,
-	storage.ErrEntityNotFound,
-	storage.ErrSensorNotFound,
-	storage.ErrImageNotFound,
-	storage.ErrFlowerbedNotFound,
-	storage.ErrTreeClusterNotFound,
-	storage.ErrTreeNotFound,
-	storage.ErrVehicleNotFound,
-	storage.ErrWateringPlanNotFound,
-}
-
 func HandleError(err error) error {
 	if err == nil {
 		return nil
@@ -48,13 +34,5 @@ func HandleError(err error) error {
 		}
 	}
 
-	// Check for specific "not found" errors
-	for _, notFoundErr := range notFoundErrors {
-		if errors.Is(err, notFoundErr) {
-			code = fiber.StatusNotFound
-			break
-		}
-	}
-
 	return fiber.NewError(code, err.Error())
 }

internal/server/http/handler/v1/plugin/handler.go

@@ -17,8 +17,9 @@ import (
 
 func getPluginFiles(svc service.PluginService) fiber.Handler {
 	return func(c *fiber.Ctx) error {
+		ctx := c.Context()
 		pluginParam := strings.Clone(c.Params("plugin"))
-		plugin, err := svc.Get(pluginParam)
+		plugin, err := svc.Get(ctx, pluginParam)
 		if err != nil {
 			return err
 		}
@@ -114,8 +115,9 @@ func registerPlugin(svc service.PluginService) fiber.Handler {
 // @Security		Keycloak
 func pluginHeartbeat(svc service.PluginService) fiber.Handler {
 	return func(c *fiber.Ctx) error {
+		ctx := c.Context()
 		slug := strings.Clone(c.Params("plugin"))
-		if err := svc.HeartBeat(slug); err != nil {
+		if err := svc.HeartBeat(ctx, slug); err != nil {
 			slog.Error("Failed to heartbeat", "plugin", slug, "error", err)
 			return c.Status(fiber.StatusBadRequest).SendString(err.Error())
 		}
@@ -139,7 +141,8 @@ func pluginHeartbeat(svc service.PluginService) fiber.Handler {
 // @Security		Keycloak
 func GetPluginsList(svc service.PluginService) fiber.Handler {
 	return func(c *fiber.Ctx) error {
-		p, h := svc.GetAll()
+		ctx := c.Context()
+		p, h := svc.GetAll(ctx)
 		log.Println(h)
 		plugins := utils.Map(p, func(plugin domain.Plugin) entities.PluginResponse {
 			return entities.PluginResponse{
@@ -173,8 +176,9 @@ func GetPluginsList(svc service.PluginService) fiber.Handler {
 // @Security		Keycloak
 func GetPluginInfo(svc service.PluginService) fiber.Handler {
 	return func(c *fiber.Ctx) error {
+		ctx := c.Context()
 		pluginParam := strings.Clone(c.Params("plugin"))
-		plugin, err := svc.Get(pluginParam)
+		plugin, err := svc.Get(ctx, pluginParam)
 		if err != nil {
 			return c.Status(fiber.StatusNotFound).SendString("plugin not found")
 		}

internal/server/http/handler/v1/region/handler_test.go

@@ -10,8 +10,8 @@ import (
 	"github.com/green-ecolution/green-ecolution-backend/internal/entities"
 	serverEntities "github.com/green-ecolution/green-ecolution-backend/internal/server/http/entities"
 	"github.com/green-ecolution/green-ecolution-backend/internal/server/http/handler/v1/region"
+	"github.com/green-ecolution/green-ecolution-backend/internal/service"
 	serviceMock "github.com/green-ecolution/green-ecolution-backend/internal/service/_mock"
-	"github.com/green-ecolution/green-ecolution-backend/internal/storage"
 	"github.com/green-ecolution/green-ecolution-backend/internal/utils"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/mock"
@@ -167,7 +167,7 @@ func TestGetRegionByID(t *testing.T) {
 		mockRegionService.EXPECT().GetByID(
 			mock.Anything,
 			int32(1),
-		).Return(nil, storage.ErrRegionNotFound)
+		).Return(nil, service.NewError(service.NotFound, "region not found"))
 
 		app.Get("/v1/region/:id", handler)
 

internal/server/http/handler/v1/sensor/handler_test.go

@@ -11,8 +11,8 @@ import (
 	"github.com/green-ecolution/green-ecolution-backend/internal/entities"
 	serverEntities "github.com/green-ecolution/green-ecolution-backend/internal/server/http/entities"
 	"github.com/green-ecolution/green-ecolution-backend/internal/server/http/handler/v1/sensor"
+	"github.com/green-ecolution/green-ecolution-backend/internal/service"
 	serviceMock "github.com/green-ecolution/green-ecolution-backend/internal/service/_mock"
-	"github.com/green-ecolution/green-ecolution-backend/internal/storage"
 	"github.com/green-ecolution/green-ecolution-backend/internal/utils"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/mock"
@@ -146,7 +146,7 @@ func TestGetSensorById(t *testing.T) {
 		mockSensorService.EXPECT().GetByID(
 			mock.Anything,
 			"sensor-999",
-		).Return(nil, storage.ErrSensorNotFound)
+		).Return(nil, service.NewError(service.NotFound, "not found"))
 
 		app.Get("/v1/sensor/:id", handler)
 
@@ -220,7 +220,7 @@ func TestDeleteSensor(t *testing.T) {
 		mockSensorService.EXPECT().Delete(
 			mock.Anything,
 			"sensor-999",
-		).Return(storage.ErrSensorNotFound)
+		).Return(service.NewError(service.NotFound, "not found"))
 
 		app.Delete("/v1/sensor/:id", handler)