Add trace logging to SSO methods (#15803)

It is currenly impossible to detect which "SSO" method is responsible for login. This
PR adds some basic trace logging to these methods.

Signed-off-by: Andrew Thornton <art27@cantab.net>

modules/auth/sso/basic.go

@@ -66,12 +66,16 @@ func (b *Basic) VerifyAuthData(req *http.Request, w http.ResponseWriter, store D
 	// Assume username is token
 	authToken := uname
 	if !isUsernameToken {
+		log.Trace("Basic Authorization: Attempting login for: %s", uname)
 		// Assume password is token
 		authToken = passwd
+	} else {
+		log.Trace("Basic Authorization: Attempting login with username as token")
 	}
 
 	uid := CheckOAuthAccessToken(authToken)
 	if uid != 0 {
+		log.Trace("Basic Authorization: Valid OAuthAccessToken for user[%d]", uid)
 		var err error
 		store.GetData()["IsApiToken"] = true
 
@@ -83,6 +87,8 @@ func (b *Basic) VerifyAuthData(req *http.Request, w http.ResponseWriter, store D
 	}
 	token, err := models.GetAccessTokenBySHA(authToken)
 	if err == nil {
+		log.Trace("Basic Authorization: Valid AccessToken for user[%d]", uid)
+
 		u, err = models.GetUserByID(token.UID)
 		if err != nil {
 			log.Error("GetUserByID:  %v", err)
@@ -98,6 +104,8 @@ func (b *Basic) VerifyAuthData(req *http.Request, w http.ResponseWriter, store D
 	}
 
 	if u == nil {
+		log.Trace("Basic Authorization: Attempting SignIn for %s", uname)
+
 		u, err = models.UserSignIn(uname, passwd)
 		if err != nil {
 			if !models.IsErrUserNotExist(err) {
@@ -109,5 +117,7 @@ func (b *Basic) VerifyAuthData(req *http.Request, w http.ResponseWriter, store D
 		store.GetData()["IsApiToken"] = true
 	}
 
+	log.Trace("Basic Authorization: Logged in user %-v", u)
+
 	return u
 }

modules/auth/sso/oauth2.go

@@ -130,6 +130,7 @@ func (o *OAuth2) VerifyAuthData(req *http.Request, w http.ResponseWriter, store
 	if id <= 0 {
 		return nil
 	}
+	log.Trace("OAuth2 Authorization: Found token for user[%d]", id)
 
 	user, err := models.GetUserByID(id)
 	if err != nil {
@@ -139,5 +140,6 @@ func (o *OAuth2) VerifyAuthData(req *http.Request, w http.ResponseWriter, store
 		return nil
 	}
 
+	log.Trace("OAuth2 Authorization: Logged in user %-v", user)
 	return user
 }

modules/auth/sso/reverseproxy.go

@@ -65,6 +65,7 @@ func (r *ReverseProxy) VerifyAuthData(req *http.Request, w http.ResponseWriter,
 	if len(username) == 0 {
 		return nil
 	}
+	log.Trace("ReverseProxy Authorization: Found username: %s", username)
 
 	user, err := models.GetUserByName(username)
 	if err != nil {
@@ -75,6 +76,7 @@ func (r *ReverseProxy) VerifyAuthData(req *http.Request, w http.ResponseWriter,
 		return nil
 	}
 
+	log.Trace("ReverseProxy Authorization: Logged in user %-v", user)
 	return user
 }
 

modules/auth/sso/sso.go

@@ -77,6 +77,8 @@ func SessionUser(sess SessionStore) *models.User {
 	if uid == nil {
 		return nil
 	}
+	log.Trace("Session Authorization: Found user[%d]", uid)
+
 	id, ok := uid.(int64)
 	if !ok {
 		return nil
@@ -90,6 +92,8 @@ func SessionUser(sess SessionStore) *models.User {
 		}
 		return nil
 	}
+
+	log.Trace("Session Authorization: Logged in user %-v", user)
 	return user
 }
 

modules/auth/sso/sspi_windows.go

@@ -87,6 +87,7 @@ func (s *SSPI) VerifyAuthData(req *http.Request, w http.ResponseWriter, store Da
 		return nil
 	}
 
+	log.Trace("SSPI Authorization: Attempting to authenticate")
 	userInfo, outToken, err := sspiAuth.Authenticate(req, w)
 	if err != nil {
 		log.Warn("Authentication failed with error: %v\n", err)
@@ -140,6 +141,7 @@ func (s *SSPI) VerifyAuthData(req *http.Request, w http.ResponseWriter, store Da
 		handleSignIn(w, req, sess, user)
 	}
 
+	log.Trace("SSPI Authorization: Logged in user %-v", user)
 	return user
 }