From a2df2654765c85cb7e7efc5eec9a97befa47bf15 Mon Sep 17 00:00:00 2001
From: zeripath <art27@cantab.net>
Date: Sun, 9 May 2021 17:04:53 +0100
Subject: [PATCH] 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        | 10 ++++++++++
 modules/auth/sso/oauth2.go       |  2 ++
 modules/auth/sso/reverseproxy.go |  2 ++
 modules/auth/sso/sso.go          |  4 ++++
 modules/auth/sso/sspi_windows.go |  2 ++
 5 files changed, 20 insertions(+)

diff --git a/modules/auth/sso/basic.go b/modules/auth/sso/basic.go
index d2d25c6cece6..d4ac8f8089c9 100644
--- a/modules/auth/sso/basic.go
+++ b/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
 }
diff --git a/modules/auth/sso/oauth2.go b/modules/auth/sso/oauth2.go
index fcd6845b38cc..b052b5599a88 100644
--- a/modules/auth/sso/oauth2.go
+++ b/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
 }
diff --git a/modules/auth/sso/reverseproxy.go b/modules/auth/sso/reverseproxy.go
index ca9450e71429..62598a15cdc3 100644
--- a/modules/auth/sso/reverseproxy.go
+++ b/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
 }
 
diff --git a/modules/auth/sso/sso.go b/modules/auth/sso/sso.go
index e670f1a8a719..8785a5f068f2 100644
--- a/modules/auth/sso/sso.go
+++ b/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
 }
 
diff --git a/modules/auth/sso/sspi_windows.go b/modules/auth/sso/sspi_windows.go
index 46f7ad9d97a0..2092a5e28976 100644
--- a/modules/auth/sso/sspi_windows.go
+++ b/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
 }