Make SSO login failure event emit more specific errors (#6108)

Purpose is to allow users with admin privilege that are able to view audit logs, 
to be able to debug SSO login failures from the UI as much as possible

* Return generic error message for sso console login failures to hide
  sensitive data from reaching client. Previously errors were returning as
  empty messages b/c of a trace bug.
* Remove emit event for createOIDCClient to allow outer caller to
  emit event and prevent double emits on error.
* Temporarily direct users to check teleports log on errors that come back 
  empty to tsh client.

lib/auth/auth_test.go

@@ -1084,6 +1084,26 @@ func TestU2FSignChallengeCompat(t *testing.T) {
 	})
 }
 
+func TestEmitSSOLoginFailureEvent(t *testing.T) {
+	mockE := &events.MockEmitter{}
+
+	emitSSOLoginFailureEvent(context.Background(), mockE, "test", trace.BadParameter("some error"))
+
+	require.Equal(t, mockE.LastEvent(), &events.UserLogin{
+		Metadata: events.Metadata{
+			Type: events.UserLoginEvent,
+			Code: events.UserSSOLoginFailureCode,
+		},
+		Method: "test",
+		Status: events.Status{
+			Success:     false,
+			Error:       "some error",
+			UserMessage: "some error",
+		},
+	})
+
+}
+
 func newTestServices(t *testing.T) Services {
 	bk, err := memory.New(memory.Config{})
 	require.NoError(t, err)

lib/auth/auth_with_roles.go

@@ -1611,7 +1611,14 @@ func (a *ServerWithRoles) CreateOIDCAuthRequest(req services.OIDCAuthRequest) (*
 	if err := a.action(defaults.Namespace, services.KindOIDCRequest, services.VerbCreate); err != nil {
 		return nil, trace.Wrap(err)
 	}
-	return a.authServer.CreateOIDCAuthRequest(req)
+
+	oidcReq, err := a.authServer.CreateOIDCAuthRequest(req)
+	if err != nil {
+		emitSSOLoginFailureEvent(a.authServer.closeCtx, a.authServer.emitter, events.LoginMethodOIDC, err)
+		return nil, trace.Wrap(err)
+	}
+
+	return oidcReq, nil
 }
 
 func (a *ServerWithRoles) ValidateOIDCAuthCallback(q url.Values) (*OIDCAuthResponse, error) {
@@ -1681,7 +1688,14 @@ func (a *ServerWithRoles) CreateSAMLAuthRequest(req services.SAMLAuthRequest) (*
 	if err := a.action(defaults.Namespace, services.KindSAMLRequest, services.VerbCreate); err != nil {
 		return nil, trace.Wrap(err)
 	}
-	return a.authServer.CreateSAMLAuthRequest(req)
+
+	samlReq, err := a.authServer.CreateSAMLAuthRequest(req)
+	if err != nil {
+		emitSSOLoginFailureEvent(a.authServer.closeCtx, a.authServer.emitter, events.LoginMethodSAML, err)
+		return nil, trace.Wrap(err)
+	}
+
+	return samlReq, nil
 }
 
 func (a *ServerWithRoles) ValidateSAMLResponse(re string) (*SAMLAuthResponse, error) {
@@ -1779,7 +1793,14 @@ func (a *ServerWithRoles) CreateGithubAuthRequest(req services.GithubAuthRequest
 	if err := a.action(defaults.Namespace, services.KindGithubRequest, services.VerbCreate); err != nil {
 		return nil, trace.Wrap(err)
 	}
-	return a.authServer.CreateGithubAuthRequest(req)
+
+	githubReq, err := a.authServer.CreateGithubAuthRequest(req)
+	if err != nil {
+		emitSSOLoginFailureEvent(a.authServer.closeCtx, a.authServer.emitter, events.LoginMethodGithub, err)
+		return nil, trace.Wrap(err)
+	}
+
+	return githubReq, nil
 }
 
 func (a *ServerWithRoles) ValidateGithubAuthCallback(q url.Values) (*GithubAuthResponse, error) {
@@ -2851,3 +2872,23 @@ func NewAdminAuthServer(authServer *Server, sessions session.Service, alog event
 		sessions:   sessions,
 	}, nil
 }
+
+func emitSSOLoginFailureEvent(ctx context.Context, emitter events.Emitter, method string, err error) {
+	emitErr := emitter.EmitAuditEvent(ctx, &events.UserLogin{
+		Metadata: events.Metadata{
+			Type: events.UserLoginEvent,
+			Code: events.UserSSOLoginFailureCode,
+		},
+		Method: method,
+		Status: events.Status{
+			Success:     false,
+			Error:       trace.Unwrap(err).Error(),
+			UserMessage: err.Error(),
+		},
+	})
+
+	if emitErr != nil {
+		log.WithError(err).Warnf("Failed to emit %v login failure event.", method)
+	}
+
+}

lib/auth/github.go

@@ -140,8 +140,6 @@ func (a *Server) ValidateGithubAuthCallback(q url.Values) (*GithubAuthResponse,
 }
 
 func validateGithubAuthCallbackHelper(ctx context.Context, m githubManager, q url.Values, emitter events.Emitter) (*GithubAuthResponse, error) {
-	re, err := m.validateGithubAuthCallback(q)
-
 	event := &events.UserLogin{
 		Metadata: events.Metadata{
 			Type: events.UserLoginEvent,
@@ -149,10 +147,12 @@ func validateGithubAuthCallbackHelper(ctx context.Context, m githubManager, q ur
 		Method: events.LoginMethodGithub,
 	}
 
+	re, err := m.validateGithubAuthCallback(q)
 	if re != nil && re.claims != nil {
 		attributes, err := events.EncodeMapStrings(re.claims)
 		if err != nil {
-			log.WithError(err).Debugf("Failed to encode identity attributes.")
+			event.Status.UserMessage = fmt.Sprintf("Failed to encode identity attributes: %v", err.Error())
+			log.WithError(err).Debug("Failed to encode identity attributes.")
 		} else {
 			event.IdentityAttributes = attributes
 		}
@@ -161,8 +161,12 @@ func validateGithubAuthCallbackHelper(ctx context.Context, m githubManager, q ur
 	if err != nil {
 		event.Code = events.UserSSOLoginFailureCode
 		event.Status.Success = false
-		event.Status.Error = err.Error()
-		emitter.EmitAuditEvent(ctx, event)
+		event.Status.Error = trace.Unwrap(err).Error()
+		event.Status.UserMessage = err.Error()
+
+		if err := emitter.EmitAuditEvent(ctx, event); err != nil {
+			log.WithError(err).Warn("Failed to emit Github login failed event.")
+		}
 		return nil, trace.Wrap(err)
 	}
 	event.Code = events.UserSSOLoginCode

lib/auth/oidc.go

@@ -103,25 +103,7 @@ func (a *Server) createOIDCClient(conn services.OIDCConnector) (*oidc.Client, er
 				"unknown problem with connector %v, most likely URL %q is not valid or not accessible, check configuration and try to re-create the connector",
 				conn.GetName(), conn.GetIssuerURL())
 		}
-		if err := a.emitter.EmitAuditEvent(ctx, &events.UserLogin{
-			Metadata: events.Metadata{
-				Type: events.UserLoginEvent,
-				Code: events.UserSSOLoginFailureCode,
-			},
-			Method: events.LoginMethodOIDC,
-			Status: events.Status{
-				Success:     false,
-				Error:       trace.Unwrap(ctx.Err()).Error(),
-				UserMessage: err.Error(),
-			},
-		}); err != nil {
-			log.WithError(err).Warn("Failed to emit OIDC login failure event.")
-		}
-		// return user-friendly error hiding the actual error in the event
-		// logs for security purposes
-		return nil, trace.ConnectionProblem(nil,
-			"failed to login with %v",
-			conn.GetDisplay())
+		return nil, err
 	}
 
 	a.lock.Lock()
@@ -243,43 +225,44 @@ func (a *Server) CreateOIDCAuthRequest(req services.OIDCAuthRequest) (*services.
 // returned by OIDC Provider, if everything checks out, auth server
 // will respond with OIDCAuthResponse, otherwise it will return error
 func (a *Server) ValidateOIDCAuthCallback(q url.Values) (*OIDCAuthResponse, error) {
-	re, err := a.validateOIDCAuthCallback(q)
 	event := &events.UserLogin{
 		Metadata: events.Metadata{
 			Type: events.UserLoginEvent,
 		},
 		Method: events.LoginMethodOIDC,
 	}
+
+	re, err := a.validateOIDCAuthCallback(q)
+	if re != nil && re.claims != nil {
+		attributes, err := events.EncodeMap(re.claims)
+		if err != nil {
+			event.Status.UserMessage = fmt.Sprintf("Failed to encode identity attributes: %v", err.Error())
+			log.WithError(err).Debug("Failed to encode identity attributes.")
+		} else {
+			event.IdentityAttributes = attributes
+		}
+	}
+
 	if err != nil {
 		event.Code = events.UserSSOLoginFailureCode
 		event.Status.Success = false
 		event.Status.Error = trace.Unwrap(err).Error()
 		event.Status.UserMessage = err.Error()
-		if re != nil && re.claims != nil {
-			attributes, err := events.EncodeMap(re.claims)
-			if err != nil {
-				log.WithError(err).Debugf("Failed to encode identity attributes.")
-			} else {
-				event.IdentityAttributes = attributes
-			}
+
+		if err := a.emitter.EmitAuditEvent(a.closeCtx, event); err != nil {
+			log.WithError(err).Warn("Failed to emit OIDC login failed event.")
 		}
-		a.emitter.EmitAuditEvent(a.closeCtx, event)
+
 		return nil, trace.Wrap(err)
 	}
 	event.Code = events.UserSSOLoginCode
 	event.User = re.auth.Username
 	event.Status.Success = true
-	if re.claims != nil {
-		attributes, err := events.EncodeMap(re.claims)
-		if err != nil {
-			log.WithError(err).Debugf("Failed to encode identity attributes.")
-		} else {
-			event.IdentityAttributes = attributes
-		}
-	}
+
 	if err := a.emitter.EmitAuditEvent(a.closeCtx, event); err != nil {
 		log.WithError(err).Warn("Failed to emit OIDC login event.")
 	}
+
 	return &re.auth, nil
 }
 
@@ -329,14 +312,7 @@ func (a *Server) validateOIDCAuthCallback(q url.Values) (*oidcAuthResponse, erro
 	// extract claims from both the id token and the userinfo endpoint and merge them
 	claims, err := a.getClaims(oidcClient, connector, code)
 	if err != nil {
-		return nil, trace.WrapWithMessage(
-			// preserve the original error message, to avoid leaking
-			// server errors to the user in the UI, but override
-			// user message to the high level instruction to check audit log for details
-			trace.OAuth2(
-				oauth2.ErrorUnsupportedResponseType, err.Error(), q),
-			"unable to construct claims, check audit log for details",
-		)
+		return nil, trace.Wrap(err)
 	}
 	re := &oidcAuthResponse{
 		claims: claims,
@@ -785,13 +761,18 @@ func (a *Server) getClaims(oidcClient *oidc.Client, connector services.OIDCConne
 
 	t, err := oac.RequestToken(oauth2.GrantTypeAuthCode, code)
 	if err != nil {
+		if e, ok := err.(*oauth2.Error); ok {
+			if e.Type == oauth2.ErrorAccessDenied {
+				return nil, trace.Wrap(err, "the client_id and/or client_secret may be incorrect")
+			}
+		}
 		return nil, trace.Wrap(err)
 	}
 
 	idTokenClaims, err := claimsFromIDToken(oidcClient, t.IDToken)
 	if err != nil {
 		log.Debugf("Unable to fetch OIDC ID token claims: %v.", err)
-		return nil, trace.Wrap(err)
+		return nil, trace.Wrap(err, "unable to fetch OIDC ID token claims")
 	}
 	log.Debugf("OIDC ID Token claims: %v.", idTokenClaims)
 
@@ -802,7 +783,7 @@ func (a *Server) getClaims(oidcClient *oidc.Client, connector services.OIDCConne
 			return idTokenClaims, nil
 		}
 		log.Debugf("Unable to fetch UserInfo claims: %v.", err)
-		return nil, trace.Wrap(err)
+		return nil, trace.Wrap(err, "unable to fetch UserInfo claims")
 	}
 	log.Debugf("UserInfo claims: %v.", userInfoClaims)
 
@@ -814,21 +795,21 @@ func (a *Server) getClaims(oidcClient *oidc.Client, connector services.OIDCConne
 	var exists bool
 	if idsub, exists, err = idTokenClaims.StringClaim("sub"); err != nil || !exists {
 		log.Debugf("Unable to extract OIDC sub claim from ID token.")
-		return nil, trace.Wrap(err)
+		return nil, trace.Wrap(err, "unable to extract OIDC sub claim from ID token")
 	}
 	if uisub, exists, err = userInfoClaims.StringClaim("sub"); err != nil || !exists {
 		log.Debugf("Unable to extract OIDC sub claim from UserInfo.")
-		return nil, trace.Wrap(err)
+		return nil, trace.Wrap(err, "unable to extract OIDC sub claim from UserInfo")
 	}
 	if idsub != uisub {
 		log.Debugf("OIDC claim subjects don't match '%v' != '%v'.", idsub, uisub)
-		return nil, trace.BadParameter("invalid subject in UserInfo")
+		return nil, trace.BadParameter("OIDC claim subjects in UserInfo does not match")
 	}
 
 	claims, err := mergeClaims(idTokenClaims, userInfoClaims)
 	if err != nil {
 		log.Debugf("Unable to merge OIDC claims: %v.", err)
-		return nil, trace.Wrap(err)
+		return nil, trace.Wrap(err, "unable to merge OIDC claims")
 	}
 
 	// for GSuite users, fetch extra data from the proprietary google API

lib/auth/saml.go

@@ -21,6 +21,7 @@ import (
 	"compress/flate"
 	"context"
 	"encoding/base64"
+	"fmt"
 	"io/ioutil"
 
 	"github.com/gravitational/teleport"
@@ -304,27 +305,31 @@ func (a *Server) ValidateSAMLResponse(samlResponse string) (*SAMLAuthResponse, e
 	if re != nil && re.attributeStatements != nil {
 		attributes, err := events.EncodeMapStrings(re.attributeStatements)
 		if err != nil {
-			log.WithError(err).Warn("Failed to encode identity attributes.")
+			event.Status.UserMessage = fmt.Sprintf("Failed to encode identity attributes: %v", err.Error())
+			log.WithError(err).Debug("Failed to encode identity attributes.")
 		} else {
 			event.IdentityAttributes = attributes
 		}
 	}
+
 	if err != nil {
 		event.Code = events.UserSSOLoginFailureCode
 		event.Status.Success = false
 		event.Status.Error = trace.Unwrap(err).Error()
 		event.Status.UserMessage = err.Error()
 		if err := a.emitter.EmitAuditEvent(a.closeCtx, event); err != nil {
-			log.WithError(err).Warn("Failed to emit SAML login success event.")
+			log.WithError(err).Warn("Failed to emit SAML login failed event.")
 		}
 		return nil, trace.Wrap(err)
 	}
 	event.Status.Success = true
 	event.User = re.auth.Username
 	event.Code = events.UserSSOLoginCode
+
 	if err := a.emitter.EmitAuditEvent(a.closeCtx, event); err != nil {
-		log.WithError(err).Warn("Failed to emit SAML login failure event.")
+		log.WithError(err).Warn("Failed to emit SAML login event.")
 	}
+
 	return &re.auth, nil
 }
 

lib/services/saml.go

@@ -139,11 +139,11 @@ func GetSAMLServiceProvider(sc SAMLConnector, clock clockwork.Clock) (*saml2.SAM
 			for _, samlCert := range kd.KeyInfo.X509Data.X509Certificates {
 				certData, err := base64.StdEncoding.DecodeString(strings.TrimSpace(samlCert.Data))
 				if err != nil {
-					return nil, trace.Wrap(err)
+					return nil, trace.Wrap(err, "failed to decode certificate defined in entity_descriptor")
 				}
 				cert, err := x509.ParseCertificate(certData)
 				if err != nil {
-					return nil, trace.Wrap(err, "failed to parse certificate in metadata")
+					return nil, trace.Wrap(err, "failed to parse certificate defined in entity_descriptor")
 				}
 				certStore.Roots = append(certStore.Roots, cert)
 			}
@@ -153,7 +153,7 @@ func GetSAMLServiceProvider(sc SAMLConnector, clock clockwork.Clock) (*saml2.SAM
 	if sc.GetCert() != "" {
 		cert, err := tlsca.ParseCertificatePEM([]byte(sc.GetCert()))
 		if err != nil {
-			return nil, trace.Wrap(err)
+			return nil, trace.Wrap(err, "failed to parse certificate defined in cert")
 		}
 		certStore.Roots = append(certStore.Roots, cert)
 	}
@@ -163,7 +163,7 @@ func GetSAMLServiceProvider(sc SAMLConnector, clock clockwork.Clock) (*saml2.SAM
 
 	signingKeyStore, err := utils.ParseSigningKeyStorePEM(sc.GetSigningKeyPair().PrivateKey, sc.GetSigningKeyPair().Cert)
 	if err != nil {
-		return nil, trace.Wrap(err)
+		return nil, trace.Wrap(err, "failed to parse certificate defined in signing_key_pair")
 	}
 
 	// The encryption keystore here is defaulted to the value of the signing keystore
@@ -174,7 +174,7 @@ func GetSAMLServiceProvider(sc SAMLConnector, clock clockwork.Clock) (*saml2.SAM
 	if encryptionKeyPair != nil {
 		encryptionKeyStore, err = utils.ParseSigningKeyStorePEM(encryptionKeyPair.PrivateKey, encryptionKeyPair.Cert)
 		if err != nil {
-			return nil, trace.Wrap(err)
+			return nil, trace.Wrap(err, "failed to parse certificate defined in assertion_key_pair")
 		}
 	}
 

lib/utils/cli.go

@@ -189,6 +189,7 @@ func UserMessageFromError(err error) string {
 	if err != nil {
 		var buf bytes.Buffer
 		fmt.Fprint(&buf, Color(Red, "ERROR: "))
+
 		// If the error is a trace error, check if it has a user message embedded in
 		// it, if it does, print it, otherwise escape and print the original error.
 		if er, ok := err.(*trace.TraceErr); ok {
@@ -197,8 +198,15 @@ func UserMessageFromError(err error) string {
 			}
 			fmt.Fprintln(&buf, AllowNewlines(trace.Unwrap(er).Error()))
 		} else {
-			fmt.Fprintln(&buf, AllowNewlines(err.Error()))
+			strErr := err.Error()
+			// Error can be of type trace.proxyError where error message didn't get captured.
+			if strErr == "" {
+				fmt.Fprintln(&buf, "please check Teleport's log for more details")
+			} else {
+				fmt.Fprintln(&buf, AllowNewlines(err.Error()))
+			}
 		}
+
 		return buf.String()
 	}
 	return ""

lib/web/apiserver.go

@@ -66,6 +66,11 @@ import (
 	"golang.org/x/crypto/ssh"
 )
 
+const (
+	// ssoLoginConsoleErr is a generic error message to hide revealing sso login failure msgs.
+	ssoLoginConsoleErr = "Failed to login. Please check Teleport's log for more details."
+)
+
 // Handler is HTTP web proxy handler
 type Handler struct {
 	log logrus.FieldLogger
@@ -906,14 +911,20 @@ func (h *Handler) githubLoginWeb(w http.ResponseWriter, r *http.Request, p httpr
 }
 
 func (h *Handler) githubLoginConsole(w http.ResponseWriter, r *http.Request, p httprouter.Params) (interface{}, error) {
-	h.log.WithField("auth", "github").Debug("Console login start.")
+	logger := h.log.WithField("auth", "github")
+	logger.Debug("Console login start.")
+
 	req := new(client.SSOLoginConsoleReq)
 	if err := httplib.ReadJSON(r, req); err != nil {
-		return nil, trace.Wrap(err)
+		logger.WithError(err).Error("Error reading json.")
+		return nil, trace.AccessDenied(ssoLoginConsoleErr)
 	}
+
 	if err := req.CheckAndSetDefaults(); err != nil {
-		return nil, trace.Wrap(err)
+		logger.WithError(err).Error("Missing request parameters.")
+		return nil, trace.AccessDenied(ssoLoginConsoleErr)
 	}
+
 	response, err := h.cfg.ProxyClient.CreateGithubAuthRequest(
 		services.GithubAuthRequest{
 			ConnectorID:       req.ConnectorID,
@@ -925,8 +936,10 @@ func (h *Handler) githubLoginConsole(w http.ResponseWriter, r *http.Request, p h
 			KubernetesCluster: req.KubernetesCluster,
 		})
 	if err != nil {
-		return nil, trace.Wrap(err)
+		logger.WithError(err).Error("Failed to create Github auth request.")
+		return nil, trace.AccessDenied(ssoLoginConsoleErr)
 	}
+
 	return &client.SSOLoginConsoleResponse{
 		RedirectURL: response.RedirectURL,
 	}, nil
@@ -986,14 +999,20 @@ func (h *Handler) githubCallback(w http.ResponseWriter, r *http.Request, p httpr
 }
 
 func (h *Handler) oidcLoginConsole(w http.ResponseWriter, r *http.Request, p httprouter.Params) (interface{}, error) {
-	h.log.WithField("auth", "oidc").Debug("Console login start.")
+	logger := h.log.WithField("auth", "oidc")
+	logger.Debug("Console login start.")
+
 	req := new(client.SSOLoginConsoleReq)
 	if err := httplib.ReadJSON(r, req); err != nil {
-		return nil, trace.Wrap(err)
+		logger.WithError(err).Error("Error reading json.")
+		return nil, trace.AccessDenied(ssoLoginConsoleErr)
 	}
+
 	if err := req.CheckAndSetDefaults(); err != nil {
-		return nil, trace.Wrap(err)
+		logger.WithError(err).Error("Missing request parameters.")
+		return nil, trace.AccessDenied(ssoLoginConsoleErr)
 	}
+
 	response, err := h.cfg.ProxyClient.CreateOIDCAuthRequest(
 		services.OIDCAuthRequest{
 			ConnectorID:       req.ConnectorID,
@@ -1006,8 +1025,10 @@ func (h *Handler) oidcLoginConsole(w http.ResponseWriter, r *http.Request, p htt
 			KubernetesCluster: req.KubernetesCluster,
 		})
 	if err != nil {
-		return nil, trace.Wrap(err)
+		logger.WithError(err).Error("Failed to create OIDC auth request.")
+		return nil, trace.AccessDenied(ssoLoginConsoleErr)
 	}
+
 	return &client.SSOLoginConsoleResponse{
 		RedirectURL: response.RedirectURL,
 	}, nil

lib/web/saml.go

@@ -54,14 +54,20 @@ func (h *Handler) samlSSO(w http.ResponseWriter, r *http.Request, p httprouter.P
 }
 
 func (h *Handler) samlSSOConsole(w http.ResponseWriter, r *http.Request, p httprouter.Params) (interface{}, error) {
-	h.log.WithField("auth", "saml").Debug("SSO console start.")
+	logger := h.log.WithField("auth", "saml")
+	logger.Debug("Console login start.")
+
 	req := new(client.SSOLoginConsoleReq)
 	if err := httplib.ReadJSON(r, req); err != nil {
-		return nil, trace.Wrap(err)
+		logger.WithError(err).Error("Error reading json.")
+		return nil, trace.AccessDenied(ssoLoginConsoleErr)
 	}
+
 	if err := req.CheckAndSetDefaults(); err != nil {
-		return nil, trace.Wrap(err)
+		logger.WithError(err).Error("Missing request parameters.")
+		return nil, trace.AccessDenied(ssoLoginConsoleErr)
 	}
+
 	response, err := h.cfg.ProxyClient.CreateSAMLAuthRequest(
 		services.SAMLAuthRequest{
 			ConnectorID:       req.ConnectorID,
@@ -73,8 +79,10 @@ func (h *Handler) samlSSOConsole(w http.ResponseWriter, r *http.Request, p httpr
 			KubernetesCluster: req.KubernetesCluster,
 		})
 	if err != nil {
-		return nil, trace.Wrap(err)
+		logger.WithError(err).Error("Failed to create SAML auth request.")
+		return nil, trace.AccessDenied(ssoLoginConsoleErr)
 	}
+
 	return &client.SSOLoginConsoleResponse{RedirectURL: response.RedirectURL}, nil
 }