APPS-1257-refactored-handlers

- WIP logging on api handlers

cmd/backup/main.go

@@ -12,7 +12,6 @@ import (
 
 	"github.com/aerospike/backup"
 	"github.com/aerospike/backup/internal/server"
-	"github.com/aerospike/backup/internal/server/handlers"
 	"github.com/aerospike/backup/internal/util"
 	"github.com/aerospike/backup/pkg/model"
 	"github.com/aerospike/backup/pkg/service"
@@ -28,7 +27,7 @@ var (
 
 // run parses the CLI parameters and executes backup.
 //
-
+//nolint:funlen // Initialization function contains a lot of code.
 func run() int {
 	var (
 		configFile string
@@ -57,30 +56,39 @@ func run() int {
 		if err != nil {
 			return err
 		}
-		handlers.ConfigurationManager = manager
+
 		// read configuration file
-		config, err := readConfiguration()
+		config, err := readConfiguration(manager)
 		if err != nil {
 			return err
 		}
+
 		// get system ctx
 		ctx := systemCtx()
+
 		// set default loggers
 		loggerConfig := config.ServiceConfig.Logger
+		appLogger := slog.New(
+			util.LogHandler(loggerConfig),
+		)
 		slog.SetDefault(slog.New(util.LogHandler(loggerConfig)))
 		logger.SetDefault(util.NewQuartzLogger(ctx))
 		slog.Info("Aerospike Backup Service", "commit", commit, "buildTime", buildTime)
+
 		// schedule all configured backups
 		backends := service.NewBackupBackends(config)
 		handlers := service.MakeHandlers(config, backends)
 		scheduler, err := service.ScheduleBackup(ctx, config, handlers)
 		if err != nil {
 			return err
 		}
+
 		// run HTTP server
-		err = runHTTPServer(ctx, config, scheduler, backends, handlers)
+		err = runHTTPServer(ctx, config, scheduler, backends, handlers, manager, appLogger)
+
 		// stop the scheduler
 		scheduler.Stop()
+
 		return err
 	}
 
@@ -105,8 +113,8 @@ func systemCtx() context.Context {
 	return ctx
 }
 
-func readConfiguration() (*model.Config, error) {
-	config, err := handlers.ConfigurationManager.ReadConfiguration()
+func readConfiguration(configurationManager service.ConfigurationManager) (*model.Config, error) {
+	config, err := configurationManager.ReadConfiguration()
 	if err != nil {
 		slog.Error("failed to read configuration file", "error", err)
 		return nil, err
@@ -123,8 +131,10 @@ func runHTTPServer(ctx context.Context,
 	scheduler quartz.Scheduler,
 	backends service.BackendsHolder,
 	handlerHolder service.BackupHandlerHolder,
+	configurationManager service.ConfigurationManager,
+	logger *slog.Logger,
 ) error {
-	httpServer := server.NewHTTPServer(config, scheduler, backends, handlerHolder)
+	httpServer := server.NewHTTPServer(config, scheduler, backends, handlerHolder, configurationManager, logger)
 	go func() {
 		httpServer.Start()
 	}()

internal/server/handlers/backup.go

@@ -73,18 +73,36 @@ func (s *Service) GetIncrementalBackupsForRoutine(w http.ResponseWriter, r *http
 }
 
 func (s *Service) readAllBackups(w http.ResponseWriter, r *http.Request, isFullBackup bool) {
-	timeBounds, err := model.NewTimeBoundsFromString(r.URL.Query().Get("from"), r.URL.Query().Get("to"))
+	hLogger := s.logger.With(slog.String("handler", "readAllBackups"))
+
+	from := r.URL.Query().Get("from")
+	to := r.URL.Query().Get("to")
+
+	timeBounds, err := model.NewTimeBoundsFromString(from, to)
 	if err != nil {
+		hLogger.Error("failed parse time limits",
+			slog.String("from", from),
+			slog.String("to", to),
+			slog.Any("error", err),
+		)
 		http.Error(w, "failed parse time limits: "+err.Error(), http.StatusBadRequest)
 		return
 	}
 	backups, err := readBackupsLogic(s.config.BackupRoutines, s.backupBackends, timeBounds, isFullBackup)
 	if err != nil {
+		hLogger.Error("failed to retrieve backup list",
+			slog.Any("timeBounds", timeBounds),
+			slog.Bool("isFullBackup", isFullBackup),
+			slog.Any("error", err),
+		)
 		http.Error(w, "failed to retrieve backup list: "+err.Error(), http.StatusInternalServerError)
 		return
 	}
 	response, err := json.Marshal(backups)
 	if err != nil {
+		hLogger.Error("failed to marshal backup list",
+			slog.Any("error", err),
+		)
 		http.Error(w, "failed to parse backup list", http.StatusInternalServerError)
 		return
 	}
@@ -93,43 +111,74 @@ func (s *Service) readAllBackups(w http.ResponseWriter, r *http.Request, isFullB
 	w.WriteHeader(http.StatusOK)
 	_, err = w.Write(response)
 	if err != nil {
-		slog.Error("failed to write response", "err", err)
+		hLogger.Error("failed to write response",
+			slog.Any("response", response),
+			slog.Any("error", err),
+		)
 	}
 }
 
 func (s *Service) readBackupsForRoutine(w http.ResponseWriter, r *http.Request, isFullBackup bool) {
-	timeBounds, err := model.NewTimeBoundsFromString(r.URL.Query().Get("from"), r.URL.Query().Get("to"))
+	hLogger := s.logger.With(slog.String("handler", "readBackupsForRoutine"))
+
+	from := r.URL.Query().Get("from")
+	to := r.URL.Query().Get("to")
+
+	timeBounds, err := model.NewTimeBoundsFromString(from, to)
 	if err != nil {
+		hLogger.Error("failed parse time limits",
+			slog.String("from", from),
+			slog.String("to", to),
+			slog.Any("error", err),
+		)
 		http.Error(w, "failed parse time limits: "+err.Error(), http.StatusBadRequest)
 		return
 	}
+
 	routine := r.PathValue("name")
 	if routine == "" {
+		hLogger.Error("routine name required")
 		http.Error(w, "routine name required", http.StatusBadRequest)
 		return
 	}
+
 	reader, found := s.backupBackends.GetReader(routine)
 	if !found {
+		hLogger.Error("routine name not found",
+			slog.String("routine", routine),
+		)
 		http.Error(w, "routine name not found: "+routine, http.StatusBadRequest)
 		return
 	}
+
 	backupListFunction := backupsReadFunction(reader, isFullBackup)
 	backups, err := backupListFunction(timeBounds)
 	if err != nil {
+		hLogger.Error("failed to retrieve backup list",
+			slog.Bool("isFullBackup", isFullBackup),
+			slog.Any("timeBounds", timeBounds),
+			slog.Any("error", err),
+		)
 		http.Error(w, "failed to retrieve backup list: "+err.Error(), http.StatusInternalServerError)
 		return
 	}
 	response, err := json.Marshal(backups)
 	if err != nil {
-		http.Error(w, "failed to parse backup list", http.StatusInternalServerError)
+		hLogger.Error("failed to marshal backup list",
+			slog.Any("error", err),
+		)
+		http.Error(w, "failed to marshal backup list", http.StatusInternalServerError)
 		return
 	}
 
 	w.Header().Set("Content-Type", "application/json")
 	w.WriteHeader(http.StatusOK)
 	_, err = w.Write(response)
 	if err != nil {
-		slog.Error("failed to write response", "err", err)
+		hLogger.Error("failed to write response",
+			slog.Any("response", response),
+			slog.Any("error", err),
+		)
 	}
 }
 
@@ -169,8 +218,11 @@ func backupsReadFunction(
 // @Response 400 {string} string
 // @Failure  404 {string} string
 func (s *Service) ScheduleFullBackup(w http.ResponseWriter, r *http.Request) {
+	hLogger := s.logger.With(slog.String("handler", "ScheduleFullBackup"))
+
 	routineName := r.PathValue("name")
 	if routineName == "" {
+		hLogger.Error("routine name required")
 		http.Error(w, "routine name required", http.StatusBadRequest)
 		return
 	}
@@ -180,22 +232,36 @@ func (s *Service) ScheduleFullBackup(w http.ResponseWriter, r *http.Request) {
 		var err error
 		delayMillis, err = strconv.Atoi(delayParameter)
 		if err != nil {
+			hLogger.Error("failed to parse delay parameter",
+				slog.String("delayParameter", delayParameter),
+				slog.Any("error", err),
+			)
 			http.Error(w, err.Error(), http.StatusBadRequest)
 			return
 		}
 	}
 	if delayMillis < 0 {
+		hLogger.Error("nonpositive delay query parameter",
+			slog.Int("delayMillis", delayMillis),
+		)
 		http.Error(w, "nonpositive delay query parameter", http.StatusBadRequest)
 		return
 	}
 	fullBackupJobDetail := service.NewAdHocFullBackupJobForRoutine(routineName)
 	if fullBackupJobDetail == nil {
+		hLogger.Error("unknown routine name",
+			slog.String("name", routineName),
+		)
 		http.Error(w, "unknown routine name "+routineName, http.StatusNotFound)
 		return
 	}
 	trigger := quartz.NewRunOnceTrigger(time.Duration(delayMillis) * time.Millisecond)
 	// schedule using the quartz scheduler
 	if err := s.scheduler.ScheduleJob(fullBackupJobDetail, trigger); err != nil {
+		hLogger.Error("failed to schedule job",
+			slog.Any("trigger", trigger),
+			slog.Any("error", err),
+		)
 		http.Error(w, err.Error(), http.StatusInternalServerError)
 		return
 	}
@@ -212,26 +278,41 @@ func (s *Service) ScheduleFullBackup(w http.ResponseWriter, r *http.Request) {
 // @Success  200 {object} model.CurrentBackups "Current backup statistics"
 // @Failure  404 {string} string
 func (s *Service) GetCurrentBackupInfo(w http.ResponseWriter, r *http.Request) {
+	hLogger := s.logger.With(slog.String("handler", "GetCurrentBackupInfo"))
+
 	routineName := r.PathValue("name")
 	if routineName == "" {
+		hLogger.Error("routine name required")
 		http.Error(w, "routine name required", http.StatusBadRequest)
 		return
 	}
 
 	handler, found := s.handlerHolder[routineName]
 	if !found {
+		hLogger.Error("unknown routine name",
+			slog.String("name", routineName),
+		)
 		http.Error(w, "unknown routine name "+routineName, http.StatusNotFound)
 		return
 	}
 
 	stat := handler.GetCurrentStat()
 	response, err := json.Marshal(stat)
 	if err != nil {
+		hLogger.Error("failed to marshal statistics",
+			slog.Any("error", err),
+		)
 		http.Error(w, "failed to marshal statistics", http.StatusInternalServerError)
 		return
 	}
 
 	w.Header().Set("Content-Type", "application/json")
 	w.WriteHeader(http.StatusOK)
-	_, _ = w.Write(response)
+	_, err = w.Write(response)
+	if err != nil {
+		hLogger.Error("failed to write response",
+			slog.Any("response", response),
+			slog.Any("error", err),
+		)
+	}
 }

internal/server/handlers/config.go

@@ -2,14 +2,13 @@ package handlers
 
 import (
 	"encoding/json"
+	"log/slog"
 	"net/http"
 
 	"github.com/aerospike/backup/pkg/model"
 	"github.com/aerospike/backup/pkg/service"
 )
 
-var ConfigurationManager service.ConfigurationManager
-
 // readConfig
 // @Summary     Returns the configuration for the service.
 // @ID	        readConfig
@@ -19,14 +18,24 @@ var ConfigurationManager service.ConfigurationManager
 // @Success     200 {object} model.Config
 // @Failure     400 {string} string
 func (s *Service) readConfig(w http.ResponseWriter) {
+	hLogger := s.logger.With(slog.String("handler", "readConfig"))
+
 	configuration, err := json.MarshalIndent(s.config, "", "    ") // pretty print
 	if err != nil {
+		// We won't log config as it is not secure.
+		hLogger.Error("failed to parse service configuration",
+			slog.Any("error", err),
+		)
 		http.Error(w, "failed to parse service configuration", http.StatusInternalServerError)
 		return
 	}
 	w.Header().Set("Content-Type", "application/json")
 	w.WriteHeader(http.StatusOK)
-	_, _ = w.Write(configuration)
+	if _, err = w.Write(configuration); err != nil {
+		hLogger.Error("failed to write response",
+			slog.Any("error", err),
+		)
+	}
 }
 
 // updateConfig
@@ -39,20 +48,33 @@ func (s *Service) readConfig(w http.ResponseWriter) {
 // @Success     200
 // @Failure     400 {string} string
 func (s *Service) updateConfig(w http.ResponseWriter, r *http.Request) {
+	hLogger := s.logger.With(slog.String("handler", "updateConfig"))
+
 	var newConfig model.Config
 
 	err := json.NewDecoder(r.Body).Decode(&newConfig)
 	if err != nil {
+		// We won't log config as it is not secure.
+		hLogger.Error("failed to decode new configuration",
+			slog.Any("error", err),
+		)
 		http.Error(w, err.Error(), http.StatusBadRequest)
 		return
 	}
 	if err = newConfig.Validate(); err != nil {
+		hLogger.Error("invalid configuration",
+			slog.Any("error", err),
+		)
 		http.Error(w, "invalid configuration: "+err.Error(), http.StatusBadRequest)
 		return
 	}
 	s.config = &newConfig
-	err = ConfigurationManager.WriteConfiguration(&newConfig)
+	err = s.configurationManager.WriteConfiguration(&newConfig)
 	if err != nil {
+		// We won't log config as it is not secure.
+		hLogger.Error("failed to update configuration",
+			slog.Any("error", err),
+		)
 		http.Error(w, err.Error(), http.StatusBadRequest)
 		return
 	}
@@ -68,8 +90,13 @@ func (s *Service) updateConfig(w http.ResponseWriter, r *http.Request) {
 // @Success     200
 // @Failure     400 {string} string
 func (s *Service) ApplyConfig(w http.ResponseWriter, _ *http.Request) {
+	hLogger := s.logger.With(slog.String("handler", "ApplyConfig"))
+
 	handlers, err := service.ApplyNewConfig(s.scheduler, s.config, s.backupBackends)
 	if err != nil {
+		hLogger.Error("failed to apply new config",
+			slog.Any("error", err),
+		)
 		http.Error(w, err.Error(), http.StatusInternalServerError)
 		return
 	}