Convert TeleportProcess to use slog for logging (#38551)

Begins the conversion away from logrus to slog for all messages emitted from TeleportProcess. The logrus logger should now only be in use for dependency injection to child components that haven't been converted yet. There are still instances of the logrus logger in the process configuration to emit messages, they will be converted in a follow up PR.
gravitational · Mar 12, 2024 · 34aa080 · 34aa080
1 parent 2a29d63
commit 34aa080
Show file tree

Hide file tree

Showing 10 changed files with 426 additions and 454 deletions.
diff --git a/lib/service/awsoidc.go b/lib/service/awsoidc.go
@@ -94,7 +94,7 @@ func (process *TeleportProcess) initAWSOIDCDeployServiceUpdater() error {
 		return trace.Wrap(err)
 	}
 
-	process.log.Infof("The new service has started successfully. Checking for deploy service updates every %v.", updateAWSOIDCDeployServiceInterval)
+	process.logger.InfoContext(process.ExitContext(), "The new service has started successfully.", "update_interval", updateAWSOIDCDeployServiceInterval)
 	return trace.Wrap(updater.Run(process.GracefulExitContext()))
 }
 

diff --git a/lib/service/connect.go b/lib/service/connect.go
diff --git a/lib/service/db.go b/lib/service/db.go
@@ -47,10 +47,9 @@ func (process *TeleportProcess) initDatabases() {
 }
 
 func (process *TeleportProcess) initDatabaseService() (retErr error) {
-	log := process.log.WithField(trace.Component, teleport.Component(
-		teleport.ComponentDatabase, process.id))
+	logger := process.logger.With(trace.Component, teleport.Component(teleport.ComponentDatabase, process.id))
 
-	conn, err := process.WaitForConnector(DatabasesIdentityEvent, log)
+	conn, err := process.WaitForConnector(DatabasesIdentityEvent, logger)
 	if conn == nil {
 		return trace.Wrap(err)
 	}
@@ -88,7 +87,7 @@ func (process *TeleportProcess) initDatabaseService() (retErr error) {
 	lockWatcher, err := services.NewLockWatcher(process.ExitContext(), services.LockWatcherConfig{
 		ResourceWatcherConfig: services.ResourceWatcherConfig{
 			Component: teleport.ComponentDatabase,
-			Log:       log,
+			Log:       process.log.WithField(trace.Component, teleport.Component(teleport.ComponentDatabase, process.id)),
 			Client:    conn.Client,
 		},
 	})
@@ -101,7 +100,7 @@ func (process *TeleportProcess) initDatabaseService() (retErr error) {
 		ClusterName: clusterName,
 		AccessPoint: accessPoint,
 		LockWatcher: lockWatcher,
-		Logger:      log,
+		Logger:      process.log.WithField(trace.Component, teleport.Component(teleport.ComponentDatabase, process.id)),
 	})
 	if err != nil {
 		return trace.Wrap(err)
@@ -117,7 +116,7 @@ func (process *TeleportProcess) initDatabaseService() (retErr error) {
 	}
 	defer func() {
 		if retErr != nil {
-			warnOnErr(asyncEmitter.Close(), process.log)
+			warnOnErr(process.ExitContext(), asyncEmitter.Close(), logger)
 		}
 	}()
 
@@ -171,7 +170,7 @@ func (process *TeleportProcess) initDatabaseService() (retErr error) {
 	}
 	defer func() {
 		if retErr != nil {
-			warnOnErr(dbService.Close(), process.log)
+			warnOnErr(process.ExitContext(), dbService.Close(), logger)
 		}
 	}()
 
@@ -206,25 +205,25 @@ func (process *TeleportProcess) initDatabaseService() (retErr error) {
 	process.OnExit("db.stop", func(payload interface{}) {
 		if dbService != nil {
 			if payload == nil {
-				log.Info("Shutting down immediately.")
-				warnOnErr(dbService.Close(), log)
+				logger.InfoContext(process.ExitContext(), "Shutting down immediately.")
+				warnOnErr(process.ExitContext(), dbService.Close(), logger)
 			} else {
-				log.Info("Shutting down gracefully.")
-				warnOnErr(dbService.Shutdown(payloadContext(payload, log)), log)
+				logger.InfoContext(process.ExitContext(), "Shutting down gracefully.")
+				warnOnErr(process.ExitContext(), dbService.Shutdown(payloadContext(payload)), logger)
 			}
 		}
 		if asyncEmitter != nil {
-			warnOnErr(asyncEmitter.Close(), log)
+			warnOnErr(process.ExitContext(), asyncEmitter.Close(), logger)
 		}
 		if agentPool != nil {
 			agentPool.Stop()
 		}
-		warnOnErr(conn.Close(), log)
-		log.Info("Exited.")
+		warnOnErr(process.ExitContext(), conn.Close(), logger)
+		logger.InfoContext(process.ExitContext(), "Exited.")
 	})
 
 	process.BroadcastEvent(Event{Name: DatabasesReady, Payload: nil})
-	log.Infof("Database service has successfully started: %v.", databases)
+	logger.InfoContext(process.ExitContext(), "Database service has successfully started.", "database", databases)
 
 	// Block and wait while the server and agent pool are running.
 	if err := dbService.Wait(); err != nil {

diff --git a/lib/service/desktop.go b/lib/service/desktop.go
@@ -21,12 +21,12 @@ package service
 import (
 	"crypto/tls"
 	"errors"
+	"log/slog"
 	"net"
 	"net/http"
 	"strconv"
 
 	"github.com/gravitational/trace"
-	"github.com/sirupsen/logrus"
 
 	"github.com/gravitational/teleport"
 	"github.com/gravitational/teleport/api/types"
@@ -45,28 +45,26 @@ import (
 )
 
 func (process *TeleportProcess) initWindowsDesktopService() {
-	log := process.log.WithFields(logrus.Fields{
-		trace.Component: teleport.Component(teleport.ComponentWindowsDesktop, process.id),
-	})
+	logger := process.logger.With(trace.Component, teleport.Component(teleport.ComponentWindowsDesktop, process.id))
 	process.RegisterWithAuthServer(types.RoleWindowsDesktop, WindowsDesktopIdentityEvent)
 	process.RegisterCriticalFunc("windows_desktop.init", func() error {
-		conn, err := process.WaitForConnector(WindowsDesktopIdentityEvent, log)
+		conn, err := process.WaitForConnector(WindowsDesktopIdentityEvent, logger)
 		if conn == nil {
 			return trace.Wrap(err)
 		}
 
-		if err := process.initWindowsDesktopServiceRegistered(log, conn); err != nil {
-			warnOnErr(conn.Close(), log)
+		if err := process.initWindowsDesktopServiceRegistered(logger, conn); err != nil {
+			warnOnErr(process.ExitContext(), conn.Close(), logger)
 			return trace.Wrap(err)
 		}
 		return nil
 	})
 }
 
-func (process *TeleportProcess) initWindowsDesktopServiceRegistered(log *logrus.Entry, conn *Connector) (retErr error) {
+func (process *TeleportProcess) initWindowsDesktopServiceRegistered(logger *slog.Logger, conn *Connector) (retErr error) {
 	defer func() {
 		if err := process.closeImportedDescriptors(teleport.ComponentWindowsDesktop); err != nil {
-			log.WithError(err).Warn("Failed closing imported file descriptors.")
+			logger.WarnContext(process.ExitContext(), "Failed closing imported file descriptors.")
 		}
 	}()
 	cfg := process.Config
@@ -99,14 +97,14 @@ func (process *TeleportProcess) initWindowsDesktopServiceRegistered(log *logrus.
 
 	// Start a local listener and let proxies dial in.
 	case !useTunnel && !cfg.WindowsDesktop.ListenAddr.IsEmpty():
-		log.Info("Using local listener and registering directly with auth server")
+		logger.InfoContext(process.ExitContext(), "Using local listener and registering directly with auth server")
 		listener, err = process.importOrCreateListener(ListenerWindowsDesktop, cfg.WindowsDesktop.ListenAddr.Addr)
 		if err != nil {
 			return trace.Wrap(err)
 		}
 		defer func() {
 			if retErr != nil {
-				warnOnErr(listener.Close(), log)
+				warnOnErr(process.ExitContext(), listener.Close(), logger)
 			}
 		}()
 
@@ -140,13 +138,13 @@ func (process *TeleportProcess) initWindowsDesktopServiceRegistered(log *logrus.
 				agentPool.Stop()
 			}
 		}()
-		log.Info("Using a reverse tunnel to register and handle proxy connections")
+		logger.InfoContext(process.ExitContext(), "Using a reverse tunnel to register and handle proxy connections")
 	}
 
 	lockWatcher, err := services.NewLockWatcher(process.ExitContext(), services.LockWatcherConfig{
 		ResourceWatcherConfig: services.ResourceWatcherConfig{
 			Component: teleport.ComponentWindowsDesktop,
-			Log:       log,
+			Log:       process.log.WithField(trace.Component, teleport.Component(teleport.ComponentWindowsDesktop, process.id)),
 			Clock:     cfg.Clock,
 			Client:    conn.Client,
 		},
@@ -161,7 +159,7 @@ func (process *TeleportProcess) initWindowsDesktopServiceRegistered(log *logrus.
 		ClusterName: clusterName,
 		AccessPoint: accessPoint,
 		LockWatcher: lockWatcher,
-		Logger:      log,
+		Logger:      process.log.WithField(trace.Component, teleport.Component(teleport.ComponentWindowsDesktop, process.id)),
 		// Device authorization breaks browser-based access.
 		DeviceAuthorization: authz.DeviceAuthorizationOpts{
 			DisableGlobalMode: true,
@@ -184,7 +182,7 @@ func (process *TeleportProcess) initWindowsDesktopServiceRegistered(log *logrus.
 		if info.ServerName != "" {
 			clusterName, err = apiutils.DecodeClusterName(info.ServerName)
 			if err != nil && !trace.IsNotFound(err) {
-				log.Debugf("Ignoring unsupported cluster name %q.", info.ServerName)
+				logger.DebugContext(process.ExitContext(), "Ignoring unsupported cluster name.", "cluster_name", info.ServerName)
 			}
 		}
 		pool, _, err := auth.DefaultClientCertPool(accessPoint, clusterName)
@@ -214,7 +212,7 @@ func (process *TeleportProcess) initWindowsDesktopServiceRegistered(log *logrus.
 
 	srv, err := desktop.NewWindowsService(desktop.WindowsServiceConfig{
 		DataDir:      process.Config.DataDir,
-		Log:          log,
+		Log:          process.log.WithField(trace.Component, teleport.Component(teleport.ComponentWindowsDesktop, process.id)),
 		Clock:        process.Clock,
 		Authorizer:   authorizer,
 		Emitter:      conn.Client,
@@ -245,14 +243,14 @@ func (process *TeleportProcess) initWindowsDesktopServiceRegistered(log *logrus.
 	}
 	defer func() {
 		if retErr != nil {
-			warnOnErr(srv.Close(), log)
+			warnOnErr(process.ExitContext(), srv.Close(), logger)
 		}
 	}()
 	process.RegisterCriticalFunc("windows_desktop.serve", func() error {
 		if useTunnel {
-			log.Info("Starting Windows desktop service via proxy reverse tunnel.")
+			logger.InfoContext(process.ExitContext(), "Starting Windows desktop service via proxy reverse tunnel.")
 		} else {
-			log.Infof("Starting Windows desktop service on %v.", listener.Addr())
+			logger.InfoContext(process.ExitContext(), "Starting Windows desktop service.", "listen_address", listener.Addr())
 		}
 		process.BroadcastEvent(Event{Name: WindowsDesktopReady, Payload: nil})
 
@@ -287,16 +285,16 @@ func (process *TeleportProcess) initWindowsDesktopServiceRegistered(log *logrus.
 	// Cleanup, when process is exiting.
 	process.OnExit("windows_desktop.shutdown", func(payload interface{}) {
 		// Fast shutdown.
-		warnOnErr(srv.Close(), log)
+		warnOnErr(process.ExitContext(), srv.Close(), logger)
 		agentPool.Stop()
 		if payload != nil {
 			// Graceful shutdown.
 			agentPool.Wait()
 		}
-		warnOnErr(listener.Close(), log)
-		warnOnErr(conn.Close(), log)
+		warnOnErr(process.ExitContext(), listener.Close(), logger)
+		warnOnErr(process.ExitContext(), conn.Close(), logger)
 
-		log.Info("Exited.")
+		logger.InfoContext(process.ExitContext(), "Exited.")
 	})
 	return nil
 }
diff --git a/lib/service/discovery.go b/lib/service/discovery.go
@@ -37,10 +37,9 @@ func (process *TeleportProcess) initDiscovery() {
 }
 
 func (process *TeleportProcess) initDiscoveryService() error {
-	log := process.log.WithField(trace.Component, teleport.Component(
-		teleport.ComponentDiscovery, process.id))
+	logger := process.logger.With(trace.Component, teleport.Component(teleport.ComponentDiscovery, process.id))
 
-	conn, err := process.WaitForConnector(DiscoveryIdentityEvent, log)
+	conn, err := process.WaitForConnector(DiscoveryIdentityEvent, logger)
 	if conn == nil {
 		return trace.Wrap(err)
 	}
@@ -90,23 +89,23 @@ func (process *TeleportProcess) initDiscoveryService() error {
 	}
 
 	process.OnExit("discovery.stop", func(payload interface{}) {
-		log.Info("Shutting down.")
+		logger.InfoContext(process.ExitContext(), "Shutting down.")
 		if discoveryService != nil {
 			discoveryService.Stop()
 		}
 		if asyncEmitter != nil {
-			warnOnErr(asyncEmitter.Close(), process.log)
+			warnOnErr(process.ExitContext(), asyncEmitter.Close(), logger)
 		}
-		warnOnErr(conn.Close(), log)
-		log.Info("Exited.")
+		warnOnErr(process.ExitContext(), conn.Close(), logger)
+		logger.InfoContext(process.ExitContext(), "Exited.")
 	})
 
 	process.BroadcastEvent(Event{Name: DiscoveryReady, Payload: nil})
 
 	if err := discoveryService.Start(); err != nil {
 		return trace.Wrap(err)
 	}
-	log.Infof("Discovery service has successfully started")
+	logger.InfoContext(process.ExitContext(), "Discovery service has successfully started")
 
 	if err := discoveryService.Wait(); err != nil {
 		return trace.Wrap(err)