Convert lib/auth/webauthn* to use slog (#50510)

gravitational · Dec 20, 2024 · 1cab8d9 · 1cab8d9
1 parent cc757ce
commit 1cab8d9
Show file tree

Hide file tree

Showing 8 changed files with 155 additions and 90 deletions.
diff --git a/lib/auth/webauthn/attestation.go b/lib/auth/webauthn/attestation.go
@@ -19,17 +19,22 @@
 package webauthn
 
 import (
+	"context"
 	"crypto/x509"
 	"encoding/pem"
+	"log/slog"
 	"slices"
 
 	"github.com/go-webauthn/webauthn/protocol"
 	"github.com/gravitational/trace"
-	log "github.com/sirupsen/logrus"
 
+	"github.com/gravitational/teleport"
 	"github.com/gravitational/teleport/api/types"
+	logutils "github.com/gravitational/teleport/lib/utils/log"
 )
 
+var log = logutils.NewPackageLogger(teleport.ComponentKey, "WebAuthn")
+
 // x5cFormats enumerates all attestation formats that supply an attestation
 // chain through the "x5c" field.
 // See https://www.w3.org/TR/webauthn/#sctn-defined-attestation-formats.
@@ -138,13 +143,17 @@ func getChainFromX5C(obj protocol.AttestationObject) ([]*x509.Certificate, error
 
 	// Print out attestation certs if debug is enabled.
 	// This may come in handy for people having trouble with their setups.
-	if log.IsLevelEnabled(log.DebugLevel) {
+	ctx := context.Background()
+	if log.Handler().Enabled(ctx, slog.LevelDebug) {
 		for _, cert := range chain {
 			certPEM := pem.EncodeToMemory(&pem.Block{
 				Type:  "CERTIFICATE",
 				Bytes: cert.Raw,
 			})
-			log.Debugf("WebAuthn: got %q attestation certificate:\n\n%s", obj.Format, certPEM)
+			log.DebugContext(context.Background(), "got attestation certificate",
+				"format", obj.Format,
+				"certificate", string(certPEM),
+			)
 		}
 	}
 

diff --git a/lib/auth/webauthn/device.go b/lib/auth/webauthn/device.go
@@ -19,14 +19,14 @@
 package webauthn
 
 import (
+	"context"
 	"crypto/ecdsa"
 	"crypto/x509"
 
 	"github.com/fxamacker/cbor/v2"
 	"github.com/go-webauthn/webauthn/protocol/webauthncose"
 	wan "github.com/go-webauthn/webauthn/webauthn"
 	"github.com/gravitational/trace"
-	log "github.com/sirupsen/logrus"
 
 	"github.com/gravitational/teleport/api/types"
 )
@@ -51,7 +51,7 @@ func deviceToCredential(
 			var err error
 			pubKeyCBOR, err = u2fDERKeyToCBOR(dev.U2F.PubKey)
 			if err != nil {
-				log.Warnf("WebAuthn: failed to convert U2F device key to CBOR: %v", err)
+				log.WarnContext(context.Background(), "failed to convert U2F device key to CBOR", "error", err)
 				return wan.Credential{}, false
 			}
 		}

diff --git a/lib/auth/webauthn/login.go b/lib/auth/webauthn/login.go
@@ -31,7 +31,6 @@ import (
 	wan "github.com/go-webauthn/webauthn/webauthn"
 	gogotypes "github.com/gogo/protobuf/types"
 	"github.com/gravitational/trace"
-	log "github.com/sirupsen/logrus"
 
 	mfav1 "github.com/gravitational/teleport/api/gen/proto/go/teleport/mfa/v1"
 	"github.com/gravitational/teleport/api/types"
@@ -107,13 +106,14 @@ func (f *loginFlow) begin(ctx context.Context, user string, challengeExtensions
 				continue
 			}
 
-			log.Errorf(""+
-				"User device %q/%q has unexpected RPID=%q, excluding from allowed credentials. "+
-				"RPID changes are not supported by WebAuthn, this is likely to cause permanent authentication problems for your users. "+
-				"Consider reverting the change or reset your users so they may register their devices again.",
-				user,
-				devices[i].GetName(),
-				webDev.CredentialRpId)
+			const msg = "User device has unexpected RPID, excluding from allowed credentials. " +
+				"RPID changes are not supported by WebAuthn, this is likely to cause permanent authentication problems for your users. " +
+				"Consider reverting the change or reset your users so they may register their devices again."
+			log.ErrorContext(ctx, msg,
+				"user", user,
+				"device", devices[i].GetName(),
+				"rpid", webDev.CredentialRpId,
+			)
 
 			// "Cut" device from slice.
 			devices = slices.Delete(devices, i, i+1)
@@ -249,7 +249,7 @@ func (f *loginFlow) finish(ctx context.Context, user string, resp *wantypes.Cred
 
 	origin := parsedResp.Response.CollectedClientData.Origin
 	if err := validateOrigin(origin, f.Webauthn.RPID); err != nil {
-		log.WithError(err).Debugf("WebAuthn: origin validation failed")
+		log.DebugContext(ctx, "origin validation failed", "error", err)
 		return nil, trace.Wrap(err)
 	}
 
@@ -330,9 +330,9 @@ func (f *loginFlow) finish(ctx context.Context, user string, resp *wantypes.Cred
 	if (discoverableLogin || uvr == protocol.VerificationRequired) && sd.UserVerification != string(protocol.VerificationRequired) {
 		// This is not a failure yet, but will likely become one.
 		sd.UserVerification = string(protocol.VerificationRequired)
-		log.Warnf(""+
-			"WebAuthn: User verification required by extensions but not by challenge. "+
-			"Increased SessionData.UserVerification to %s.", sd.UserVerification)
+		const msg = "User verification required by extensions but not by challenge. " +
+			"Increased SessionData.UserVerification."
+		log.WarnContext(ctx, msg, "user_verification", sd.UserVerification)
 	}
 
 	sessionData := wantypes.SessionDataToProtocol(sd)
@@ -371,8 +371,10 @@ func (f *loginFlow) finish(ctx context.Context, user string, resp *wantypes.Cred
 		return nil, trace.Wrap(err)
 	}
 	if credential.Authenticator.CloneWarning {
-		log.Warnf(
-			"WebAuthn: Clone warning detected for user %q / device %q. Device counter may be malfunctioning.", user, dev.GetName())
+		log.WarnContext(ctx, "Clone warning detected for device, the device counter may be malfunctioning",
+			"user", user,
+			"device", dev.GetName(),
+		)
 	}
 
 	// Update last used timestamp and device counter.
@@ -381,7 +383,11 @@ func (f *loginFlow) finish(ctx context.Context, user string, resp *wantypes.Cred
 	}
 	// Retroactively write the credential RPID, now that it cleared authn.
 	if webDev := dev.GetWebauthn(); webDev != nil && webDev.CredentialRpId == "" {
-		log.Debugf("WebAuthn: Recording RPID=%q in device %q/%q", rpID, user, dev.GetName())
+		log.DebugContext(ctx, "Recording RPID in device",
+			"rpid", rpID,
+			"user", user,
+			"device", dev.GetName(),
+		)
 		webDev.CredentialRpId = rpID
 	}
 
@@ -395,7 +401,10 @@ func (f *loginFlow) finish(ctx context.Context, user string, resp *wantypes.Cred
 	// passes.
 	if sd.ChallengeExtensions.AllowReuse != mfav1.ChallengeAllowReuse_CHALLENGE_ALLOW_REUSE_YES {
 		if err := f.sessionData.Delete(ctx, user, challenge); err != nil {
-			log.Warnf("WebAuthn: failed to delete login SessionData for user %v (scope = %s)", user, sd.ChallengeExtensions.Scope)
+			log.WarnContext(ctx, "failed to delete login SessionData for user",
+				"user", user,
+				"scope", sd.ChallengeExtensions.Scope,
+			)
 		}
 	}
 
@@ -463,19 +472,19 @@ func updateCredentialAndTimestamps(
 			d.Webauthn.CredentialBackupEligible = &gogotypes.BoolValue{
 				Value: credential.Flags.BackupEligible,
 			}
-			log.WithFields(log.Fields{
-				"device": dest.GetName(),
-				"be":     credential.Flags.BackupEligible,
-			}).Debug("Backfilled Webauthn device BE flag")
+			log.DebugContext(context.Background(), "Backfilled Webauthn device BE flag",
+				"device", dest.GetName(),
+				"be", credential.Flags.BackupEligible,
+			)
 		}
 		if d.Webauthn.CredentialBackedUp == nil {
 			d.Webauthn.CredentialBackedUp = &gogotypes.BoolValue{
 				Value: credential.Flags.BackupState,
 			}
-			log.WithFields(log.Fields{
-				"device": dest.GetName(),
-				"bs":     credential.Flags.BackupState,
-			}).Debug("Backfilled Webauthn device BS flag")
+			log.DebugContext(context.Background(), "Backfilled Webauthn device BS flag",
+				"device", dest.GetName(),
+				"bs", credential.Flags.BackupState,
+			)
 		}
 
 	default:

diff --git a/lib/auth/webauthn/register.go b/lib/auth/webauthn/register.go
@@ -32,7 +32,6 @@ import (
 	gogotypes "github.com/gogo/protobuf/types"
 	"github.com/google/uuid"
 	"github.com/gravitational/trace"
-	log "github.com/sirupsen/logrus"
 
 	"github.com/gravitational/teleport/api/types"
 	wantypes "github.com/gravitational/teleport/lib/auth/webauthntypes"
@@ -284,7 +283,7 @@ func (f *RegistrationFlow) Finish(ctx context.Context, req RegisterResponse) (*t
 
 	origin := parsedResp.Response.CollectedClientData.Origin
 	if err := validateOrigin(origin, f.Webauthn.RPID); err != nil {
-		log.WithError(err).Debugf("WebAuthn: origin validation failed")
+		log.DebugContext(ctx, "origin validation failed", "error", err)
 		return nil, trace.Wrap(err)
 	}
 
@@ -332,7 +331,7 @@ func (f *RegistrationFlow) Finish(ctx context.Context, req RegisterResponse) (*t
 			protocolErr.Type == protocol.ErrVerification.Type &&
 			passwordless &&
 			!parsedResp.Response.AttestationObject.AuthData.Flags.UserVerified() {
-			log.WithError(err).Debug("WebAuthn: Replacing verification error with PIN message")
+			log.DebugContext(ctx, "WebAuthn: Replacing verification error with PIN message", "error", err)
 			return nil, trace.BadParameter("authenticator doesn't support passwordless, setting up a PIN may fix this")
 		}
 
@@ -378,7 +377,7 @@ func (f *RegistrationFlow) Finish(ctx context.Context, req RegisterResponse) (*t
 
 	// Registration complete, remove the registration challenge we just used.
 	if err := f.Identity.DeleteWebauthnSessionData(ctx, req.User, scopeSession); err != nil {
-		log.Warnf("WebAuthn: failed to delete registration SessionData for user %v", req.User)
+		log.WarnContext(ctx, "failed to delete registration SessionData for user", "user", req.User, "error", err)
 	}
 
 	return newDevice, nil

diff --git a/lib/auth/webauthncli/api.go b/lib/auth/webauthncli/api.go
@@ -24,14 +24,20 @@ import (
 	"strings"
 
 	"github.com/gravitational/trace"
-	log "github.com/sirupsen/logrus"
 	oteltrace "go.opentelemetry.io/otel/trace"
 
+	"github.com/gravitational/teleport"
 	"github.com/gravitational/teleport/api/client/proto"
 	"github.com/gravitational/teleport/api/observability/tracing"
 	"github.com/gravitational/teleport/lib/auth/touchid"
 	wantypes "github.com/gravitational/teleport/lib/auth/webauthntypes"
 	wanwin "github.com/gravitational/teleport/lib/auth/webauthnwin"
+	logutils "github.com/gravitational/teleport/lib/utils/log"
+)
+
+var (
+	log     = logutils.NewPackageLogger(teleport.ComponentKey, "WebAuthn")
+	fidoLog = logutils.NewPackageLogger(teleport.ComponentKey, "FIDO2")
 )
 
 // ErrUsingNonRegisteredDevice is returned from Login when the user attempts to
@@ -137,10 +143,10 @@ func Login(
 	switch {
 	case origin == "", assertion == nil: // let downstream handle empty/nil
 	case !strings.HasPrefix(origin, "https://"+assertion.Response.RelyingPartyID):
-		log.Warnf(""+
-			"WebAuthn: origin and RPID mismatch, "+
-			"if you are having authentication problems double check your proxy address "+
-			"(%q vs %q)", origin, assertion.Response.RelyingPartyID)
+		log.WarnContext(ctx, "origin and RPID mismatch, if you are having authentication problems double check your proxy address",
+			"origin", origin,
+			"rpid", assertion.Response.RelyingPartyID,
+		)
 	}
 
 	var attachment AuthenticatorAttachment
@@ -151,27 +157,27 @@ func Login(
 	}
 
 	if wanwin.IsAvailable() {
-		log.Debug("WebAuthnWin: Using windows webauthn for credential assertion")
+		log.DebugContext(ctx, "Using windows webauthn for credential assertion")
 		return wanwin.Login(ctx, origin, assertion, &wanwin.LoginOpts{
 			AuthenticatorAttachment: wanwin.AuthenticatorAttachment(attachment),
 		})
 	}
 
 	switch attachment {
 	case AttachmentCrossPlatform:
-		log.Debug("Cross-platform login")
+		log.DebugContext(ctx, "Cross-platform login")
 		return crossPlatformLogin(ctx, origin, assertion, prompt, opts)
 	case AttachmentPlatform:
-		log.Debug("Platform login")
+		log.DebugContext(ctx, "Platform login")
 		return platformLogin(origin, user, assertion, prompt)
 	default:
-		log.Debug("Attempting platform login")
+		log.DebugContext(ctx, "Attempting platform login")
 		resp, credentialUser, err := platformLogin(origin, user, assertion, prompt)
 		if !errors.Is(err, &touchid.ErrAttemptFailed{}) {
 			return resp, credentialUser, trace.Wrap(err)
 		}
 
-		log.WithError(err).Debug("Platform login failed, falling back to cross-platform")
+		log.DebugContext(ctx, "Platform login failed, falling back to cross-platform", "error", err)
 		return crossPlatformLogin(ctx, origin, assertion, prompt, opts)
 	}
 }
@@ -180,7 +186,7 @@ func crossPlatformLogin(
 	ctx context.Context,
 	origin string, assertion *wantypes.CredentialAssertion, prompt LoginPrompt, opts *LoginOpts,
 ) (*proto.MFAAuthenticateResponse, string, error) {
-	log.Debug("FIDO2: Using libfido2 for assertion")
+	fidoLog.DebugContext(ctx, "Using libfido2 for assertion")
 	resp, user, err := FIDO2Login(ctx, origin, assertion, prompt, opts)
 	return resp, user, trace.Wrap(err)
 }
@@ -223,11 +229,11 @@ func Register(
 	ctx context.Context,
 	origin string, cc *wantypes.CredentialCreation, prompt RegisterPrompt) (*proto.MFARegisterResponse, error) {
 	if wanwin.IsAvailable() {
-		log.Debug("WebAuthnWin: Using windows webauthn for credential creation")
+		log.DebugContext(ctx, "Using windows webauthn for credential creation")
 		return wanwin.Register(ctx, origin, cc)
 	}
 
-	log.Debug("FIDO2: Using libfido2 for credential creation")
+	fidoLog.DebugContext(ctx, "Using libfido2 for credential creation")
 	resp, err := FIDO2Register(ctx, origin, cc, prompt)
 	return resp, trace.Wrap(err)
 }