From ed4279b6f330bea5a70b2256e8bdab528107a164 Mon Sep 17 00:00:00 2001 From: Elle Mouton Date: Wed, 27 Nov 2024 10:15:07 +0200 Subject: [PATCH] lnd: update Main logs to use structured logging --- lnd.go | 80 ++++++++++++++++++++++++++++++---------------------------- 1 file changed, 42 insertions(+), 38 deletions(-) diff --git a/lnd.go b/lnd.go index 5507b2b80..d00294bc2 100644 --- a/lnd.go +++ b/lnd.go @@ -149,7 +149,7 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, interceptor signal.Interceptor) error { defer func() { - ltndLog.Info("Shutdown complete\n") + ltndLog.Info("Shutdown complete") err := cfg.LogRotator.Close() if err != nil { ltndLog.Errorf("Could not close log rotator: %v", err) @@ -183,9 +183,11 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, } // Show version at startup. - ltndLog.Infof("Version: %s commit=%s, build=%s, logging=%s, "+ - "debuglevel=%s", build.Version(), build.Commit, - build.Deployment, build.LoggingType, cfg.DebugLevel) + ltndLog.InfoS(ctx, "Version Info", + slog.String("version", build.Version()), + slog.String("commit", build.Commit), + slog.Any("debuglevel", build.Deployment), + slog.String("logging", cfg.DebugLevel)) var network string switch { @@ -205,9 +207,9 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, network = "signet" } - ltndLog.Infof("Active chain: %v (network=%v)", - strings.Title(BitcoinChainName), network, - ) + ltndLog.InfoS(ctx, "Network Info", + "active_chain", strings.Title(BitcoinChainName), + "network", network) // Enable http profiling server if requested. if cfg.Pprof.Profile != "" { @@ -233,7 +235,7 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, "/debug/pprof/", http.StatusSeeOther, )) - ltndLog.Infof("Pprof listening on %v", cfg.Pprof.Profile) + ltndLog.InfoS(ctx, "Pprof listening", "addr", cfg.Pprof.Profile) // Create the pprof server. pprofServer := &http.Server{ @@ -244,11 +246,10 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, // Shut the server down when lnd is shutting down. defer func() { - ltndLog.Info("Stopping pprof server...") + ltndLog.InfoS(ctx, "Stopping pprof server...") err := pprofServer.Shutdown(ctx) if err != nil { - ltndLog.Errorf("Stop pprof server got err: %v", - err) + ltndLog.ErrorS(ctx, "Stop pprof server", err) } }() @@ -256,7 +257,8 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, go func() { err := pprofServer.ListenAndServe() if err != nil && !errors.Is(err, http.ErrServerClosed) { - ltndLog.Errorf("Serving pprof got err: %v", err) + ltndLog.ErrorS(ctx, "Could not serve pprof "+ + "server", err) } }() } @@ -420,8 +422,8 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, cancelElection() }() - ltndLog.Infof("Using %v leader elector", - cfg.Cluster.LeaderElector) + ltndLog.InfoS(ctx, "Using leader elector", + "elector", cfg.Cluster.LeaderElector) leaderElector, err = cfg.Cluster.MakeLeaderElector( electionCtx, cfg.DB, @@ -435,8 +437,8 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, return } - ltndLog.Infof("Attempting to resign from leader role "+ - "(%v)", cfg.Cluster.ID) + ltndLog.InfoS(ctx, "Attempting to resign from "+ + "leader role", "cluster_id", cfg.Cluster.ID) // Ensure that we don't block the shutdown process if // the leader resigning process takes too long. The @@ -454,21 +456,23 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, } }() - ltndLog.Infof("Starting leadership campaign (%v)", - cfg.Cluster.ID) + ltndLog.InfoS(ctx, "Starting leadership campaign", + "cluster_id", cfg.Cluster.ID) if err := leaderElector.Campaign(electionCtx); err != nil { return mkErr("leadership campaign failed", err) } elected = true - ltndLog.Infof("Elected as leader (%v)", cfg.Cluster.ID) + ltndLog.InfoS(ctx, "Elected as leader", + "cluster_id", cfg.Cluster.ID) } dbs, cleanUp, err := implCfg.DatabaseBuilder.BuildDatabase(ctx) switch { case err == channeldb.ErrDryRunMigrationOK: - ltndLog.Infof("%v, exiting", err) + ltndLog.InfoS(ctx, "Exiting due to BuildDatabase error", + slog.Any("err", err)) return nil case err != nil: return mkErr("unable to open databases", err) @@ -512,14 +516,14 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, if cfg.Tor.Active { if cfg.Tor.SkipProxyForClearNetTargets { - srvrLog.Info("Onion services are accessible via Tor! " + - "NOTE: Traffic to clearnet services is not " + - "routed via Tor.") + srvrLog.InfoS(ctx, "Onion services are accessible "+ + "via Tor! NOTE: Traffic to clearnet services "+ + "is not routed via Tor.") } else { - srvrLog.Infof("Proxying all network traffic via Tor "+ - "(stream_isolation=%v)! NOTE: Ensure the "+ - "backend node is proxying over Tor as well", - cfg.Tor.StreamIsolation) + srvrLog.InfoS(ctx, "Proxying all network traffic "+ + "via Tor! NOTE: Ensure the backend node is "+ + "proxying over Tor as well", + "stream_isolation", cfg.Tor.StreamIsolation) } } @@ -541,8 +545,8 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, } defer func() { if err := torController.Stop(); err != nil { - ltndLog.Errorf("error stopping tor "+ - "controller: %v", err) + ltndLog.ErrorS(ctx, "Error stopping tor "+ + "controller", err) } }() } @@ -684,8 +688,8 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, return mkErr("unable to determine chain tip", err) } - ltndLog.Infof("Waiting for chain backend to finish sync, "+ - "start_height=%v", bestHeight) + ltndLog.InfoS(ctx, "Waiting for chain backend to finish sync", + slog.Int64("start_height", int64(bestHeight))) type syncResult struct { synced bool @@ -715,9 +719,9 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, "is synced", res.err) } - ltndLog.Debugf("Syncing to block timestamp: %v, is "+ - "synced=%v", time.Unix(res.bestBlockTime, 0), - res.synced) + ltndLog.DebugS(ctx, "Syncing to block chain", + "best_block_time", time.Unix(res.bestBlockTime, 0), + "is_synced", res.synced) if res.synced { break @@ -742,8 +746,8 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, return mkErr("unable to determine chain tip", err) } - ltndLog.Infof("Chain backend is fully synced (end_height=%v)!", - bestHeight) + ltndLog.InfoS(ctx, "Chain backend is fully synced!", + "end_height", bestHeight) // With all the relevant chains initialized, we can finally start the // server itself. We start the server in an asynchronous goroutine so @@ -757,8 +761,8 @@ func Main(cfg *Config, lisCfg ListenerCfg, implCfg *ImplementationCfg, defer func() { err := server.Stop() if err != nil { - ltndLog.Warnf("Stopping the server including all "+ - "its subsystems failed with %v", err) + ltndLog.WarnS(ctx, "Stopping the server including all "+ + "its subsystems failed with", err) } }()