all: imp code

internal/aghhttp/aghhttp.go

@@ -2,13 +2,16 @@
 package aghhttp
 
 import (
+	"context"
 	"fmt"
 	"io"
+	"log/slog"
 	"net/http"
 
 	"github.com/AdguardTeam/AdGuardHome/internal/version"
 	"github.com/AdguardTeam/golibs/httphdr"
 	"github.com/AdguardTeam/golibs/log"
+	"github.com/AdguardTeam/golibs/logutil/slogutil"
 )
 
 // HTTP scheme constants.
@@ -31,12 +34,39 @@ func OK(w http.ResponseWriter) {
 }
 
 // Error writes formatted message to w and also logs it.
+//
+// TODO(s.chzhen):  Remove it.
 func Error(r *http.Request, w http.ResponseWriter, code int, format string, args ...any) {
 	text := fmt.Sprintf(format, args...)
 	log.Error("%s %s %s: %s", r.Method, r.Host, r.URL, text)
 	http.Error(w, text, code)
 }
 
+// ErrorAndLog writes formatted message to w and also logs it with the specified
+// logging level.
+func ErrorAndLog(
+	ctx context.Context,
+	l *slog.Logger,
+	lvl slog.Level,
+	r *http.Request,
+	w http.ResponseWriter,
+	code int,
+	format string,
+	args ...any,
+) {
+	text := fmt.Sprintf(format, args...)
+	l.Log(
+		ctx,
+		lvl,
+		"http error",
+		"method", r.Method,
+		"host", r.Host,
+		"url", r.URL,
+		slogutil.KeyError, text,
+	)
+	http.Error(w, text, code)
+}
+
 // UserAgent returns the ID of the service as a User-Agent string.  It can also
 // be used as the value of the Server HTTP header.
 func UserAgent() (ua string) {

internal/stats/http.go

@@ -4,6 +4,7 @@ package stats
 
 import (
 	"encoding/json"
+	"log/slog"
 	"net/http"
 	"time"
 
@@ -50,6 +51,8 @@ type StatsResp struct {
 func (s *StatsCtx) handleStats(w http.ResponseWriter, r *http.Request) {
 	start := time.Now()
 
+	ctx := r.Context()
+
 	var (
 		resp *StatsResp
 		ok   bool
@@ -61,12 +64,23 @@ func (s *StatsCtx) handleStats(w http.ResponseWriter, r *http.Request) {
 		resp, ok = s.getData(uint32(s.limit.Hours()))
 	}()
 
-	s.logger.Debug("prepared data", "elapsed", timeutil.Duration{Duration: time.Since(start)})
+	s.logger.DebugContext(
+		ctx,
+		"prepared data",
+		"elapsed", timeutil.Duration{Duration: time.Since(start)},
+	)
 
 	if !ok {
 		// Don't bring the message to the lower case since it's a part of UI
 		// text for the moment.
-		aghhttp.Error(r, w, http.StatusInternalServerError, "Couldn't get statistics data")
+		aghhttp.ErrorAndLog(
+			ctx,
+			s.logger,
+			slog.LevelError,
+			r,
+			w,
+			http.StatusInternalServerError, "Couldn't get statistics data",
+		)
 
 		return
 	}
@@ -145,16 +159,35 @@ func (s *StatsCtx) handleGetStatsConfig(w http.ResponseWriter, r *http.Request)
 //
 // Deprecated:  Remove it when migration to the new API is over.
 func (s *StatsCtx) handleStatsConfig(w http.ResponseWriter, r *http.Request) {
+	ctx := r.Context()
+
 	reqData := configResp{}
 	err := json.NewDecoder(r.Body).Decode(&reqData)
 	if err != nil {
-		aghhttp.Error(r, w, http.StatusBadRequest, "json decode: %s", err)
+		aghhttp.ErrorAndLog(
+			ctx,
+			s.logger,
+			slog.LevelError,
+			r,
+			w,
+			http.StatusBadRequest,
+			"json decode: %s",
+			err,
+		)
 
 		return
 	}
 
 	if !checkInterval(reqData.IntervalDays) {
-		aghhttp.Error(r, w, http.StatusBadRequest, "Unsupported interval")
+		aghhttp.ErrorAndLog(
+			ctx,
+			s.logger,
+			slog.LevelError,
+			r,
+			w,
+			http.StatusBadRequest,
+			"Unsupported interval",
+		)
 
 		return
 	}
@@ -172,17 +205,37 @@ func (s *StatsCtx) handleStatsConfig(w http.ResponseWriter, r *http.Request) {
 // handlePutStatsConfig is the handler for the PUT /control/stats/config/update
 // HTTP API.
 func (s *StatsCtx) handlePutStatsConfig(w http.ResponseWriter, r *http.Request) {
+	ctx := r.Context()
+
 	reqData := getConfigResp{}
 	err := json.NewDecoder(r.Body).Decode(&reqData)
 	if err != nil {
-		aghhttp.Error(r, w, http.StatusBadRequest, "json decode: %s", err)
+		aghhttp.ErrorAndLog(
+			ctx,
+			s.logger,
+			slog.LevelError,
+			r,
+			w,
+			http.StatusBadRequest,
+			"json decode: %s",
+			err,
+		)
 
 		return
 	}
 
 	engine, err := aghnet.NewIgnoreEngine(reqData.Ignored)
 	if err != nil {
-		aghhttp.Error(r, w, http.StatusUnprocessableEntity, "ignored: %s", err)
+		aghhttp.ErrorAndLog(
+			ctx,
+			s.logger,
+			slog.LevelError,
+			r,
+			w,
+			http.StatusUnprocessableEntity,
+			"ignored: %s",
+			err,
+		)
 
 		return
 	}
@@ -190,13 +243,30 @@ func (s *StatsCtx) handlePutStatsConfig(w http.ResponseWriter, r *http.Request)
 	ivl := time.Duration(reqData.Interval) * time.Millisecond
 	err = validateIvl(ivl)
 	if err != nil {
-		aghhttp.Error(r, w, http.StatusUnprocessableEntity, "unsupported interval: %s", err)
+		aghhttp.ErrorAndLog(
+			ctx,
+			s.logger,
+			slog.LevelError,
+			r,
+			w,
+			http.StatusUnprocessableEntity,
+			"unsupported interval: %s",
+			err,
+		)
 
 		return
 	}
 
 	if reqData.Enabled == aghalg.NBNull {
-		aghhttp.Error(r, w, http.StatusUnprocessableEntity, "enabled is null")
+		aghhttp.ErrorAndLog(
+			ctx,
+			s.logger,
+			slog.LevelError,
+			r,
+			w,
+			http.StatusUnprocessableEntity,
+			"enabled is null",
+		)
 
 		return
 	}
@@ -215,7 +285,16 @@ func (s *StatsCtx) handlePutStatsConfig(w http.ResponseWriter, r *http.Request)
 func (s *StatsCtx) handleStatsReset(w http.ResponseWriter, r *http.Request) {
 	err := s.clear()
 	if err != nil {
-		aghhttp.Error(r, w, http.StatusInternalServerError, "stats: %s", err)
+		aghhttp.ErrorAndLog(
+			r.Context(),
+			s.logger,
+			slog.LevelError,
+			r,
+			w,
+			http.StatusInternalServerError,
+			"stats: %s",
+			err,
+		)
 	}
 }
 

internal/stats/stats.go

@@ -189,7 +189,7 @@ func New(conf Config) (s *StatsCtx, err error) {
 
 	tx, err := s.db.Load().Begin(true)
 	if err != nil {
-		return nil, fmt.Errorf("stats: opening a transaction: %w", err)
+		return nil, fmt.Errorf("opening a transaction: %w", err)
 	}
 
 	deleted := s.deleteOldUnits(tx, id-uint32(s.limit.Hours())-1)
@@ -239,8 +239,6 @@ func (s *StatsCtx) Start() {
 
 // Close implements the [io.Closer] interface for *StatsCtx.
 func (s *StatsCtx) Close() (err error) {
-	defer func() { err = errors.Annotate(err, "stats: closing: %w") }()
-
 	db := s.db.Swap(nil)
 	if db == nil {
 		return nil
@@ -392,7 +390,13 @@ func (s *StatsCtx) openDB() (err error) {
 Please read the explanation here: https://github.com/AdguardTeam/AdGuardHome/wiki/Getting-Started#limitations`
 
 			// TODO(s.chzhen):  Use passed context.
-			slogutil.PrintLines(context.TODO(), s.logger, slog.LevelError, "opening database", lines)
+			slogutil.PrintLines(
+				context.TODO(),
+				s.logger,
+				slog.LevelError,
+				"opening database",
+				lines,
+			)
 		}
 
 		return err
@@ -458,16 +462,17 @@ func (s *StatsCtx) flushDB(id, limit uint32, ptr *unit) (cont bool, sleepFor tim
 	}
 
 	delErr := tx.DeleteBucket(idToUnitName(id - limit))
+
 	if delErr != nil {
 		// TODO(e.burkov):  Improve the algorithm of deleting the oldest bucket
 		// to avoid the error.
-		msg := "deleting bucket"
+		logFunc := s.logger.Warn
-		if errors.Is(delErr, bbolt.ErrBucketNotFound) {
+		if !errors.Is(delErr, bbolt.ErrBucketNotFound) {
-			s.logger.Warn(msg, slogutil.KeyError, delErr)
-		} else {
 			isCommitable = false
-			s.logger.Error(msg, slogutil.KeyError, delErr)
+			logFunc = s.logger.Error
 		}
+
+		logFunc("deleting bucket", slogutil.KeyError, delErr)
 	}
 
 	return true, 0

internal/stats/stats_test.go

@@ -22,11 +22,6 @@ import (
 	"github.com/stretchr/testify/require"
 )
 
-// TODO(s.chzhen):  Remove once [aghhttp.Error] starts using slog.
-func TestMain(m *testing.M) {
-	testutil.DiscardLogOutput(m)
-}
-
 // constUnitID is the UnitIDGenFunc which always return 0.
 func constUnitID() (id uint32) { return 0 }