OAuth: Add some debug logs (#26716)

* OAuth: Add some debug logs

Signed-off-by: Arve Knudsen <arve.knudsen@gmail.com>

pkg/api/login_oauth.go

@@ -186,6 +186,7 @@ func (hs *HTTPServer) OAuthLogin(ctx *models.ReqContext) {
 	if userInfo.Role != "" {
 	if userInfo.Role != "" {
 		rt := models.RoleType(userInfo.Role)
 		rt := models.RoleType(userInfo.Role)
 		if rt.IsValid() {
 		if rt.IsValid() {
+			// The user will be assigned a role in either the auto-assigned organization or in the default one
 			var orgID int64
 			var orgID int64
 			if setting.AutoAssignOrg && setting.AutoAssignOrgId > 0 {
 			if setting.AutoAssignOrg && setting.AutoAssignOrgId > 0 {
 				orgID = int64(setting.AutoAssignOrgId)
 				orgID = int64(setting.AutoAssignOrgId)

pkg/login/social/generic_oauth.go

@@ -181,7 +181,7 @@ func (s *SocialGenericOAuth) extractToken(data *UserInfoJson, token *oauth2.Toke
 func (s *SocialGenericOAuth) extractAPI(data *UserInfoJson, client *http.Client) bool {
 func (s *SocialGenericOAuth) extractAPI(data *UserInfoJson, client *http.Client) bool {
 	rawUserInfoResponse, err := HttpGet(client, s.apiUrl)
 	rawUserInfoResponse, err := HttpGet(client, s.apiUrl)
 	if err != nil {
 	if err != nil {
-		s.log.Debug("Error getting user info response", "url", s.apiUrl, "error", err)
+		s.log.Debug("Error getting user info", "url", s.apiUrl, "error", err)
 		return false
 		return false
 	}
 	}
 	data.rawJSON = rawUserInfoResponse.Body
 	data.rawJSON = rawUserInfoResponse.Body

pkg/services/login/login.go

 package login
 package login
 
 
 import (
 import (
+	"errors"
+
 	"github.com/grafana/grafana/pkg/bus"
 	"github.com/grafana/grafana/pkg/bus"
 	"github.com/grafana/grafana/pkg/infra/log"
 	"github.com/grafana/grafana/pkg/infra/log"
 	"github.com/grafana/grafana/pkg/models"
 	"github.com/grafana/grafana/pkg/models"
@@ -180,8 +182,11 @@ func updateUserAuth(user *models.User, extUser *models.ExternalUserInfo) error {
 }
 }
 
 
 func syncOrgRoles(user *models.User, extUser *models.ExternalUserInfo) error {
 func syncOrgRoles(user *models.User, extUser *models.ExternalUserInfo) error {
-	// don't sync org roles if none are specified
+	logger.Debug("Syncing organization roles", "id", user.Id, "extOrgRoles", extUser.OrgRoles)
+
+	// don't sync org roles if none is specified
 	if len(extUser.OrgRoles) == 0 {
 	if len(extUser.OrgRoles) == 0 {
+		logger.Debug("Not syncing organization roles since external user doesn't have any")
 		return nil
 		return nil
 	}
 	}
 
 
@@ -197,11 +202,12 @@ func syncOrgRoles(user *models.User, extUser *models.ExternalUserInfo) error {
 	for _, org := range orgsQuery.Result {
 	for _, org := range orgsQuery.Result {
 		handledOrgIds[org.OrgId] = true
 		handledOrgIds[org.OrgId] = true
 
 
-		if extUser.OrgRoles[org.OrgId] == "" {
+		extRole := extUser.OrgRoles[org.OrgId]
+		if extRole == "" {
 			deleteOrgIds = append(deleteOrgIds, org.OrgId)
 			deleteOrgIds = append(deleteOrgIds, org.OrgId)
-		} else if extUser.OrgRoles[org.OrgId] != org.Role {
+		} else if extRole != org.Role {
 			// update role
 			// update role
-			cmd := &models.UpdateOrgUserCommand{OrgId: org.OrgId, UserId: user.Id, Role: extUser.OrgRoles[org.OrgId]}
+			cmd := &models.UpdateOrgUserCommand{OrgId: org.OrgId, UserId: user.Id, Role: extRole}
 			if err := bus.Dispatch(cmd); err != nil {
 			if err := bus.Dispatch(cmd); err != nil {
 				return err
 				return err
 			}
 			}
@@ -224,13 +230,15 @@ func syncOrgRoles(user *models.User, extUser *models.ExternalUserInfo) error {
 
 
 	// delete any removed org roles
 	// delete any removed org roles
 	for _, orgId := range deleteOrgIds {
 	for _, orgId := range deleteOrgIds {
+		logger.Debug("Removing user's organization membership as part of syncing with OAuth login",
+			"userId", user.Id, "orgId", orgId)
 		cmd := &models.RemoveOrgUserCommand{OrgId: orgId, UserId: user.Id}
 		cmd := &models.RemoveOrgUserCommand{OrgId: orgId, UserId: user.Id}
-		err := bus.Dispatch(cmd)
-		if err == models.ErrLastOrgAdmin {
-			logger.Error(err.Error(), "userId", cmd.UserId, "orgId", cmd.OrgId)
-			continue
-		}
-		if err != nil {
+		if err := bus.Dispatch(cmd); err != nil {
+			if errors.Is(err, models.ErrLastOrgAdmin) {
+				logger.Error(err.Error(), "userId", cmd.UserId, "orgId", cmd.OrgId)
+				continue
+			}
+
 			return err
 			return err
 		}
 		}
 	}
 	}

pkg/services/login/login_test.go

@@ -6,6 +6,7 @@ import (
 	"github.com/grafana/grafana/pkg/bus"
 	"github.com/grafana/grafana/pkg/bus"
 	"github.com/grafana/grafana/pkg/models"
 	"github.com/grafana/grafana/pkg/models"
 	log "github.com/inconshreveable/log15"
 	log "github.com/inconshreveable/log15"
+	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 	"github.com/stretchr/testify/require"
 )
 )
 
 
@@ -39,9 +40,9 @@ func Test_syncOrgRoles_doesNotBreakWhenTryingToRemoveLastOrgAdmin(t *testing.T)
 }
 }
 
 
 func Test_syncOrgRoles_whenTryingToRemoveLastOrgLogsError(t *testing.T) {
 func Test_syncOrgRoles_whenTryingToRemoveLastOrgLogsError(t *testing.T) {
-	var logOutput string
+	logs := []string{}
 	logger.SetHandler(log.FuncHandler(func(r *log.Record) error {
 	logger.SetHandler(log.FuncHandler(func(r *log.Record) error {
-		logOutput = r.Msg
+		logs = append(logs, r.Msg)
 		return nil
 		return nil
 	}))
 	}))
 
 
@@ -70,7 +71,7 @@ func Test_syncOrgRoles_whenTryingToRemoveLastOrgLogsError(t *testing.T) {
 
 
 	err := syncOrgRoles(&user, &externalUser)
 	err := syncOrgRoles(&user, &externalUser)
 	require.NoError(t, err)
 	require.NoError(t, err)
-	require.Equal(t, models.ErrLastOrgAdmin.Error(), logOutput)
+	assert.Contains(t, logs, models.ErrLastOrgAdmin.Error())
 }
 }
 
 
 func createSimpleUser() models.User {
 func createSimpleUser() models.User {