From 72adfb101fcdb42635702c1f1c4e13ddcc95bfdc Mon Sep 17 00:00:00 2001
From: Stanislav Chzhen <s.chzhen@adguard.com>
Date: Wed, 21 Aug 2024 16:42:44 +0300
Subject: [PATCH] all: slog ipset

---
 internal/dnsforward/config.go               | 10 +++---
 internal/dnsforward/dnsforward.go           | 10 ++++--
 internal/dnsforward/ipset.go                | 39 +++++++++++----------
 internal/dnsforward/ipset_internal_test.go  |  8 ++++-
 internal/ipset/ipset.go                     |  5 +--
 internal/ipset/ipset_linux.go               | 38 +++++++++++++-------
 internal/ipset/ipset_linux_internal_test.go |  3 +-
 internal/ipset/ipset_others.go              |  4 ++-
 8 files changed, 75 insertions(+), 42 deletions(-)

diff --git a/internal/dnsforward/config.go b/internal/dnsforward/config.go
index 7b1fe1f7..c5c45dee 100644
--- a/internal/dnsforward/config.go
+++ b/internal/dnsforward/config.go
@@ -457,24 +457,24 @@ func (s *Server) initDefaultSettings() {
 
 // prepareIpsetListSettings reads and prepares the ipset configuration either
 // from a file or from the data in the configuration file.
-func (s *Server) prepareIpsetListSettings() (err error) {
+func (s *Server) prepareIpsetListSettings() (ipsets []string, err error) {
 	fn := s.conf.IpsetListFileName
 	if fn == "" {
-		return s.ipset.init(s.conf.IpsetList)
+		return s.conf.IpsetList, nil
 	}
 
 	// #nosec G304 -- Trust the path explicitly given by the user.
 	data, err := os.ReadFile(fn)
 	if err != nil {
-		return err
+		return nil, err
 	}
 
-	ipsets := stringutil.SplitTrimmed(string(data), "\n")
+	ipsets = stringutil.SplitTrimmed(string(data), "\n")
 	ipsets = stringutil.FilterOut(ipsets, IsCommentOrEmpty)
 
 	log.Debug("dns: using %d ipset rules from file %q", len(ipsets), fn)
 
-	return s.ipset.init(ipsets)
+	return ipsets, nil
 }
 
 // loadUpstreams parses upstream DNS servers from the configured file or from
diff --git a/internal/dnsforward/dnsforward.go b/internal/dnsforward/dnsforward.go
index 9ae6fc69..c92f2221 100644
--- a/internal/dnsforward/dnsforward.go
+++ b/internal/dnsforward/dnsforward.go
@@ -134,7 +134,7 @@ type Server struct {
 	localDomainSuffix string
 
 	// ipset processes DNS requests using ipset data.
-	ipset ipsetCtx
+	ipset *ipsetCtx
 
 	// privateNets is the configured set of IP networks considered private.
 	privateNets netutil.SubnetSet
@@ -609,11 +609,17 @@ func (s *Server) prepareLocalResolvers() (uc *proxy.UpstreamConfig, err error) {
 // the primary DNS proxy instance.  It assumes s.serverLock is locked or the
 // Server not running.
 func (s *Server) prepareInternalDNS() (err error) {
-	err = s.prepareIpsetListSettings()
+	ipsetConf, err := s.prepareIpsetListSettings()
 	if err != nil {
 		return fmt.Errorf("preparing ipset settings: %w", err)
 	}
 
+	s.ipset, err = newIPSetCtx(s.logger, ipsetConf)
+	if err != nil {
+		// Don't wrap the error, because it's informative enough as is.
+		return err
+	}
+
 	bootOpts := &upstream.Options{
 		Timeout:      DefaultTimeout,
 		HTTPVersions: UpstreamHTTPVersions(s.conf.UseHTTP3Upstreams),
diff --git a/internal/dnsforward/ipset.go b/internal/dnsforward/ipset.go
index cd841c34..64adcfe4 100644
--- a/internal/dnsforward/ipset.go
+++ b/internal/dnsforward/ipset.go
@@ -2,26 +2,31 @@ package dnsforward
 
 import (
 	"fmt"
+	"log/slog"
 	"net"
 	"os"
 	"strings"
 
 	"github.com/AdguardTeam/AdGuardHome/internal/ipset"
 	"github.com/AdguardTeam/golibs/errors"
-	"github.com/AdguardTeam/golibs/log"
+	"github.com/AdguardTeam/golibs/logutil/slogutil"
 	"github.com/miekg/dns"
 )
 
 // ipsetCtx is the ipset context.  ipsetMgr can be nil.
 type ipsetCtx struct {
 	ipsetMgr ipset.Manager
+	logger   *slog.Logger
 }
 
-// init initializes the ipset context.  It is not safe for concurrent use.
-//
-// TODO(a.garipov): Rewrite into a simple constructor?
-func (c *ipsetCtx) init(ipsetConf []string) (err error) {
-	c.ipsetMgr, err = ipset.NewManager(ipsetConf)
+// newIPSetCtx returns a new initialized [ipsetCtx].  It is not safe for
+// concurrent use.
+func newIPSetCtx(logger *slog.Logger, ipsetConf []string) (c *ipsetCtx, err error) {
+	c = &ipsetCtx{
+		logger: logger,
+	}
+	ipsetLogger := logger.With(slogutil.KeyPrefix, "ipset")
+	c.ipsetMgr, err = ipset.NewManager(ipsetLogger, ipsetConf)
 	if errors.Is(err, os.ErrInvalid) || errors.Is(err, os.ErrPermission) {
 		// ipset cannot currently be initialized if the server was installed
 		// from Snap or when the user or the binary doesn't have the required
@@ -31,18 +36,18 @@ func (c *ipsetCtx) init(ipsetConf []string) (err error) {
 		//
 		// TODO(a.garipov): The Snap problem can probably be solved if we add
 		// the netlink-connector interface plug.
-		log.Info("ipset: warning: cannot initialize: %s", err)
+		logger.Warn("ipset: cannot initialize", slogutil.KeyError, err)
 
-		return nil
+		return c, nil
 	} else if errors.Is(err, errors.ErrUnsupported) {
-		log.Info("ipset: warning: %s", err)
+		logger.Warn("ipset: cannot initialize", slogutil.KeyError, err)
 
-		return nil
+		return c, nil
 	} else if err != nil {
-		return fmt.Errorf("initializing ipset: %w", err)
+		return nil, fmt.Errorf("initializing ipset: %w", err)
 	}
 
-	return nil
+	return c, nil
 }
 
 // close closes the Linux Netfilter connections.
@@ -109,15 +114,13 @@ func ipsFromAnswer(ans []dns.RR) (ip4s, ip6s []net.IP) {
 
 // process adds the resolved IP addresses to the domain's ipsets, if any.
 func (c *ipsetCtx) process(dctx *dnsContext) (rc resultCode) {
-	log.Debug("dnsforward: ipset: started processing")
-	defer log.Debug("dnsforward: ipset: finished processing")
+	c.logger.Debug("ipset: started processing")
+	defer c.logger.Debug("ipset: finished processing")
 
 	if c.skipIpsetProcessing(dctx) {
 		return resultCodeSuccess
 	}
 
-	log.Debug("ipset: starting processing")
-
 	req := dctx.proxyCtx.Req
 	host := req.Question[0].Name
 	host = strings.TrimSuffix(host, ".")
@@ -127,12 +130,12 @@ func (c *ipsetCtx) process(dctx *dnsContext) (rc resultCode) {
 	n, err := c.ipsetMgr.Add(host, ip4s, ip6s)
 	if err != nil {
 		// Consider ipset errors non-critical to the request.
-		log.Error("dnsforward: ipset: adding host ips: %s", err)
+		c.logger.Error("ipset: adding host ips", slogutil.KeyError, err)
 
 		return resultCodeSuccess
 	}
 
-	log.Debug("dnsforward: ipset: added %d new ipset entries", n)
+	c.logger.Debug("ipset: added new ipset entries", "num", n)
 
 	return resultCodeSuccess
 }
diff --git a/internal/dnsforward/ipset_internal_test.go b/internal/dnsforward/ipset_internal_test.go
index cdeed21b..01e29832 100644
--- a/internal/dnsforward/ipset_internal_test.go
+++ b/internal/dnsforward/ipset_internal_test.go
@@ -5,6 +5,7 @@ import (
 	"testing"
 
 	"github.com/AdguardTeam/dnsproxy/proxy"
+	"github.com/AdguardTeam/golibs/logutil/slogutil"
 	"github.com/miekg/dns"
 	"github.com/stretchr/testify/assert"
 )
@@ -58,7 +59,9 @@ func TestIpsetCtx_process(t *testing.T) {
 			responseFromUpstream: true,
 		}
 
-		ictx := &ipsetCtx{}
+		ictx := &ipsetCtx{
+			logger: slogutil.NewDiscardLogger(),
+		}
 		rc := ictx.process(dctx)
 		assert.Equal(t, resultCodeSuccess, rc)
 
@@ -79,6 +82,7 @@ func TestIpsetCtx_process(t *testing.T) {
 		m := &fakeIpsetMgr{}
 		ictx := &ipsetCtx{
 			ipsetMgr: m,
+			logger:   slogutil.NewDiscardLogger(),
 		}
 
 		rc := ictx.process(dctx)
@@ -103,6 +107,7 @@ func TestIpsetCtx_process(t *testing.T) {
 		m := &fakeIpsetMgr{}
 		ictx := &ipsetCtx{
 			ipsetMgr: m,
+			logger:   slogutil.NewDiscardLogger(),
 		}
 
 		rc := ictx.process(dctx)
@@ -126,6 +131,7 @@ func TestIpsetCtx_SkipIpsetProcessing(t *testing.T) {
 	m := &fakeIpsetMgr{}
 	ictx := &ipsetCtx{
 		ipsetMgr: m,
+		logger:   slogutil.NewDiscardLogger(),
 	}
 
 	testCases := []struct {
diff --git a/internal/ipset/ipset.go b/internal/ipset/ipset.go
index 44f519f1..f271c67e 100644
--- a/internal/ipset/ipset.go
+++ b/internal/ipset/ipset.go
@@ -2,6 +2,7 @@
 package ipset
 
 import (
+	"log/slog"
 	"net"
 )
 
@@ -24,10 +25,10 @@ type Manager interface {
 //
 // If ipsetConf is empty, msg and err are nil.  The error's chain contains
 // [errors.ErrUnsupported] if current OS is not supported.
-func NewManager(ipsetConf []string) (mgr Manager, err error) {
+func NewManager(logger *slog.Logger, ipsetConf []string) (mgr Manager, err error) {
 	if len(ipsetConf) == 0 {
 		return nil, nil
 	}
 
-	return newManager(ipsetConf)
+	return newManager(logger, ipsetConf)
 }
diff --git a/internal/ipset/ipset_linux.go b/internal/ipset/ipset_linux.go
index 12dcecea..7e842e53 100644
--- a/internal/ipset/ipset_linux.go
+++ b/internal/ipset/ipset_linux.go
@@ -5,13 +5,14 @@ package ipset
 import (
 	"bytes"
 	"fmt"
+	"log/slog"
 	"net"
 	"strings"
 	"sync"
 
 	"github.com/AdguardTeam/golibs/container"
 	"github.com/AdguardTeam/golibs/errors"
-	"github.com/AdguardTeam/golibs/log"
+	"github.com/AdguardTeam/golibs/logutil/slogutil"
 	"github.com/digineo/go-ipset/v2"
 	"github.com/mdlayher/netlink"
 	"github.com/ti-mo/netfilter"
@@ -34,8 +35,8 @@ import (
 //     resolved IP addresses.
 
 // newManager returns a new Linux ipset manager.
-func newManager(ipsetConf []string) (set Manager, err error) {
-	return newManagerWithDialer(ipsetConf, defaultDial)
+func newManager(logger *slog.Logger, ipsetConf []string) (set Manager, err error) {
+	return newManagerWithDialer(logger, ipsetConf, defaultDial)
 }
 
 // defaultDial is the default netfilter dialing function.
@@ -180,6 +181,8 @@ type manager struct {
 	nameToIpset    map[string]props
 	domainToIpsets map[string][]props
 
+	logger *slog.Logger
+
 	dial dialer
 
 	// mu protects all properties below.
@@ -336,10 +339,11 @@ func (m *manager) ipsets(names []string, currentlyKnown map[string]props) (sets
 		}
 
 		if p.family != netfilter.ProtoIPv4 && p.family != netfilter.ProtoIPv6 {
-			log.Debug("ipset: getting properties: %q %q unexpected ipset family %q",
-				p.name,
-				p.typeName,
-				p.family,
+			m.logger.Debug("getting properties",
+				slogutil.KeyError, "unexpected ipset family",
+				"set_name", p.name,
+				"set_type", p.typeName,
+				"set_family", p.family,
 			)
 
 			p, err = m.ipsetProps(n)
@@ -357,7 +361,11 @@ func (m *manager) ipsets(names []string, currentlyKnown map[string]props) (sets
 
 // newManagerWithDialer returns a new Linux ipset manager using the provided
 // dialer.
-func newManagerWithDialer(ipsetConf []string, dial dialer) (mgr Manager, err error) {
+func newManagerWithDialer(
+	logger *slog.Logger,
+	ipsetConf []string,
+	dial dialer,
+) (mgr Manager, err error) {
 	defer func() { err = errors.Annotate(err, "ipset: %w") }()
 
 	m := &manager{
@@ -366,6 +374,8 @@ func newManagerWithDialer(ipsetConf []string, dial dialer) (mgr Manager, err err
 		nameToIpset:    make(map[string]props),
 		domainToIpsets: make(map[string][]props),
 
+		logger: logger,
+
 		dial: dial,
 
 		addedIPs: container.NewMapSet[ipInIpsetEntry](),
@@ -376,7 +386,7 @@ func newManagerWithDialer(ipsetConf []string, dial dialer) (mgr Manager, err err
 		if errors.Is(err, unix.EPROTONOSUPPORT) {
 			// The implementation doesn't support this protocol version.  Just
 			// issue a warning.
-			log.Info("ipset: dialing netfilter: warning: %s", err)
+			logger.Warn("dialing netfilter", slogutil.KeyError, err)
 
 			return nil, nil
 		}
@@ -389,7 +399,7 @@ func newManagerWithDialer(ipsetConf []string, dial dialer) (mgr Manager, err err
 		return nil, fmt.Errorf("getting ipsets: %w", err)
 	}
 
-	log.Debug("ipset: initialized")
+	logger.Debug("initialized")
 
 	return m, nil
 }
@@ -498,7 +508,11 @@ func (m *manager) addToSets(
 			return n, fmt.Errorf("%q %q unexpected family %q", set.name, set.typeName, set.family)
 		}
 
-		log.Debug("ipset: added %d ips to set %q %q", nn, set.name, set.typeName)
+		m.logger.Debug("added ips to set",
+			"ips_num", nn,
+			"set_name", set.name,
+			"set_type", set.typeName,
+		)
 
 		n += nn
 	}
@@ -516,7 +530,7 @@ func (m *manager) Add(host string, ip4s, ip6s []net.IP) (n int, err error) {
 		return 0, nil
 	}
 
-	log.Debug("ipset: found %d sets", len(sets))
+	m.logger.Debug("found sets", "set_num", len(sets))
 
 	return m.addToSets(host, ip4s, ip6s, sets)
 }
diff --git a/internal/ipset/ipset_linux_internal_test.go b/internal/ipset/ipset_linux_internal_test.go
index 4d727ee7..31e9e823 100644
--- a/internal/ipset/ipset_linux_internal_test.go
+++ b/internal/ipset/ipset_linux_internal_test.go
@@ -8,6 +8,7 @@ import (
 	"testing"
 
 	"github.com/AdguardTeam/golibs/errors"
+	"github.com/AdguardTeam/golibs/logutil/slogutil"
 	"github.com/digineo/go-ipset/v2"
 	"github.com/mdlayher/netlink"
 	"github.com/stretchr/testify/assert"
@@ -89,7 +90,7 @@ func TestManager_Add(t *testing.T) {
 		}, nil
 	}
 
-	m, err := newManagerWithDialer(ipsetConf, fakeDial)
+	m, err := newManagerWithDialer(slogutil.NewDiscardLogger(), ipsetConf, fakeDial)
 	require.NoError(t, err)
 
 	ip4 := net.IP{1, 2, 3, 4}
diff --git a/internal/ipset/ipset_others.go b/internal/ipset/ipset_others.go
index 8b75912f..4090b0b3 100644
--- a/internal/ipset/ipset_others.go
+++ b/internal/ipset/ipset_others.go
@@ -3,9 +3,11 @@
 package ipset
 
 import (
+	"log/slog"
+
 	"github.com/AdguardTeam/AdGuardHome/internal/aghos"
 )
 
-func newManager(_ []string) (mgr Manager, err error) {
+func newManager(_ *slog.Logger, _ []string) (mgr Manager, err error) {
 	return nil, aghos.Unsupported("ipset")
 }