User credential types consistently log token scopes (Azure#23712)

Author: chlowell

sdk/azidentity/CHANGELOG.md

@@ -7,6 +7,7 @@
 ### Breaking Changes
 
 ### Bugs Fixed
+* User credential types inconsistently log access token scopes
 
 ### Other Changes
 

sdk/azidentity/azidentity.go

@@ -42,6 +42,8 @@ const (
 	developerSignOnClientID = "04b07795-8ddb-461a-bbee-02f9e1bf7b46"
 	defaultSuffix           = "/.default"
 
+	scopeLogFmt = "%s.GetToken() acquired a token for scope %q"
+
 	traceNamespace      = "Microsoft.Entra"
 	traceOpGetToken     = "GetToken"
 	traceOpAuthenticate = "Authenticate"

sdk/azidentity/confidential_client.go

@@ -115,7 +115,7 @@ func (c *confidentialClient) GetToken(ctx context.Context, tro policy.TokenReque
 			err = newAuthenticationFailedErrorFromMSAL(c.name, err)
 		}
 	} else {
-		msg := fmt.Sprintf("%s.GetToken() acquired a token for scope %q", c.name, strings.Join(ar.GrantedScopes, ", "))
+		msg := fmt.Sprintf(scopeLogFmt, c.name, strings.Join(ar.GrantedScopes, ", "))
 		log.Write(EventAuthentication, msg)
 	}
 	return azcore.AccessToken{Token: ar.AccessToken, ExpiresOn: ar.ExpiresOn.UTC()}, err

sdk/azidentity/confidential_client_test.go

@@ -0,0 +1,53 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+package azidentity
+
+import (
+	"fmt"
+	"strings"
+	"testing"
+
+	"github.com/Azure/azure-sdk-for-go/sdk/azcore"
+	"github.com/Azure/azure-sdk-for-go/sdk/azcore/log"
+	"github.com/AzureAD/microsoft-authentication-library-for-go/apps/confidential"
+	"github.com/stretchr/testify/require"
+)
+
+func TestConfidentialClientLogging(t *testing.T) {
+	logMsgs := []string{}
+	log.SetListener(func(e log.Event, msg string) {
+		if e == EventAuthentication {
+			logMsgs = append(logMsgs, msg)
+		}
+	})
+	defer log.SetListener(nil)
+
+	cred, err := confidential.NewCredFromSecret(fakeSecret)
+	require.NoError(t, err)
+
+	c, err := newConfidentialClient(fakeTenantID, fakeClientID, credNameSecret, cred, confidentialClientOptions{
+		ClientOptions: azcore.ClientOptions{
+			Transport: &mockSTS{},
+		},
+	})
+	require.NoError(t, err)
+
+	// client should log token scopes when acquiring a token from the cache or authority
+	expected := fmt.Sprintf(scopeLogFmt, credNameSecret, strings.Join(testTRO.Scopes, ", "))
+	for i := 0; i < 2; i++ {
+		logMsgs = []string{}
+		_, err = c.GetToken(ctx, testTRO)
+		require.NoError(t, err)
+
+		scopesLogged := false
+		for _, msg := range logMsgs {
+			require.Contains(t, msg, credNameSecret)
+			if strings.Contains(msg, testTRO.Scopes[0]) {
+				scopesLogged = true
+				require.Equal(t, expected, msg)
+			}
+		}
+		require.True(t, scopesLogged)
+	}
+}

sdk/azidentity/public_client.go

@@ -154,12 +154,7 @@ func (p *publicClient) GetToken(ctx context.Context, tro policy.TokenRequestOpti
 	if p.opts.DisableAutomaticAuthentication {
 		return azcore.AccessToken{}, newAuthenticationRequiredError(p.name, tro)
 	}
-	at, err := p.reqToken(ctx, client, tro)
-	if err == nil {
-		msg := fmt.Sprintf("%s.GetToken() acquired a token for scope %q", p.name, strings.Join(ar.GrantedScopes, ", "))
-		log.Write(EventAuthentication, msg)
-	}
-	return at, err
+	return p.reqToken(ctx, client, tro)
 }
 
 // reqToken requests a token from the MSAL public client. It's separate from GetToken() to enable Authenticate() to bypass the cache.
@@ -242,6 +237,8 @@ func (p *publicClient) newMSALClient(enableCAE bool) (msalPublicClient, error) {
 
 func (p *publicClient) token(ar public.AuthResult, err error) (azcore.AccessToken, error) {
 	if err == nil {
+		msg := fmt.Sprintf(scopeLogFmt, p.name, strings.Join(ar.GrantedScopes, ", "))
+		log.Write(EventAuthentication, msg)
 		p.record, err = newAuthenticationRecord(ar)
 	} else {
 		err = newAuthenticationFailedErrorFromMSAL(p.name, err)

sdk/azidentity/public_client_test.go

@@ -0,0 +1,49 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+package azidentity
+
+import (
+	"fmt"
+	"strings"
+	"testing"
+
+	"github.com/Azure/azure-sdk-for-go/sdk/azcore"
+	"github.com/Azure/azure-sdk-for-go/sdk/azcore/log"
+	"github.com/stretchr/testify/require"
+)
+
+func TestPublicClientLogging(t *testing.T) {
+	logMsgs := []string{}
+	log.SetListener(func(e log.Event, msg string) {
+		if e == EventAuthentication {
+			logMsgs = append(logMsgs, msg)
+		}
+	})
+	defer log.SetListener(nil)
+
+	pc, err := newPublicClient(fakeTenantID, fakeClientID, credNameUserPassword, publicClientOptions{
+		ClientOptions: azcore.ClientOptions{
+			Transport: &mockSTS{},
+		},
+	})
+	require.NoError(t, err)
+
+	// client should log token scopes when acquiring a token from the cache or authority
+	expected := fmt.Sprintf(scopeLogFmt, credNameUserPassword, strings.Join(testTRO.Scopes, ", "))
+	for i := 0; i < 2; i++ {
+		logMsgs = []string{}
+		_, err = pc.GetToken(ctx, testTRO)
+		require.NoError(t, err)
+
+		scopesLogged := false
+		for _, msg := range logMsgs {
+			require.Contains(t, msg, credNameUserPassword)
+			if strings.Contains(msg, testTRO.Scopes[0]) {
+				scopesLogged = true
+				require.Equal(t, expected, msg)
+			}
+		}
+		require.True(t, scopesLogged)
+	}
+}