Make slog attributes output the same content regardless of format (#3…

…9428)

* Make slog attributes output the same content regardless of format

There were a few instances of fmt.Stringers being passed to slog
as attributes to delay their evaluation as per the performance
considerations of slog: https://pkg.go.dev/log/slog#hdr-Performance_considerations.
However, this resulted in the json handler emitting different
content since they check to see if attributes are json.Marshalers
and not fmt.Stringers. To rectify the situation, a new slog.LogValuer
implementation was added that wraps a fmt.Stringer so that attributes
can be lazily constructed while producing the same output no matter
the log output format.

* fix: wrap identity and correct typo

lib/service/connect.go

@@ -52,6 +52,7 @@ import (
 	"github.com/gravitational/teleport/lib/tlsca"
 	"github.com/gravitational/teleport/lib/utils"
 	"github.com/gravitational/teleport/lib/utils/interval"
+	logutils "github.com/gravitational/teleport/lib/utils/log"
 )
 
 // reconnectToAuthService continuously attempts to reconnect to the auth
@@ -155,7 +156,7 @@ func (process *TeleportProcess) connectToAuthService(role types.SystemRole, opts
 	if err != nil {
 		return nil, trace.Wrap(err)
 	}
-	process.logger.DebugContext(process.ExitContext(), "Client successfully connected to cluster", "client_identity", connector.ClientIdentity)
+	process.logger.DebugContext(process.ExitContext(), "Client successfully connected to cluster", "client_identity", logutils.StringerAttr(connector.ClientIdentity))
 	process.addConnector(connector)
 
 	return connector, nil
@@ -179,7 +180,7 @@ func (process *TeleportProcess) connect(role types.SystemRole, opts ...certOptio
 		c, err := process.firstTimeConnect(role)
 		return c, trace.Wrap(err)
 	}
-	process.logger.DebugContext(process.ExitContext(), "Got connected state.", "rotation_state", state.Spec.Rotation.String())
+	process.logger.DebugContext(process.ExitContext(), "Got connected state.", "rotation_state", logutils.StringerAttr(&state.Spec.Rotation))
 
 	identity, err := process.GetIdentity(role)
 	if err != nil {
@@ -884,7 +885,7 @@ func (process *TeleportProcess) rotate(conn *Connector, localState auth.StateV2,
 		// rollback cycle.
 		case "", types.RotationStateStandby:
 			if regenerateCertificate {
-				process.logger.InfoContext(process.ExitContext(), "Service has updated principals and DNS Names, going to request new principals and update.", "identity", id.Role, "principals", additionalPrincipals, "dna_names", dnsNames)
+				process.logger.InfoContext(process.ExitContext(), "Service has updated principals and DNS Names, going to request new principals and update.", "identity", id.Role, "principals", additionalPrincipals, "dns_names", dnsNames)
 				identity, err := process.reRegister(conn, additionalPrincipals, dnsNames, remote)
 				if err != nil {
 					return nil, trace.Wrap(err)
@@ -942,7 +943,7 @@ func (process *TeleportProcess) rotate(conn *Connector, localState auth.StateV2,
 			if err != nil {
 				return nil, trace.Wrap(err)
 			}
-			process.logger.DebugContext(process.ExitContext(), "Re-registered, received new identity.", "identity", identity)
+			process.logger.DebugContext(process.ExitContext(), "Re-registered, received new identity.", "identity", logutils.StringerAttr(identity))
 			err = writeStateAndIdentity(auth.IdentityReplacement, identity)
 			if err != nil {
 				return nil, trace.Wrap(err)

lib/service/service.go

@@ -146,6 +146,7 @@ import (
 	usagereporter "github.com/gravitational/teleport/lib/usagereporter/teleport"
 	"github.com/gravitational/teleport/lib/utils"
 	"github.com/gravitational/teleport/lib/utils/cert"
+	logutils "github.com/gravitational/teleport/lib/utils/log"
 	vc "github.com/gravitational/teleport/lib/versioncontrol"
 	uw "github.com/gravitational/teleport/lib/versioncontrol/upgradewindow"
 	"github.com/gravitational/teleport/lib/web"
@@ -651,7 +652,7 @@ func (process *TeleportProcess) GetIdentity(role types.SystemRole) (i *auth.Iden
 			if err != nil {
 				return nil, trace.Wrap(err)
 			}
-			process.logger.InfoContext(process.ExitContext(), "Found static identity in the config file, writing to disk.", "identity", &id)
+			process.logger.InfoContext(process.ExitContext(), "Found static identity in the config file, writing to disk.", "identity", logutils.StringerAttr(&id))
 			if err = process.storage.WriteIdentity(auth.IdentityCurrent, *i); err != nil {
 				return nil, trace.Wrap(err)
 			}
@@ -4211,7 +4212,7 @@ func (process *TeleportProcess) initProxyEndpoint(conn *Connector) error {
 				return nil
 			}
 
-			logger.InfoContext(process.ExitContext(), "Starting peer proxy service", "listen_address", listeners.proxyPeer.Addr().String())
+			logger.InfoContext(process.ExitContext(), "Starting peer proxy service", "listen_address", logutils.StringerAttr(listeners.proxyPeer.Addr()))
 			err := proxyServer.Serve()
 			if err != nil {
 				return trace.Wrap(err)
@@ -4683,7 +4684,7 @@ func (process *TeleportProcess) initProxyEndpoint(conn *Connector) error {
 		alpnHandlerForWeb.Set(alpnServer.MakeConnectionHandler(alpnTLSConfigForWeb))
 
 		process.RegisterCriticalFunc("proxy.tls.alpn.sni.proxy", func() error {
-			logger.InfoContext(process.ExitContext(), "Starting TLS ALPN SNI proxy server on.", "listen_address", listeners.alpn.Addr())
+			logger.InfoContext(process.ExitContext(), "Starting TLS ALPN SNI proxy server on.", "listen_address", logutils.StringerAttr(listeners.alpn.Addr()))
 			if err := alpnServer.Serve(process.ExitContext()); err != nil {
 				logger.WarnContext(process.ExitContext(), "TLS ALPN SNI proxy proxy server exited with error.", "error", err)
 			}

lib/utils/log/slog_handler.go

@@ -555,3 +555,26 @@ func getCaller(a slog.Attr) (file string, line int) {
 
 	return file, line
 }
+
+type stringerAttr struct {
+	fmt.Stringer
+}
+
+// StringerAttr creates a [slog.LogValuer] that will defer to
+// the provided [fmt.Stringer]. All slog attributes are always evaluated,
+// even if the log event is discarded due to the configured log level.
+// A text [slog.Handler] will try to defer evaluation if the attribute is a
+// [fmt.Stringer], however, the JSON [slog.Handler] only defers to [json.Marshaler].
+// This means that to defer evaluation and creation of the string representation,
+// the object must implement [fmt.Stringer] and [json.Marshaler], otherwise additional
+// and unwanted values may be emitted if the logger is configured to use JSON
+// instead of text. This wrapping mechanism allows a value that implements [fmt.Stringer],
+// to be guaranteed to be lazily constructed and always output the same
+// content regardless of the output format.
+func StringerAttr(s fmt.Stringer) slog.LogValuer {
+	return stringerAttr{Stringer: s}
+}
+
+func (s stringerAttr) LogValue() slog.Value {
+	return slog.StringValue(s.Stringer.String())
+}