Added logging

api/api.go

@@ -6,12 +6,13 @@ import (
 	"encoding/xml"
 	"errors"
 	"fmt"
+	"fs/logging"
 	"fs/metadata"
 	"fs/models"
 	"fs/service"
 	"fs/utils"
 	"io"
-	"log"
+	"log/slog"
 	"net/http"
 	"os"
 	"os/signal"
@@ -25,23 +26,36 @@ import (
 )
 
 type Handler struct {
-	router *chi.Mux
-	svc    *service.ObjectService
+	router    *chi.Mux
+	svc       *service.ObjectService
+	logger    *slog.Logger
+	logConfig logging.Config
 }
 
-func NewHandler(svc *service.ObjectService) *Handler {
+func NewHandler(svc *service.ObjectService, logger *slog.Logger, logConfig logging.Config) *Handler {
 	r := chi.NewRouter()
 	r.Use(middleware.Recoverer)
+	if logger == nil {
+		logger = slog.Default()
+	}
 
 	h := &Handler{
-		router: r,
-		svc:    svc,
+		router:    r,
+		svc:       svc,
+		logger:    logger,
+		logConfig: logConfig,
 	}
 	return h
 }
 
 func (h *Handler) setupRoutes() {
-	h.router.Use(middleware.Logger)
+	if h.logConfig.Format == "text" {
+		if h.logConfig.Audit || h.logConfig.DebugMode {
+			h.router.Use(middleware.Logger)
+		}
+	} else {
+		h.router.Use(logging.HTTPMiddleware(h.logger, h.logConfig))
+	}
 
 	h.router.Get("/", h.handleGetBuckets)
 
@@ -546,30 +560,50 @@ func (h *Handler) handleListObjectsV2(w http.ResponseWriter, r *http.Request, bu
 }
 
 func (h *Handler) Start(address string) error {
-	fmt.Printf("Starting API server on %s\n", address)
+	h.logger.Info("server_starting",
+		"address", address,
+		"log_format", h.logConfig.Format,
+		"log_level", h.logConfig.LevelName,
+		"audit_log", h.logConfig.Audit,
+	)
 	h.setupRoutes()
 	stop := make(chan os.Signal, 1)
 	signal.Notify(stop, os.Interrupt, syscall.SIGTERM)
+	defer signal.Stop(stop)
 	server := http.Server{
 		Addr:    address,
 		Handler: h.router,
 	}
+	errCh := make(chan error, 1)
 
 	go func() {
 		if err := server.ListenAndServe(); err != nil {
-			log.Fatal(err)
+			if !errors.Is(err, http.ErrServerClosed) {
+				errCh <- err
+			}
 		}
 	}()
-	<-stop
+
+	select {
+	case <-stop:
+		h.logger.Info("shutdown_signal_received")
+	case err := <-errCh:
+		h.logger.Error("server_listen_failed", "error", err)
+		return err
+	}
+
 	ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
 	defer cancel()
 
 	if err := server.Shutdown(ctx); err != nil {
+		h.logger.Error("server_shutdown_failed", "error", err)
 		return err
 	}
 	if err := h.svc.Close(); err != nil {
+		h.logger.Error("service_close_failed", "error", err)
 		return err
 	}
 
+	h.logger.Info("server_stopped")
 	return nil
 }

go.mod

@@ -3,10 +3,9 @@ module fs
 go 1.25.7
 
 require (
-	github.com/go-chi/chi/v5 v5.2.5 // indirect
-	github.com/google/uuid v1.6.0 // indirect
-	github.com/klauspost/cpuid/v2 v2.3.0 // indirect
-	github.com/klauspost/reedsolomon v1.13.2 // indirect
-	go.etcd.io/bbolt v1.4.3 // indirect
-	golang.org/x/sys v0.41.0 // indirect
+	github.com/go-chi/chi/v5 v5.2.5
+	github.com/google/uuid v1.6.0
+	go.etcd.io/bbolt v1.4.3
 )
+
+require golang.org/x/sys v0.41.0 // indirect

go.sum

@@ -1,14 +1,18 @@
+github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
+github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/go-chi/chi/v5 v5.2.5 h1:Eg4myHZBjyvJmAFjFvWgrqDTXFyOzjj7YIm3L3mu6Ug=
 github.com/go-chi/chi/v5 v5.2.5/go.mod h1:X7Gx4mteadT3eDOMTsXzmI4/rwUpOwBHLpAfupzFJP0=
 github.com/google/uuid v1.6.0 h1:NIvaJDMOsjHA8n1jAhLSgzrAzy1Hgr+hNrb57e+94F0=
 github.com/google/uuid v1.6.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
-github.com/klauspost/cpuid/v2 v2.3.0 h1:S4CRMLnYUhGeDFDqkGriYKdfoFlDnMtqTiI/sFzhA9Y=
-github.com/klauspost/cpuid/v2 v2.3.0/go.mod h1:hqwkgyIinND0mEev00jJYCxPNVRVXFQeu1XKlok6oO0=
-github.com/klauspost/reedsolomon v1.13.2 h1:9qtQy2tKEVpVB8Pfq87ZljHZb60/LbeTQ1OxV8EGzdE=
-github.com/klauspost/reedsolomon v1.13.2/go.mod h1:ggJT9lc71Vu+cSOPBlxGvBN6TfAS77qB4fp8vJ05NSA=
+github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
+github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
+github.com/stretchr/testify v1.10.0 h1:Xv5erBjTwe/5IxqUQTdXv5kgmIvbHo3QQyRwhJsOfJA=
+github.com/stretchr/testify v1.10.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY=
 go.etcd.io/bbolt v1.4.3 h1:dEadXpI6G79deX5prL3QRNP6JB8UxVkqo4UPnHaNXJo=
 go.etcd.io/bbolt v1.4.3/go.mod h1:tKQlpPaYCVFctUIgFKFnAlvbmB3tpy1vkTnDWohtc0E=
-golang.org/x/sys v0.29.0 h1:TPYlXGxvx1MGTn2GiZDhnjPA9wZzZeGKHHmKhHYvgaU=
-golang.org/x/sys v0.29.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
+golang.org/x/sync v0.10.0 h1:3NQrjDixjgGwUOCaF8w2+VYHv0Ve/vGYSbdkTa98gmQ=
+golang.org/x/sync v0.10.0/go.mod h1:Czt+wKu1gCyEFDUtn0jG5QVvpJ6rzVqr5aXyt9drQfk=
 golang.org/x/sys v0.41.0 h1:Ivj+2Cp/ylzLiEU89QhWblYnOE9zerudt9Ftecq2C6k=
 golang.org/x/sys v0.41.0/go.mod h1:OgkHotnGiDImocRcuBABYBEXf8A9a87e/uXjp9XT3ks=
+gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
+gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=

logging/logging.go

@@ -0,0 +1,162 @@
+package logging
+
+import (
+	"log/slog"
+	"net/http"
+	"os"
+	"path/filepath"
+	"strconv"
+	"strings"
+	"time"
+)
+
+type Config struct {
+	Level     slog.Level
+	LevelName string
+	Format    string
+	Audit     bool
+	AddSource bool
+	DebugMode bool
+}
+
+func ConfigFromEnv() Config {
+	levelName := strings.ToLower(strings.TrimSpace(os.Getenv("LOG_LEVEL")))
+	if levelName == "" {
+		levelName = "info"
+	}
+	level := parseLevel(levelName)
+	levelName = level.String()
+
+	format := strings.ToLower(strings.TrimSpace(os.Getenv("LOG_FORMAT")))
+	if format == "" {
+		format = "text"
+	}
+	if format != "json" && format != "text" {
+		format = "text"
+	}
+
+	debugMode := level <= slog.LevelDebug
+	return Config{
+		Level:     level,
+		LevelName: levelName,
+		Format:    format,
+		Audit:     envBool("AUDIT_LOG", true),
+		AddSource: debugMode,
+		DebugMode: debugMode,
+	}
+}
+
+func NewLogger(cfg Config) *slog.Logger {
+	opts := &slog.HandlerOptions{
+		Level:     cfg.Level,
+		AddSource: cfg.AddSource,
+	}
+	opts.ReplaceAttr = func(_ []string, attr slog.Attr) slog.Attr {
+		if attr.Key == slog.SourceKey {
+			if src, ok := attr.Value.Any().(*slog.Source); ok && src != nil {
+				attr.Key = "src"
+				attr.Value = slog.StringValue(filepath.Base(src.File) + ":" + strconv.Itoa(src.Line))
+			}
+		}
+		return attr
+	}
+
+	var handler slog.Handler
+	if cfg.Format == "json" {
+		handler = slog.NewJSONHandler(os.Stdout, opts)
+	} else {
+		handler = slog.NewTextHandler(os.Stdout, opts)
+	}
+
+	logger := slog.New(handler)
+	slog.SetDefault(logger)
+	return logger
+}
+
+func HTTPMiddleware(logger *slog.Logger, cfg Config) func(http.Handler) http.Handler {
+	return func(next http.Handler) http.Handler {
+		return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+			start := time.Now()
+			ww := &responseWriter{ResponseWriter: w, status: http.StatusOK}
+
+			next.ServeHTTP(ww, r)
+
+			if !cfg.Audit && !cfg.DebugMode {
+				return
+			}
+
+			elapsed := time.Since(start)
+			attrs := []any{
+				"method", r.Method,
+				"path", r.URL.Path,
+				"status", ww.status,
+				"bytes", ww.bytes,
+				"remote_addr", r.RemoteAddr,
+			}
+			switch {
+			case elapsed < time.Microsecond:
+				attrs = append(attrs, "duration_ns", elapsed.Nanoseconds())
+			case elapsed < time.Millisecond:
+				attrs = append(attrs, "duration_us", elapsed.Microseconds())
+			default:
+				attrs = append(attrs, "duration_ms", elapsed.Milliseconds())
+			}
+
+			if cfg.DebugMode {
+				attrs = append(attrs,
+					"query", r.URL.RawQuery,
+					"user_agent", r.UserAgent(),
+					"content_length", r.ContentLength,
+					"content_type", r.Header.Get("Content-Type"),
+					"x_amz_sha256", r.Header.Get("x-amz-content-sha256"),
+				)
+				logger.Debug("http_request", attrs...)
+				return
+			}
+
+			logger.Info("http_request", attrs...)
+		})
+	}
+}
+
+type responseWriter struct {
+	http.ResponseWriter
+	status int
+	bytes  int
+}
+
+func (w *responseWriter) WriteHeader(statusCode int) {
+	w.status = statusCode
+	w.ResponseWriter.WriteHeader(statusCode)
+}
+
+func (w *responseWriter) Write(p []byte) (int, error) {
+	n, err := w.ResponseWriter.Write(p)
+	w.bytes += n
+	return n, err
+}
+
+func envBool(key string, defaultValue bool) bool {
+	raw := os.Getenv(key)
+	if raw == "" {
+		return defaultValue
+	}
+	value, err := strconv.ParseBool(raw)
+	if err != nil {
+		return defaultValue
+	}
+	return value
+}
+
+func parseLevel(levelName string) slog.Level {
+	switch levelName {
+	case "debug":
+		return slog.LevelDebug
+	case "warn", "warning":
+		return slog.LevelWarn
+	case "error":
+		return slog.LevelError
+	default:
+		return slog.LevelInfo
+	}
+}

main.go

@@ -1,24 +1,31 @@
 package main
 
 import (
-	"fmt"
 	"fs/api"
+	"fs/logging"
 	"fs/metadata"
 	"fs/service"
 )
 
 func main() {
+	logConfig := logging.ConfigFromEnv()
+	logger := logging.NewLogger(logConfig)
+	logger.Info("boot",
+		"log_level", logConfig.LevelName,
+		"log_format", logConfig.Format,
+		"audit_log", logConfig.Audit,
+	)
 
 	metadataHandler, err := metadata.NewMetadataHandler("metadata.db")
 	if err != nil {
-		fmt.Printf("Error initializing metadata handler: %v\n", err)
+		logger.Error("failed_to_initialize_metadata_handler", "error", err)
 		return
 	}
 
 	objectService := service.NewObjectService(metadataHandler)
-	handler := api.NewHandler(objectService)
-	err = handler.Start("0.0.0.0:3000")
-	if err != nil {
+	handler := api.NewHandler(objectService, logger, logConfig)
+	if err = handler.Start("0.0.0.0:3000"); err != nil {
+		logger.Error("server_stopped_with_error", "error", err)
 		return
 	}
 }

metadata/metadata.go

@@ -36,7 +36,7 @@ var (
 )
 
 func NewMetadataHandler(dbPath string) (*MetadataHandler, error) {
-	db, err := bbolt.Open(dbPath, 0600, nil)
+	db, err := bbolt.Open(dbPath, 0600, &bbolt.Options{Timeout: 2 * time.Second})
 	if err != nil {
 		return nil, err
 	}

service/service.go

@@ -9,6 +9,7 @@ import (
 	"fs/models"
 	"fs/storage"
 	"io"
+	"log/slog"
 	"strings"
 	"time"
 )
@@ -45,7 +46,13 @@ func (s *ObjectService) PutObject(bucket, key, contentType string, input io.Read
 		Chunks:      chunks,
 		CreatedAt:   timestamp,
 	}
-	fmt.Println(manifest)
+	slog.Debug("object_written_manifest",
+		"bucket", manifest.Bucket,
+		"key", manifest.Key,
+		"size", manifest.Size,
+		"chunk_count", len(manifest.Chunks),
+		"etag", manifest.ETag,
+	)
 	if err = s.metadataHandler.PutManifest(manifest); err != nil {
 		return nil, err
 	}