From fce1bf475f33f6fe45252e2276ea8ebf2a82a8b2 Mon Sep 17 00:00:00 2001 From: Stanislav Chzhen Date: Mon, 2 Dec 2024 18:20:31 +0300 Subject: [PATCH] home: slog webapi --- internal/home/controlinstall.go | 6 +-- internal/home/controlupdate.go | 13 +++++-- internal/home/dns.go | 2 +- internal/home/home.go | 18 ++++----- internal/home/web.go | 66 ++++++++++++++++++++------------- 5 files changed, 63 insertions(+), 42 deletions(-) diff --git a/internal/home/controlinstall.go b/internal/home/controlinstall.go index 3051f0f6..bad59c59 100644 --- a/internal/home/controlinstall.go +++ b/internal/home/controlinstall.go @@ -20,6 +20,7 @@ import ( "github.com/AdguardTeam/AdGuardHome/internal/version" "github.com/AdguardTeam/golibs/errors" "github.com/AdguardTeam/golibs/log" + "github.com/AdguardTeam/golibs/logutil/slogutil" "github.com/quic-go/quic-go/http3" ) @@ -436,7 +437,7 @@ func (web *webAPI) handleInstallConfigure(w http.ResponseWriter, r *http.Request // moment we'll allow setting up TLS in the initial configuration or the // configuration itself will use HTTPS protocol, because the underlying // functions potentially restart the HTTPS server. - err = startMods(web.logger) + err = startMods(web.baseLogger) if err != nil { Context.firstRun = true copyInstallSettings(config, curConfig) @@ -472,9 +473,8 @@ func (web *webAPI) handleInstallConfigure(w http.ResponseWriter, r *http.Request // and with its own context, because it waits until all requests are handled // and will be blocked by it's own caller. go func(timeout time.Duration) { - defer log.OnPanic("web") - ctx, cancel := context.WithTimeout(context.Background(), timeout) + defer slogutil.RecoverAndLog(ctx, web.logger) defer cancel() shutdownSrv(ctx, web.httpServer) diff --git a/internal/home/controlupdate.go b/internal/home/controlupdate.go index aeab8810..0febddb4 100644 --- a/internal/home/controlupdate.go +++ b/internal/home/controlupdate.go @@ -17,6 +17,7 @@ import ( "github.com/AdguardTeam/AdGuardHome/internal/updater" "github.com/AdguardTeam/golibs/errors" "github.com/AdguardTeam/golibs/log" + "github.com/AdguardTeam/golibs/logutil/slogutil" ) // temporaryError is the interface for temporary errors from the Go standard @@ -52,7 +53,7 @@ func (web *webAPI) handleVersionJSON(w http.ResponseWriter, r *http.Request) { } } - err = web.requestVersionInfo(resp, req.Recheck) + err = web.requestVersionInfo(r.Context(), resp, req.Recheck) if err != nil { // Don't wrap the error, because it's informative enough as is. aghhttp.Error(r, w, http.StatusBadGateway, "%s", err) @@ -73,7 +74,11 @@ func (web *webAPI) handleVersionJSON(w http.ResponseWriter, r *http.Request) { // requestVersionInfo sets the VersionInfo field of resp if it can reach the // update server. -func (web *webAPI) requestVersionInfo(resp *versionResponse, recheck bool) (err error) { +func (web *webAPI) requestVersionInfo( + ctx context.Context, + resp *versionResponse, + recheck bool, +) (err error) { updater := web.conf.updater for range 3 { resp.VersionInfo, err = updater.VersionInfo(recheck) @@ -89,7 +94,9 @@ func (web *webAPI) requestVersionInfo(resp *versionResponse, recheck bool) (err // See https://github.com/AdguardTeam/AdGuardHome/issues/934. const sleepTime = 2 * time.Second - log.Info("update: temp net error: %v; sleeping for %s and retrying", err, sleepTime) + err = fmt.Errorf("temp net error: %w; sleeping for %s and retrying", err, sleepTime) + web.logger.ErrorContext(ctx, "updating version info", slogutil.KeyError, err) + time.Sleep(sleepTime) continue diff --git a/internal/home/dns.go b/internal/home/dns.go index 5b07e795..1c1fb202 100644 --- a/internal/home/dns.go +++ b/internal/home/dns.go @@ -47,7 +47,7 @@ func onConfigModified() { // initDNS updates all the fields of the [Context] needed to initialize the DNS // server and initializes it at last. It also must not be called unless -// [config] and [Context] are initialized. l must not be nil. +// [config] and [Context] are initialized. baseLogger must not be nil. func initDNS(baseLogger *slog.Logger, statsDir, querylogDir string) (err error) { anonymizer := config.anonymizer() diff --git a/internal/home/home.go b/internal/home/home.go index 5f573876..40ef7c6c 100644 --- a/internal/home/home.go +++ b/internal/home/home.go @@ -522,13 +522,13 @@ func isUpdateEnabled(ctx context.Context, l *slog.Logger, opts *options, customU } } -// initWeb initializes the web module. +// initWeb initializes the web module. upd and baseLogger must not be nil. func initWeb( ctx context.Context, opts options, clientBuildFS fs.FS, upd *updater.Updater, - l *slog.Logger, + baseLogger *slog.Logger, customURL bool, ) (web *webAPI, err error) { var clientFS fs.FS @@ -543,7 +543,7 @@ func initWeb( } } - disableUpdate := !isUpdateEnabled(ctx, l, &opts, customURL) + disableUpdate := !isUpdateEnabled(ctx, baseLogger, &opts, customURL) webConf := &webConfig{ updater: upd, @@ -562,7 +562,7 @@ func initWeb( serveHTTP3: config.DNS.ServeHTTP3, } - web = newWebAPI(webConf, l) + web = newWebAPI(ctx, webConf, baseLogger) if web == nil { return nil, errors.Error("can not initialize web") } @@ -692,7 +692,7 @@ func run(opts options, clientBuildFS fs.FS, done chan struct{}) { checkPermissions(Context.workDir, confPath, dataDir, statsDir, querylogDir) } - Context.web.start() + Context.web.start(ctx) // Wait for other goroutines to complete their job. <-done @@ -793,15 +793,15 @@ func (c *configuration) anonymizer() (ipmut *aghnet.IPMut) { return aghnet.NewIPMut(anonFunc) } -// startMods initializes and starts the DNS server after installation. l must -// not be nil. -func startMods(l *slog.Logger) (err error) { +// startMods initializes and starts the DNS server after installation. +// baseLogger must not be nil. +func startMods(baseLogger *slog.Logger) (err error) { statsDir, querylogDir, err := checkStatsAndQuerylogDirs(&Context, config) if err != nil { return err } - err = initDNS(l, statsDir, querylogDir) + err = initDNS(baseLogger, statsDir, querylogDir) if err != nil { return err } diff --git a/internal/home/web.go b/internal/home/web.go index 1909720b..21110948 100644 --- a/internal/home/web.go +++ b/internal/home/web.go @@ -3,6 +3,7 @@ package home import ( "context" "crypto/tls" + "fmt" "io/fs" "log/slog" "net/http" @@ -15,6 +16,7 @@ import ( "github.com/AdguardTeam/AdGuardHome/internal/updater" "github.com/AdguardTeam/golibs/errors" "github.com/AdguardTeam/golibs/log" + "github.com/AdguardTeam/golibs/logutil/slogutil" "github.com/AdguardTeam/golibs/netutil" "github.com/AdguardTeam/golibs/netutil/httputil" "github.com/AdguardTeam/golibs/netutil/urlutil" @@ -94,21 +96,27 @@ type webAPI struct { // logger is a slog logger used in webAPI. It must not be nil. logger *slog.Logger + // baseLogger is used to create loggers for other entities. It must not be + // nil. + baseLogger *slog.Logger + // httpsServer is the server that handles HTTPS traffic. If it is not nil, // [Web.http3Server] must also not be nil. httpsServer httpsServer } -// newWebAPI creates a new instance of the web UI and API server. l must not be -// nil. +// newWebAPI creates a new instance of the web UI and API server. baseLogger +// must not be nil. // // TODO(a.garipov): Return a proper error. -func newWebAPI(conf *webConfig, l *slog.Logger) (w *webAPI) { - log.Info("web: initializing") +func newWebAPI(ctx context.Context, conf *webConfig, baseLogger *slog.Logger) (w *webAPI) { + logger := baseLogger.With(slogutil.KeyPrefix, "webapi") + logger.InfoContext(ctx, "initializing") w = &webAPI{ - conf: conf, - logger: l, + conf: conf, + logger: logger, + baseLogger: baseLogger, } clientFS := http.FileServer(http.FS(conf.clientFS)) @@ -118,7 +126,11 @@ func newWebAPI(conf *webConfig, l *slog.Logger) (w *webAPI) { // add handlers for /install paths, we only need them when we're not configured yet if conf.firstRun { - log.Info("This is the first launch of AdGuard Home, redirecting everything to /install.html ") + logger.InfoContext( + ctx, + "This is the first launch of AdGuard Home, redirecting everything to /install.html", + ) + Context.mux.Handle("/install.html", preInstallHandler(clientFS)) w.registerInstallHandlers() } else { @@ -154,7 +166,9 @@ func webCheckPortAvailable(port uint16) (ok bool) { // tlsConfigChanged updates the TLS configuration and restarts the HTTPS server // if necessary. func (web *webAPI) tlsConfigChanged(ctx context.Context, tlsConf tlsConfigSettings) { - log.Debug("web: applying new tls configuration") + defer slogutil.RecoverAndLog(ctx, web.logger) + + web.logger.DebugContext(ctx, "applying new tls configuration") enabled := tlsConf.Enabled && tlsConf.PortHTTPS != 0 && @@ -165,7 +179,7 @@ func (web *webAPI) tlsConfigChanged(ctx context.Context, tlsConf tlsConfigSettin if enabled { cert, err = tls.X509KeyPair(tlsConf.CertificateChainData, tlsConf.PrivateKeyData) if err != nil { - log.Fatal(err) + panic(err) } } @@ -186,11 +200,13 @@ func (web *webAPI) tlsConfigChanged(ctx context.Context, tlsConf tlsConfigSettin } // start - start serving HTTP requests -func (web *webAPI) start() { - log.Println("AdGuard Home is available at the following addresses:") +func (web *webAPI) start(ctx context.Context) { + web.logger.InfoContext(ctx, "AdGuard Home is available at the following addresses:") + + defer slogutil.RecoverAndLog(ctx, web.logger) // for https, we have a separate goroutine loop - go web.tlsServerLoop() + go web.tlsServerLoop(ctx) // this loop is used as an ability to change listening host and/or port for !web.httpsServer.inShutdown { @@ -210,15 +226,13 @@ func (web *webAPI) start() { WriteTimeout: web.conf.WriteTimeout, } go func() { - defer log.OnPanic("web: plain") - errs <- web.httpServer.ListenAndServe() }() err := <-errs if !errors.Is(err, http.ErrServerClosed) { cleanupAlways() - log.Fatal(err) + panic(err) } // We use ErrServerClosed as a sign that we need to rebind on a new @@ -228,7 +242,7 @@ func (web *webAPI) start() { // close gracefully shuts down the HTTP servers. func (web *webAPI) close(ctx context.Context) { - log.Info("stopping http server...") + web.logger.InfoContext(ctx, "stopping http server") web.httpsServer.cond.L.Lock() web.httpsServer.inShutdown = true @@ -242,10 +256,12 @@ func (web *webAPI) close(ctx context.Context) { shutdownSrv3(web.httpsServer.server3) shutdownSrv(ctx, web.httpServer) - log.Info("stopped http server") + web.logger.InfoContext(ctx, "stopped http server") } -func (web *webAPI) tlsServerLoop() { +func (web *webAPI) tlsServerLoop(ctx context.Context) { + defer slogutil.RecoverAndLog(ctx, web.logger) + for { web.httpsServer.cond.L.Lock() if web.httpsServer.inShutdown { @@ -291,21 +307,19 @@ func (web *webAPI) tlsServerLoop() { printHTTPAddresses(urlutil.SchemeHTTPS) if web.conf.serveHTTP3 { - go web.mustStartHTTP3(addr) + go web.mustStartHTTP3(ctx, addr) } - log.Debug("web: starting https server") + web.logger.DebugContext(ctx, "starting https server") err := web.httpsServer.server.ListenAndServeTLS("", "") if !errors.Is(err, http.ErrServerClosed) { cleanupAlways() - log.Fatalf("web: https: %s", err) + panic(fmt.Errorf("https: %w", err)) } } } -func (web *webAPI) mustStartHTTP3(address string) { - defer log.OnPanic("web: http3") - +func (web *webAPI) mustStartHTTP3(ctx context.Context, address string) { web.httpsServer.server3 = &http3.Server{ // TODO(a.garipov): See if there is a way to use the error log as // well as timeouts here. @@ -319,11 +333,11 @@ func (web *webAPI) mustStartHTTP3(address string) { Handler: withMiddlewares(Context.mux, limitRequestBody), } - log.Debug("web: starting http/3 server") + web.logger.DebugContext(ctx, "starting http/3 server") err := web.httpsServer.server3.ListenAndServe() if !errors.Is(err, http.ErrServerClosed) { cleanupAlways() - log.Fatalf("web: http3: %s", err) + panic(fmt.Errorf("http3: %w", err)) } }