Skip to content

Commit

Permalink
Migrates various components in lib/srv to use slog (#49840)
Browse files Browse the repository at this point in the history
* Convert srv.AuthHandlers to use slog

* Convert srv.Heartbeat and srv.HeartbeatV2 to use slog

* Convert srv.KeepAlive to use slog

* Convert srv.Monitor to use slog

* Convert srv.SessionControl to use slog

* Convert srv.TermManager to use slog
  • Loading branch information
rosstimothy authored Dec 5, 2024
1 parent 0131f45 commit ffa762d
Show file tree
Hide file tree
Showing 15 changed files with 134 additions and 118 deletions.
9 changes: 6 additions & 3 deletions lib/kube/proxy/forwarder.go
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ import (
"errors"
"fmt"
"io"
"log/slog"
"maps"
"net"
"net/http"
Expand Down Expand Up @@ -2348,9 +2349,11 @@ func (s *clusterSession) monitorConn(conn net.Conn, err error, hostID string) (n
Context: s.connCtx,
TeleportUser: s.User.GetName(),
ServerID: s.parent.cfg.HostID,
Entry: s.parent.log,
Emitter: s.parent.cfg.AuthClient,
EmitterContext: s.parent.ctx,
// TODO(tross) update this to use the child logger
// once Forwarder is converted to use a slog.Logger
Logger: slog.Default(),
Emitter: s.parent.cfg.AuthClient,
EmitterContext: s.parent.ctx,
})
if err != nil {
tc.CloseWithCause(err)
Expand Down
2 changes: 1 addition & 1 deletion lib/service/db.go
Original file line number Diff line number Diff line change
Expand Up @@ -137,7 +137,7 @@ func (process *TeleportProcess) initDatabaseService() (retErr error) {
ServerID: process.Config.HostUUID,
Emitter: asyncEmitter,
EmitterContext: process.ExitContext(),
Logger: process.log,
Logger: process.logger,
})
if err != nil {
return trace.Wrap(err)
Expand Down
12 changes: 6 additions & 6 deletions lib/service/service.go
Original file line number Diff line number Diff line change
Expand Up @@ -2967,7 +2967,7 @@ func (process *TeleportProcess) initSSH() error {
LockEnforcer: lockWatcher,
Emitter: &events.StreamerAndEmitter{Emitter: asyncEmitter, Streamer: conn.Client},
Component: teleport.ComponentNode,
Logger: process.log.WithField(teleport.ComponentKey, teleport.Component(teleport.ComponentNode, process.id)).WithField(teleport.ComponentKey, "sessionctrl"),
Logger: process.logger.With(teleport.ComponentKey, teleport.Component(teleport.ComponentNode, process.id, "sessionctrl")),
TracerProvider: process.TracingProvider,
ServerID: serverID,
})
Expand Down Expand Up @@ -4468,7 +4468,7 @@ func (process *TeleportProcess) initProxyEndpoint(conn *Connector) error {
LockEnforcer: lockWatcher,
Emitter: asyncEmitter,
Component: teleport.ComponentProxy,
Logger: process.log.WithField(teleport.ComponentKey, "sessionctrl"),
Logger: process.logger.With(teleport.ComponentKey, "sessionctrl"),
TracerProvider: process.TracingProvider,
ServerID: serverID,
})
Expand Down Expand Up @@ -4561,7 +4561,7 @@ func (process *TeleportProcess) initProxyEndpoint(conn *Connector) error {
ServerID: cfg.HostUUID,
Emitter: asyncEmitter,
EmitterContext: process.GracefulExitContext(),
Logger: process.log,
Logger: process.logger,
})
if err != nil {
return trace.Wrap(err)
Expand Down Expand Up @@ -4924,7 +4924,7 @@ func (process *TeleportProcess) initProxyEndpoint(conn *Connector) error {
ServerID: serverID,
Emitter: asyncEmitter,
EmitterContext: process.ExitContext(),
Logger: process.log,
Logger: process.logger,
})
if err != nil {
return trace.Wrap(err)
Expand Down Expand Up @@ -5142,7 +5142,7 @@ func (process *TeleportProcess) initProxyEndpoint(conn *Connector) error {
ServerID: process.Config.HostUUID,
Emitter: asyncEmitter,
EmitterContext: process.ExitContext(),
Logger: process.log,
Logger: process.logger,
})
if err != nil {
return trace.Wrap(err)
Expand Down Expand Up @@ -6024,7 +6024,7 @@ func (process *TeleportProcess) initApps() {
ServerID: process.Config.HostUUID,
Emitter: asyncEmitter,
EmitterContext: process.ExitContext(),
Logger: process.log,
Logger: process.logger,
MonitorCloseChannel: process.Config.Apps.MonitorCloseChannel,
})
if err != nil {
Expand Down
74 changes: 42 additions & 32 deletions lib/srv/authhandlers.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ import (
"context"
"encoding/json"
"fmt"
"log/slog"
"net"
"strconv"
"time"
Expand All @@ -30,7 +31,6 @@ import (
"github.com/gravitational/trace"
"github.com/jonboulle/clockwork"
"github.com/prometheus/client_golang/prometheus"
log "github.com/sirupsen/logrus"
"golang.org/x/crypto/ssh"

"github.com/gravitational/teleport"
Expand Down Expand Up @@ -123,7 +123,7 @@ func (c *AuthHandlerConfig) CheckAndSetDefaults() error {
type AuthHandlers struct {
loginChecker

log *log.Entry
log *slog.Logger

c *AuthHandlerConfig
}
Expand All @@ -140,7 +140,7 @@ func NewAuthHandlers(config *AuthHandlerConfig) (*AuthHandlers, error) {

ah := &AuthHandlers{
c: config,
log: log.WithField(teleport.ComponentKey, config.Component),
log: slog.With(teleport.ComponentKey, config.Component),
}
ah.loginChecker = &ahLoginChecker{
log: ah.log,
Expand Down Expand Up @@ -284,10 +284,10 @@ func (h *AuthHandlers) CheckPortForward(addr string, ctx *ServerContext) error {
Error: systemErrorMessage,
},
}); err != nil {
h.log.WithError(err).Warn("Failed to emit port forward deny audit event.")
h.log.WarnContext(h.c.Server.Context(), "Failed to emit port forward deny audit event", "error", err)
}

h.log.Warnf("Port forwarding request denied: %v.", systemErrorMessage)
h.log.WarnContext(h.c.Server.Context(), "Port forwarding request denied", "error", systemErrorMessage)

return trace.AccessDenied(userErrorMessage)
}
Expand All @@ -303,28 +303,38 @@ func (h *AuthHandlers) UserKeyAuth(conn ssh.ConnMetadata, key ssh.PublicKey) (*s
fingerprint := fmt.Sprintf("%v %v", key.Type(), sshutils.Fingerprint(key))

// create a new logging entry with info specific to this login attempt
log := h.log.WithField(teleport.ComponentFields, log.Fields{
"local": conn.LocalAddr(),
"remote": conn.RemoteAddr(),
"user": conn.User(),
"fingerprint": fingerprint,
})

cid := fmt.Sprintf("conn(%v->%v, user=%v)", conn.RemoteAddr(), conn.LocalAddr(), conn.User())
log.Debugf("%v auth attempt", cid)
log := h.log.With(
"local_addr", conn.LocalAddr(),
"remote_addr", conn.RemoteAddr(),
"user", conn.User(),
"fingerprint", fingerprint,
)

cert, ok := key.(*ssh.Certificate)
log.Debugf("%v auth attempt with key %v, %#v", cid, fingerprint, cert)
if !ok {
log.Debugf("auth attempt, unsupported key type")
log.DebugContext(ctx, "rejecting auth attempt, unsupported key type")
return nil, trace.BadParameter("unsupported key type: %v", fingerprint)
}

log.DebugContext(ctx, "processing auth attempt with key",
slog.Group("cert",
"serial", cert.Serial,
"type", cert.CertType,
"key_id", cert.KeyId,
"valid_principals", cert.ValidPrincipals,
"valid_after", cert.ValidAfter,
"valid_before", cert.ValidBefore,
"permissions", cert.Permissions,
"reserved", cert.Reserved,
),
)

if len(cert.ValidPrincipals) == 0 {
log.Debugf("need a valid principal for key")
log.DebugContext(ctx, "rejecting auth attempt without valid principals")
return nil, trace.BadParameter("need a valid principal for key %v", fingerprint)
}
if len(cert.KeyId) == 0 {
log.Debugf("need a valid key ID for key")
log.DebugContext(ctx, "rejecting auth attempt without valid key ID")
return nil, trace.BadParameter("need a valid key for key %v", fingerprint)
}
teleportUser := cert.KeyId
Expand Down Expand Up @@ -380,7 +390,7 @@ func (h *AuthHandlers) UserKeyAuth(conn ssh.ConnMetadata, key ssh.PublicKey) (*s
message,
err,
); err != nil {
h.log.WithError(err).Warn("Failed to append Trace to ConnectionDiagnostic.")
h.log.WarnContext(ctx, "Failed to append Trace to ConnectionDiagnostic", "error", err)
}

if err := h.c.Emitter.EmitAuditEvent(h.c.Server.Context(), &apievents.AuthAttempt{
Expand All @@ -402,7 +412,7 @@ func (h *AuthHandlers) UserKeyAuth(conn ssh.ConnMetadata, key ssh.PublicKey) (*s
Error: err.Error(),
},
}); err != nil {
h.log.WithError(err).Warn("Failed to emit failed login audit event.")
h.log.WarnContext(ctx, "Failed to emit failed login audit event", "error", err)
}

auditdMsg := auditd.Message{
Expand All @@ -412,7 +422,7 @@ func (h *AuthHandlers) UserKeyAuth(conn ssh.ConnMetadata, key ssh.PublicKey) (*s
}

if err := auditd.SendEvent(auditd.AuditUserErr, auditd.Failed, auditdMsg); err != nil {
log.Warnf("Failed to send an event to auditd: %v", err)
log.WarnContext(ctx, "Failed to send an event to auditd", "error", err)
}
}

Expand All @@ -433,7 +443,7 @@ func (h *AuthHandlers) UserKeyAuth(conn ssh.ConnMetadata, key ssh.PublicKey) (*s
recordFailedLogin(err)
return nil, trace.Wrap(err)
}
log.Debugf("Successfully authenticated")
log.DebugContext(ctx, "Successfully authenticated")

clusterName, err := h.c.AccessPoint.GetClusterName()
if err != nil {
Expand All @@ -452,7 +462,7 @@ func (h *AuthHandlers) UserKeyAuth(conn ssh.ConnMetadata, key ssh.PublicKey) (*s
case ssh.HostCert:
permissions.Extensions[utils.ExtIntCertType] = utils.ExtIntCertTypeHost
default:
log.Warnf("Unexpected cert type: %v", cert.CertType)
log.WarnContext(ctx, "Received unexpected cert type", "cert_type", cert.CertType)
}

if h.isProxy() {
Expand All @@ -464,7 +474,7 @@ func (h *AuthHandlers) UserKeyAuth(conn ssh.ConnMetadata, key ssh.PublicKey) (*s
// client's certificate
ca, err := h.authorityForCert(types.UserCA, cert.SignatureKey)
if err != nil {
log.Errorf("Permission denied: %v", err)
log.ErrorContext(ctx, "Permission denied", "error", err)
recordFailedLogin(err)
return nil, trace.Wrap(err)
}
Expand All @@ -483,7 +493,7 @@ func (h *AuthHandlers) UserKeyAuth(conn ssh.ConnMetadata, key ssh.PublicKey) (*s
err = h.canLoginWithRBAC(cert, ca, clusterName.GetClusterName(), h.c.Server.GetInfo(), teleportUser, conn.User())
}
if err != nil {
log.Errorf("Permission denied: %v", err)
log.ErrorContext(ctx, "Permission denied", "error", err)
recordFailedLogin(err)
return nil, trace.Wrap(err)
}
Expand Down Expand Up @@ -572,7 +582,7 @@ func (h *AuthHandlers) hostKeyCallback(hostname string, remote net.Addr, key ssh

// If strict host key checking is not enabled, log that Teleport trusted an
// insecure key, but allow the request to go through.
h.log.Warnf("Insecure configuration! Strict host key checking disabled, allowing login without checking host key of type %v.", key.Type())
h.log.WarnContext(ctx, "Insecure configuration! Strict host key checking disabled, allowing login without checking host key", "key_type", key.Type())
return nil
}

Expand All @@ -591,7 +601,7 @@ func (h *AuthHandlers) IsUserAuthority(cert ssh.PublicKey) bool {
// Teleport CA.
func (h *AuthHandlers) IsHostAuthority(cert ssh.PublicKey, address string) bool {
if _, err := h.authorityForCert(types.HostCA, cert); err != nil {
h.log.Debugf("Unable to find SSH host CA: %v.", err)
h.log.DebugContext(h.c.Server.Context(), "Unable to find SSH host CA", "error", err)
return false
}
return true
Expand All @@ -607,7 +617,7 @@ type loginChecker interface {
}

type ahLoginChecker struct {
log *log.Entry
log *slog.Logger
c *AuthHandlerConfig
}

Expand All @@ -618,7 +628,7 @@ func (a *ahLoginChecker) canLoginWithRBAC(cert *ssh.Certificate, ca types.CertAu
// Use the server's shutdown context.
ctx := a.c.Server.Context()

a.log.Debugf("Checking permissions for (%v,%v) to login to node with RBAC checks.", teleportUser, osUser)
a.log.DebugContext(ctx, "Checking permissions for (%v,%v) to login to node with RBAC checks.", teleportUser, osUser)

// get roles assigned to this user
accessInfo, err := fetchAccessInfo(cert, ca, teleportUser, clusterName)
Expand Down Expand Up @@ -694,9 +704,9 @@ func fetchAccessInfo(cert *ssh.Certificate, ca types.CertAuthority, teleportUser
// Certificate Authority and returns it.
func (h *AuthHandlers) authorityForCert(caType types.CertAuthType, key ssh.PublicKey) (types.CertAuthority, error) {
// get all certificate authorities for given type
cas, err := h.c.AccessPoint.GetCertAuthorities(context.TODO(), caType, false)
cas, err := h.c.AccessPoint.GetCertAuthorities(h.c.Server.Context(), caType, false)
if err != nil {
h.log.Warnf("%v", trace.DebugReport(err))
h.log.WarnContext(h.c.Server.Context(), "failed retrieving cert authority", "error", err)
return nil, trace.Wrap(err)
}

Expand All @@ -705,7 +715,7 @@ func (h *AuthHandlers) authorityForCert(caType types.CertAuthType, key ssh.Publi
for i := range cas {
checkers, err := sshutils.GetCheckers(cas[i])
if err != nil {
h.log.Warnf("%v", err)
h.log.WarnContext(h.c.Server.Context(), "unable to get cert checker for ca", "ca", cas[i].GetName(), "error", err)
return nil, trace.Wrap(err)
}
for _, checker := range checkers {
Expand Down
9 changes: 6 additions & 3 deletions lib/srv/ctx.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ import (
"context"
"fmt"
"io"
"log/slog"
"net"
"os"
"strconv"
Expand Down Expand Up @@ -490,9 +491,11 @@ func NewServerContext(ctx context.Context, parent *sshutils.ConnectionContext, s
TeleportUser: child.Identity.TeleportUser,
Login: child.Identity.Login,
ServerID: child.srv.ID(),
Entry: child.Entry,
Emitter: child.srv,
EmitterContext: ctx,
// TODO(tross) update this to use the child logger
// once ServerContext is converted to use a slog.Logger
Logger: slog.Default(),
Emitter: child.srv,
EmitterContext: ctx,
}
for _, opt := range monitorOpts {
opt(&monitorConfig)
Expand Down
4 changes: 2 additions & 2 deletions lib/srv/db/access_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -2389,7 +2389,7 @@ func setupTestContext(ctx context.Context, t testing.TB, withDatabases ...withDa
ServerID: testCtx.hostID,
Emitter: testCtx.emitter,
EmitterContext: ctx,
Logger: utils.NewLoggerForTests(),
Logger: utils.NewSlogLoggerForTests(),
})
require.NoError(t, err)

Expand Down Expand Up @@ -2542,7 +2542,7 @@ func (c *testContext) setupDatabaseServer(ctx context.Context, t testing.TB, p a
ServerID: p.HostID,
Emitter: c.emitter,
EmitterContext: context.Background(),
Logger: utils.NewLoggerForTests(),
Logger: utils.NewSlogLoggerForTests(),
})
require.NoError(t, err)

Expand Down
2 changes: 1 addition & 1 deletion lib/srv/desktop/windows_server.go
Original file line number Diff line number Diff line change
Expand Up @@ -1000,7 +1000,7 @@ func (s *WindowsService) connectRDP(ctx context.Context, log *slog.Logger, tdpCo
Clock: s.cfg.Clock,
ClientIdleTimeout: authCtx.Checker.AdjustClientIdleTimeout(netConfig.GetClientIdleTimeout()),
DisconnectExpiredCert: authCtx.GetDisconnectCertExpiry(authPref),
Entry: logrus.NewEntry(logrus.StandardLogger()),
Logger: s.cfg.Logger,
Emitter: s.cfg.Emitter,
EmitterContext: s.closeCtx,
LockWatcher: s.cfg.LockWatcher,
Expand Down
Loading

0 comments on commit ffa762d

Please sign in to comment.