Pull request 2440: AGDNS-3060-imp-gocognit-logs

Merge in DNS/adguard-home from AGDNS-3060-imp-gocognit-logs to master

Squashed commit of the following:

commit 3026dc35662c71c125c60198f828e7da7e8e5b4f
Merge: 2b56f4236 df258512d
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Wed Jul 30 13:00:44 2025 +0300

    Merge branch 'master' into AGDNS-3060-imp-gocognit-logs

commit 2b56f423649ef0e5734a3a1d9c0b5df178462e29
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Fri Jul 25 14:41:40 2025 +0300

    all: imp docs

commit 101d043c85e8b813f6b28751edeeb6c6b43578a9
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Wed Jul 23 20:09:38 2025 +0300

    all: imp code

commit 87cfa502f7abf5b8f8a18b71f4a99aab9a066961
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Wed Jul 23 14:51:33 2025 +0300

    all: imp code

commit 07c1a04a4022f4e38282a538670d575fba949bb2
Author: Stanislav Chzhen <s.chzhen@adguard.com>
Date:   Tue Jul 22 20:04:58 2025 +0300

    all: imp gocognit, logs
This commit is contained in:
Stanislav Chzhen
2025-07-30 17:53:09 +03:00
parent df258512dc
commit b8043e4f05
22 changed files with 348 additions and 262 deletions

View File

@@ -29,7 +29,7 @@ func newClientsContainer(t *testing.T) (c *clientsContainer) {
&filtering.Config{
Logger: testLogger,
},
newSignalHandler(nil, nil),
newSignalHandler(testLogger, nil, nil),
)
require.NoError(t, err)

View File

@@ -22,6 +22,7 @@ import (
"github.com/AdguardTeam/AdGuardHome/internal/aghnet"
"github.com/AdguardTeam/AdGuardHome/internal/aghos"
"github.com/AdguardTeam/AdGuardHome/internal/aghslog"
"github.com/AdguardTeam/AdGuardHome/internal/aghtls"
"github.com/AdguardTeam/AdGuardHome/internal/arpdb"
"github.com/AdguardTeam/AdGuardHome/internal/dhcpd"
"github.com/AdguardTeam/AdGuardHome/internal/dnsforward"
@@ -114,13 +115,19 @@ func Main(clientBuildFS fs.FS) {
// package flag.
opts := loadCmdLineOpts()
ls := getLogSettings(opts)
// TODO(a.garipov): Use slog everywhere.
baseLogger := newSlogLogger(ls)
done := make(chan struct{})
signals := make(chan os.Signal, 1)
signal.Notify(signals, syscall.SIGINT, syscall.SIGTERM, syscall.SIGHUP, syscall.SIGQUIT)
ctx := context.Background()
sigHdlr := newSignalHandler(signals, func(ctx context.Context) {
sigHdlrLogger := baseLogger.With(slogutil.KeyPrefix, "signalhdlr")
sigHdlr := newSignalHandler(sigHdlrLogger, signals, func(ctx context.Context) {
cleanup(ctx)
cleanupAlways()
close(done)
@@ -129,24 +136,34 @@ func Main(clientBuildFS fs.FS) {
go sigHdlr.handle(ctx)
if opts.serviceControlAction != "" {
handleServiceControlAction(opts, clientBuildFS, signals, done, sigHdlr)
svcLogger := baseLogger.With(slogutil.KeyPrefix, "service")
handleServiceControlAction(
ctx,
baseLogger,
svcLogger,
opts,
clientBuildFS,
signals,
done,
sigHdlr,
)
return
}
// run the protection
run(opts, clientBuildFS, done, sigHdlr)
run(ctx, baseLogger, opts, clientBuildFS, done, sigHdlr)
}
// setupContext initializes [globalContext] fields. It also reads and upgrades
// config file if necessary.
func setupContext(opts options) (err error) {
// config file if necessary. baseLogger must not be nil.
func setupContext(ctx context.Context, baseLogger *slog.Logger, opts options) (err error) {
globalContext.firstRun = detectFirstRun()
globalContext.mux = http.NewServeMux()
if !opts.noEtcHosts {
err = setupHostsContainer()
err = setupHostsContainer(ctx, baseLogger)
if err != nil {
// Don't wrap the error, because it's informative enough as is.
return err
@@ -230,9 +247,9 @@ func configureOS(conf *configuration) (err error) {
}
// setupHostsContainer initializes the structures to keep up-to-date the hosts
// provided by the OS.
func setupHostsContainer() (err error) {
hostsWatcher, err := aghos.NewOSWritesWatcher()
// provided by the OS. baseLogger must not be nil.
func setupHostsContainer(ctx context.Context, baseLogger *slog.Logger) (err error) {
hostsWatcher, err := aghos.NewOSWritesWatcher(baseLogger.With(slogutil.KeyPrefix, "oswatcher"))
if err != nil {
log.Info("WARNING: initializing filesystem watcher: %s; not watching for changes", err)
@@ -246,7 +263,7 @@ func setupHostsContainer() (err error) {
globalContext.etcHosts, err = aghnet.NewHostsContainer(osutil.RootDirFS(), hostsWatcher, paths...)
if err != nil {
closeErr := hostsWatcher.Close()
closeErr := hostsWatcher.Shutdown(ctx)
if errors.Is(err, aghnet.ErrNoHostsPaths) {
log.Info("warning: initing hosts container: %s", err)
@@ -256,7 +273,7 @@ func setupHostsContainer() (err error) {
return errors.Join(fmt.Errorf("initializing hosts container: %w", err), closeErr)
}
return hostsWatcher.Start()
return hostsWatcher.Start(ctx)
}
// setupOpts sets up command-line options.
@@ -603,7 +620,14 @@ func fatalOnError(err error) {
// run configures and starts AdGuard Home.
//
// TODO(e.burkov): Make opts a pointer.
func run(opts options, clientBuildFS fs.FS, done chan struct{}, sigHdlr *signalHandler) {
func run(
ctx context.Context,
slogLogger *slog.Logger,
opts options,
clientBuildFS fs.FS,
done chan struct{},
sigHdlr *signalHandler,
) {
// Configure working dir.
err := initWorkingDir(opts)
fatalOnError(err)
@@ -617,10 +641,6 @@ func run(opts options, clientBuildFS fs.FS, done chan struct{}, sigHdlr *signalH
err = configureLogger(ls)
fatalOnError(err)
// TODO(a.garipov): Use slog everywhere.
slogLogger := newSlogLogger(ls)
sigHdlr.swapLogger(slogLogger)
// Print the first message after logger is configured.
log.Info("%s", version.Full())
log.Debug("current working directory is %s", globalContext.workDir)
@@ -628,15 +648,14 @@ func run(opts options, clientBuildFS fs.FS, done chan struct{}, sigHdlr *signalH
log.Info("AdGuard Home is running as a service")
}
err = setupContext(opts)
aghtls.Init(ctx, slogLogger.With(slogutil.KeyPrefix, "aghtls"))
err = setupContext(ctx, slogLogger, opts)
fatalOnError(err)
err = configureOS(config)
fatalOnError(err)
// TODO(s.chzhen): Use it for the entire initialization process.
ctx := context.Background()
// Clients package uses filtering package's static data
// (filtering.BlockedSvcKnown()), so we have to initialize filtering static
// data first, but also to avoid relying on automatic Go init() function.
@@ -646,6 +665,7 @@ func run(opts options, clientBuildFS fs.FS, done chan struct{}, sigHdlr *signalH
fatalOnError(err)
tlsMgrLogger := slogLogger.With(slogutil.KeyPrefix, "tls_manager")
tlsMgr, err := newTLSManager(ctx, &tlsManagerConfig{
logger: tlsMgrLogger,
configModified: onConfigModified,
@@ -1131,7 +1151,7 @@ func cmdlineUpdate(
err = upd.Update(ctx, globalContext.firstRun)
fatalOnError(err)
err = restartService()
err = restartService(ctx, l)
if err != nil {
l.DebugContext(ctx, "restarting service", slogutil.KeyError, err)
l.InfoContext(ctx, "AdGuard Home was not installed as a service. "+

View File

@@ -1,8 +1,10 @@
package home
import (
"context"
"fmt"
"io/fs"
"log/slog"
"os"
"runtime"
"strconv"
@@ -13,8 +15,9 @@ import (
"github.com/AdguardTeam/AdGuardHome/internal/aghos"
"github.com/AdguardTeam/AdGuardHome/internal/version"
"github.com/AdguardTeam/golibs/errors"
"github.com/AdguardTeam/golibs/log"
"github.com/AdguardTeam/golibs/logutil/slogutil"
"github.com/AdguardTeam/golibs/netutil/urlutil"
"github.com/AdguardTeam/golibs/osutil"
"github.com/kardianos/service"
)
@@ -32,10 +35,14 @@ const (
// program represents the program that will be launched by as a service or a
// daemon.
type program struct {
// TODO(s.chzhen): Remove this.
ctx context.Context
clientBuildFS fs.FS
signals chan os.Signal
done chan struct{}
opts options
baseLogger *slog.Logger
logger *slog.Logger
sigHdlr *signalHandler
}
@@ -48,14 +55,14 @@ func (p *program) Start(_ service.Service) (err error) {
args := p.opts
args.runningAsService = true
go run(args, p.clientBuildFS, p.done, p.sigHdlr)
go run(p.ctx, p.baseLogger, args, p.clientBuildFS, p.done, p.sigHdlr)
return nil
}
// Stop implements service.Interface interface for *program.
func (p *program) Stop(_ service.Service) (err error) {
log.Info("service: stopping: waiting for cleanup")
p.logger.InfoContext(p.ctx, "stopping: waiting for cleanup")
aghos.SendShutdownSignal(p.signals)
@@ -84,14 +91,14 @@ func svcStatus(s service.Service) (status service.Status, err error) {
return status, err
}
// svcAction performs the action on the service.
// svcAction performs the action on the service. l must not be nil.
//
// On OpenWrt, the service utility may not exist. We use our service script
// directly in this case.
func svcAction(s service.Service, action string) (err error) {
func svcAction(ctx context.Context, l *slog.Logger, s service.Service, action string) (err error) {
if action == "start" {
if err = aghos.PreCheckActionStart(); err != nil {
log.Error("starting service: %s", err)
l.ErrorContext(ctx, "starting service", slogutil.KeyError, err)
}
}
@@ -105,10 +112,10 @@ func svcAction(s service.Service, action string) (err error) {
}
// Send SIGHUP to a process with PID taken from our .pid file. If it doesn't
// exist, find our PID using 'ps' command.
func sendSigReload() {
// exist, find our PID using 'ps' command. baseLogger and l must not be nil.
func sendSigReload(ctx context.Context, baseLogger, l *slog.Logger) {
if runtime.GOOS == "windows" {
log.Error("service: not implemented on windows")
l.ErrorContext(ctx, "not implemented on windows")
return
}
@@ -117,25 +124,26 @@ func sendSigReload() {
var pid int
data, err := os.ReadFile(pidFile)
if errors.Is(err, os.ErrNotExist) {
if pid, err = aghos.PIDByCommand(serviceName, os.Getpid()); err != nil {
log.Error("service: finding AdGuardHome process: %s", err)
aghosLogger := baseLogger.With(slogutil.KeyPrefix, "aghos")
if pid, err = aghos.PIDByCommand(ctx, aghosLogger, serviceName, os.Getpid()); err != nil {
l.ErrorContext(ctx, "finding adguardhome process", slogutil.KeyError, err)
return
}
} else if err != nil {
log.Error("service: reading pid file %s: %s", pidFile, err)
l.ErrorContext(ctx, "reading", "pid_file", pidFile, slogutil.KeyError, err)
return
} else {
parts := strings.SplitN(string(data), "\n", 2)
if len(parts) == 0 {
log.Error("service: parsing pid file %s: bad value", pidFile)
l.ErrorContext(ctx, "splitting", "pid_file", pidFile, slogutil.KeyError, "bad value")
return
}
if pid, err = strconv.Atoi(strings.TrimSpace(parts[0])); err != nil {
log.Error("service: parsing pid from file %s: %s", pidFile, err)
l.ErrorContext(ctx, "parsing", "pid_file", pidFile, slogutil.KeyError, err)
return
}
@@ -143,23 +151,23 @@ func sendSigReload() {
var proc *os.Process
if proc, err = os.FindProcess(pid); err != nil {
log.Error("service: finding process for pid %d: %s", pid, err)
l.ErrorContext(ctx, "finding process for", "pid", pid, slogutil.KeyError, err)
return
}
if err = proc.Signal(syscall.SIGHUP); err != nil {
log.Error("service: sending signal HUP to pid %d: %s", pid, err)
l.ErrorContext(ctx, "sending sighup to", "pid", pid, slogutil.KeyError, err)
return
}
log.Debug("service: sent signal to pid %d", pid)
l.DebugContext(ctx, "sent sighup to", "pid", pid)
}
// restartService restarts the service. It returns error if the service is not
// running.
func restartService() (err error) {
// running. l must not be nil.
func restartService(ctx context.Context, l *slog.Logger) (err error) {
// Call chooseSystem explicitly to introduce OpenBSD support for service
// package. It's a noop for other GOOS values.
chooseSystem()
@@ -182,7 +190,7 @@ func restartService() (err error) {
return fmt.Errorf("initializing service: %w", err)
}
if err = svcAction(s, "restart"); err != nil {
if err = svcAction(ctx, l, s, "restart"); err != nil {
return fmt.Errorf("restarting service: %w", err)
}
@@ -201,6 +209,9 @@ func restartService() (err error) {
// it is specified when we register a service, and it indicates to the app
// that it is being run as a service/daemon.
func handleServiceControlAction(
ctx context.Context,
baseLogger *slog.Logger,
l *slog.Logger,
opts options,
clientBuildFS fs.FS,
signals chan os.Signal,
@@ -212,25 +223,26 @@ func handleServiceControlAction(
chooseSystem()
action := opts.serviceControlAction
log.Info("%s", version.Full())
log.Info("service: control action: %s", action)
l.InfoContext(ctx, version.Full())
l.InfoContext(ctx, "control", "action", action)
if action == "reload" {
sendSigReload()
sendSigReload(ctx, baseLogger, l)
return
}
pwd, err := os.Getwd()
if err != nil {
log.Fatalf("service: getting current directory: %s", err)
l.ErrorContext(ctx, "getting current directory", slogutil.KeyError, err)
os.Exit(osutil.ExitCodeFailure)
}
runOpts := opts
runOpts.serviceControlAction = "run"
args := optsToArgs(runOpts)
log.Debug("service: using args %q", args)
l.DebugContext(ctx, "using", "args", args)
svcConfig := &service.Config{
Name: serviceName,
@@ -242,33 +254,45 @@ func handleServiceControlAction(
configureService(svcConfig)
s, err := service.New(&program{
ctx: ctx,
clientBuildFS: clientBuildFS,
signals: signals,
done: done,
opts: runOpts,
baseLogger: l,
logger: l.With(slogutil.KeyPrefix, "service"),
sigHdlr: sigHdlr,
}, svcConfig)
if err != nil {
log.Fatalf("service: initializing service: %s", err)
l.ErrorContext(ctx, "initializing service", slogutil.KeyError, err)
os.Exit(osutil.ExitCodeFailure)
}
err = handleServiceCommand(s, action, opts)
err = handleServiceCommand(ctx, l, s, action, opts)
if err != nil {
log.Fatalf("service: %s", err)
l.ErrorContext(ctx, "handling command", slogutil.KeyError, err)
os.Exit(osutil.ExitCodeFailure)
}
log.Printf(
"service: action %s has been done successfully on %s",
action,
service.ChosenSystem(),
l.InfoContext(
ctx,
"action has been done successfully",
"action", action,
"system", service.ChosenSystem(),
)
}
// handleServiceCommand handles service command.
func handleServiceCommand(s service.Service, action string, opts options) (err error) {
func handleServiceCommand(
ctx context.Context,
l *slog.Logger,
s service.Service,
action string,
opts options,
) (err error) {
switch action {
case "status":
handleServiceStatusCommand(s)
handleServiceStatusCommand(ctx, l, s)
case "run":
if err = s.Run(); err != nil {
return fmt.Errorf("failed to run service: %w", err)
@@ -280,11 +304,11 @@ func handleServiceCommand(s service.Service, action string, opts options) (err e
initConfigFilename(opts)
handleServiceInstallCommand(s)
handleServiceInstallCommand(ctx, l, s)
case "uninstall":
handleServiceUninstallCommand(s)
handleServiceUninstallCommand(ctx, l, s)
default:
if err = svcAction(s, action); err != nil {
if err = svcAction(ctx, l, s, action); err != nil {
return fmt.Errorf("executing action %q: %w", action, err)
}
}
@@ -297,29 +321,35 @@ func handleServiceCommand(s service.Service, action string, opts options) (err e
const statusRestartOnFail = service.StatusStopped + 1
// handleServiceStatusCommand handles service "status" command.
func handleServiceStatusCommand(s service.Service) {
func handleServiceStatusCommand(
ctx context.Context,
l *slog.Logger,
s service.Service,
) {
status, errSt := svcStatus(s)
if errSt != nil {
log.Fatalf("service: failed to get service status: %s", errSt)
l.ErrorContext(ctx, "failed to get service status", slogutil.KeyError, errSt)
os.Exit(osutil.ExitCodeFailure)
}
switch status {
case service.StatusUnknown:
log.Printf("service: status is unknown")
l.InfoContext(ctx, "status is unknown")
case service.StatusStopped:
log.Printf("service: stopped")
l.InfoContext(ctx, "stopped")
case service.StatusRunning:
log.Printf("service: running")
l.InfoContext(ctx, "running")
case statusRestartOnFail:
log.Printf("service: restarting after failed start")
l.InfoContext(ctx, "restarting after failed start")
}
}
// handleServiceInstallCommand handles service "install" command.
func handleServiceInstallCommand(s service.Service) {
err := svcAction(s, "install")
func handleServiceInstallCommand(ctx context.Context, l *slog.Logger, s service.Service) {
err := svcAction(ctx, l, s, "install")
if err != nil {
log.Fatalf("service: executing action %q: %s", "install", err)
l.ErrorContext(ctx, "executing install", slogutil.KeyError, err)
os.Exit(osutil.ExitCodeFailure)
}
if aghos.IsOpenWrt() {
@@ -328,56 +358,60 @@ func handleServiceInstallCommand(s service.Service) {
// startup.
_, err = runInitdCommand("enable")
if err != nil {
log.Fatalf("service: running init enable: %s", err)
l.ErrorContext(ctx, "running init enable", slogutil.KeyError, err)
os.Exit(osutil.ExitCodeFailure)
}
}
// Start automatically after install.
err = svcAction(s, "start")
err = svcAction(ctx, l, s, "start")
if err != nil {
log.Fatalf("service: starting: %s", err)
l.ErrorContext(ctx, "starting", slogutil.KeyError, err)
os.Exit(osutil.ExitCodeFailure)
}
log.Printf("service: started")
l.InfoContext(ctx, "started")
if detectFirstRun() {
log.Printf(`Almost ready!
AdGuard Home is successfully installed and will automatically start on boot.
There are a few more things that must be configured before you can use it.
Click on the link below and follow the Installation Wizard steps to finish setup.
AdGuard Home is now available at the following addresses:`)
slogutil.PrintLines(ctx, l, slog.LevelInfo, "", "Almost ready!\n"+
"AdGuard Home is successfully installed and will automatically start on boot.\n"+
"There are a few more things that must be configured before you can use it.\n"+
"Click on the link below and follow the Installation Wizard steps to finish setup.\n"+
"AdGuard Home is now available at the following addresses:")
printHTTPAddresses(urlutil.SchemeHTTP, nil)
}
}
// handleServiceUninstallCommand handles service "uninstall" command.
func handleServiceUninstallCommand(s service.Service) {
func handleServiceUninstallCommand(ctx context.Context, l *slog.Logger, s service.Service) {
if aghos.IsOpenWrt() {
// On OpenWrt it is important to run disable command first
// as it will remove the symlink
_, err := runInitdCommand("disable")
if err != nil {
log.Fatalf("service: running init disable: %s", err)
l.ErrorContext(ctx, "running init disable", slogutil.KeyError, err)
os.Exit(osutil.ExitCodeFailure)
}
}
if err := svcAction(s, "stop"); err != nil {
log.Debug("service: executing action %q: %s", "stop", err)
if err := svcAction(ctx, l, s, "stop"); err != nil {
l.DebugContext(ctx, "executing action stop", slogutil.KeyError, err)
}
if err := svcAction(s, "uninstall"); err != nil {
log.Fatalf("service: executing action %q: %s", "uninstall", err)
if err := svcAction(ctx, l, s, "uninstall"); err != nil {
l.ErrorContext(ctx, "executing action uninstall", slogutil.KeyError, err)
os.Exit(osutil.ExitCodeFailure)
}
if runtime.GOOS == "darwin" {
// Remove log files on cleanup and log errors.
err := os.Remove(launchdStdoutPath)
if err != nil && !errors.Is(err, os.ErrNotExist) {
log.Info("service: warning: removing stdout file: %s", err)
l.WarnContext(ctx, "removing stdout file", slogutil.KeyError, err)
}
err = os.Remove(launchdStderrPath)
if err != nil && !errors.Is(err, os.ErrNotExist) {
log.Info("service: warning: removing stderr file: %s", err)
l.WarnContext(ctx, "removing stderr file", slogutil.KeyError, err)
}
}
}

View File

@@ -5,7 +5,6 @@ import (
"log/slog"
"os"
"sync"
"sync/atomic"
"syscall"
"github.com/AdguardTeam/AdGuardHome/internal/client"
@@ -16,10 +15,8 @@ import (
// signalHandler processes incoming signals. It reloads configurations of
// stored entities on SIGHUP and performs cleanup on all other signals.
type signalHandler struct {
// logger is used to log the operation of the signal handler. Initially,
// [slog.Default] is used, but it should be swapped later using
// [signalHandler.swapLogger].
logger *atomic.Pointer[slog.Logger]
// logger is used to log the operation of the signal handler.
logger *slog.Logger
// mu protects clientStorage and tlsManager.
mu *sync.Mutex
@@ -41,24 +38,16 @@ type signalHandler struct {
// newSignalHandler returns a new properly initialized *signalHandler.
func newSignalHandler(
l *slog.Logger,
signals <-chan os.Signal,
cleanup func(ctx context.Context),
) (h *signalHandler) {
h = &signalHandler{
logger: &atomic.Pointer[slog.Logger]{},
return &signalHandler{
logger: l,
mu: &sync.Mutex{},
signals: signals,
cleanup: cleanup,
}
h.logger.Store(slog.Default())
return h
}
// swapLogger replaces the stored logger with the given logger.
func (h *signalHandler) swapLogger(logger *slog.Logger) {
h.logger.Swap(logger)
}
// addClientStorage stores the client storage.
@@ -89,14 +78,14 @@ func (h *signalHandler) handle(ctx context.Context) {
return
}
slogutil.PrintRecovered(ctx, h.logger.Load(), v)
slogutil.PrintRecovered(ctx, h.logger, v)
os.Exit(osutil.ExitCodeFailure)
}()
for {
sig := <-h.signals
h.logger.Load().InfoContext(ctx, "received signal", "signal", sig)
h.logger.InfoContext(ctx, "received signal", "signal", sig)
switch sig {
case syscall.SIGHUP:
h.reloadConfig(ctx)

View File

@@ -99,7 +99,7 @@ func newTLSManager(ctx context.Context, conf *tlsManagerConfig) (m *tlsManager,
servePlainDNS: conf.servePlainDNS,
}
m.rootCerts = aghtls.SystemRootCAs()
m.rootCerts = aghtls.SystemRootCAs(ctx, conf.logger)
if len(conf.tlsSettings.OverrideTLSCiphers) > 0 {
m.customCipherIDs, err = aghtls.ParseCiphers(config.TLS.OverrideTLSCiphers)