diff --git a/api/api.go b/api/api.go index e8b2c8c..3bdbd51 100644 --- a/api/api.go +++ b/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 } diff --git a/go.mod b/go.mod index 8038354..097ed4b 100644 --- a/go.mod +++ b/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 diff --git a/go.sum b/go.sum index f2ff379..a3b895f 100644 --- a/go.sum +++ b/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= diff --git a/logging/logging.go b/logging/logging.go new file mode 100644 index 0000000..0562c0f --- /dev/null +++ b/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 + } +} diff --git a/main.go b/main.go index 39d3e65..c11ddaf 100644 --- a/main.go +++ b/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 } } diff --git a/metadata/metadata.go b/metadata/metadata.go index d6b1719..6a2df20 100644 --- a/metadata/metadata.go +++ b/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 } diff --git a/service/service.go b/service/service.go index 26eee1b..aa5c6d6 100644 --- a/service/service.go +++ b/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 }