CBG-3379 add missing context logging

auth/auth.go

@@ -100,12 +100,12 @@ func NewAuthenticator(datastore base.DataStore, channelComputer ChannelComputer,
 	}
 }
 
-func DefaultAuthenticatorOptions() AuthenticatorOptions {
+func DefaultAuthenticatorOptions(ctx context.Context) AuthenticatorOptions {
 	return AuthenticatorOptions{
 		ClientPartitionWindow: base.DefaultClientPartitionWindow,
 		SessionCookieName:     DefaultCookieName,
 		BcryptCost:            DefaultBcryptCost,
-		LogCtx:                context.Background(),
+		LogCtx:                ctx,
 	}
 }
 
@@ -803,7 +803,7 @@ func (auth *Authenticator) AuthenticateUntrustedJWT(rawToken string, oidcProvide
 	}
 	if authenticator == nil {
 		for _, provider := range oidcProviders {
-			if provider.ValidFor(issuer, audiences) {
+			if provider.ValidFor(auth.LogCtx, issuer, audiences) {
 				base.TracefCtx(auth.LogCtx, base.KeyAuth, "Using OIDC provider %v", base.UD(provider.Issuer))
 				authenticator = provider
 				break
@@ -812,7 +812,7 @@ func (auth *Authenticator) AuthenticateUntrustedJWT(rawToken string, oidcProvide
 	}
 	if authenticator == nil {
 		for _, provider := range localJWT {
-			if provider.ValidFor(issuer, audiences) {
+			if provider.ValidFor(auth.LogCtx, issuer, audiences) {
 				base.TracefCtx(auth.LogCtx, base.KeyAuth, "Using local JWT provider %v", base.UD(provider.Issuer))
 				authenticator = provider
 				break
@@ -825,7 +825,7 @@ func (auth *Authenticator) AuthenticateUntrustedJWT(rawToken string, oidcProvide
 	}
 
 	var identity *Identity
-	identity, err = authenticator.verifyToken(context.TODO(), rawToken, callbackURLFunc)
+	identity, err = authenticator.verifyToken(auth.LogCtx, rawToken, callbackURLFunc)
 	if err != nil {
 		base.DebugfCtx(auth.LogCtx, base.KeyAuth, "JWT invalid: %v", err)
 		return nil, PrincipalConfig{}, base.HTTPErrorf(http.StatusUnauthorized, "Invalid JWT")

auth/auth_time_sensitive_test.go

@@ -31,7 +31,7 @@ func TestAuthenticationSpeed(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 	user, _ := auth.NewUser("me", "goIsKewl", nil)
 	assert.True(t, user.Authenticate("goIsKewl"))
 

auth/collection_access_test.go

@@ -33,7 +33,7 @@ func TestUserCollectionAccess(t *testing.T) {
 	// User with no access:
 	bucket := base.GetTestBucket(t)
 	defer bucket.Close()
-	options := DefaultAuthenticatorOptions()
+	options := DefaultAuthenticatorOptions(base.TestCtx(t))
 	options.Collections = map[string]map[string]struct{}{
 		"scope1": {
 			"collection1": struct{}{},
@@ -170,7 +170,7 @@ func TestSerializeUserWithCollections(t *testing.T) {
 
 	bucket := base.GetTestBucket(t)
 	defer bucket.Close()
-	auth := NewAuthenticator(bucket.GetSingleDataStore(), nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(bucket.GetSingleDataStore(), nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 	user, _ := auth.NewUser("me", "letmein", ch.BaseSetOf(t, "me", "public"))
 	encoded, err := base.JSONMarshal(user)
 	require.NoError(t, err)

auth/jwt.go

@@ -59,13 +59,13 @@ type JWTConfigCommon struct {
 }
 
 // ValidFor returns whether the issuer matches, and one of the audiences matches
-func (j JWTConfigCommon) ValidFor(issuer string, audiences audience) bool {
+func (j JWTConfigCommon) ValidFor(ctx context.Context, issuer string, audiences audience) bool {
 	if j.Issuer != issuer {
 		return false
 	}
 	// Nil ClientID is invalid (checked by config validation), but empty-string disables audience checking
 	if j.ClientID == nil {
-		base.ErrorfCtx(context.Background(), "JWTConfigCommon.ClientID nil - should never happen (for issuer %v)", base.UD(j.Issuer))
+		base.ErrorfCtx(ctx, "JWTConfigCommon.ClientID nil - should never happen (for issuer %v)", base.UD(j.Issuer))
 		return false
 	}
 	if *j.ClientID == "" {
@@ -147,7 +147,7 @@ type LocalJWTAuthConfig struct {
 }
 
 // BuildProvider prepares a LocalJWTAuthProvider from this config, initialising keySet.
-func (l LocalJWTAuthConfig) BuildProvider(name string) *LocalJWTAuthProvider {
+func (l LocalJWTAuthConfig) BuildProvider(ctx context.Context, name string) *LocalJWTAuthProvider {
 	var prov *LocalJWTAuthProvider
 	// validation ensures these are truly mutually exclusive
 	if len(l.Keys) > 0 {
@@ -160,10 +160,10 @@ func (l LocalJWTAuthConfig) BuildProvider(name string) *LocalJWTAuthProvider {
 		prov = &LocalJWTAuthProvider{
 			LocalJWTAuthConfig: l,
 			name:               name,
-			keySet:             oidc.NewRemoteKeySet(context.Background(), l.JWKSURI),
+			keySet:             oidc.NewRemoteKeySet(ctx, l.JWKSURI),
 		}
 	}
-	prov.initUserPrefix()
+	prov.initUserPrefix(ctx)
 	return prov
 }
 
@@ -209,14 +209,14 @@ func (l *LocalJWTAuthProvider) common() JWTConfigCommon {
 	return l.JWTConfigCommon
 }
 
-func (l *LocalJWTAuthProvider) initUserPrefix() {
+func (l *LocalJWTAuthProvider) initUserPrefix(ctx context.Context) {
 	if l.UserPrefix != "" || l.UsernameClaim != "" {
 		return
 	}
 
 	issuerURL, err := url.ParseRequestURI(l.Issuer)
 	if err != nil {
-		base.WarnfCtx(context.TODO(), "Unable to parse issuer URI when initializing user prefix - using provider name")
+		base.WarnfCtx(ctx, "Unable to parse issuer URI when initializing user prefix - using provider name")
 		l.UserPrefix = l.name
 		return
 	}

auth/jwt_test.go

@@ -86,7 +86,7 @@ func TestJWTVerifyToken(t *testing.T) {
 		testIssuer   = "testIssuer"
 		testClientID = "testAud"
 	)
-
+	ctx := base.TestCtx(t)
 	common := JWTConfigCommon{
 		Issuer:   testIssuer,
 		ClientID: base.StringPtr(testClientID),
@@ -96,13 +96,13 @@ func TestJWTVerifyToken(t *testing.T) {
 		Algorithms:      []string{"RS256", "ES256"},
 		Keys:            []jose.JSONWebKey{testRSAJWK, testECJWK, testEncRSAJWK},
 		SkipExpiryCheck: base.BoolPtr(true),
-	}.BuildProvider("test")
+	}.BuildProvider(ctx, "test")
 	providerWithExpiryCheck := LocalJWTAuthConfig{
 		JWTConfigCommon: common,
 		Algorithms:      []string{"RS256", "ES256"},
 		Keys:            []jose.JSONWebKey{testRSAJWK, testECJWK, testEncRSAJWK},
 		SkipExpiryCheck: base.BoolPtr(false),
-	}.BuildProvider("test")
+	}.BuildProvider(ctx, "test")
 
 	t.Run("garbage", test(baseProvider, "INVALID", anyError))
 

auth/main_test.go

@@ -11,12 +11,14 @@ licenses/APL2.txt.
 package auth
 
 import (
+	"context"
 	"testing"
 
 	"github.com/couchbase/sync_gateway/base"
 )
 
 func TestMain(m *testing.M) {
+	ctx := context.Background() // start of test process
 	tbpOptions := base.TestBucketPoolOptions{MemWatermarkThresholdMB: 2048}
-	base.TestBucketPoolNoIndexes(m, tbpOptions)
+	base.TestBucketPoolNoIndexes(ctx, m, tbpOptions)
 }

auth/oidc.go

@@ -540,7 +540,7 @@ func (op *OIDCProvider) runDiscoverySync(ctx context.Context, discoveryURL strin
 		return ttl, err
 	}
 	if refresh && !op.isStandardDiscovery() {
-		verifier := op.generateVerifier(&metadata, context.Background())
+		verifier := op.generateVerifier(&metadata, ctx)
 		op.client.SetConfig(verifier, metadata.endpoint())
 		op.metadata = metadata
 	}
@@ -624,7 +624,7 @@ func (op *OIDCProvider) verifyToken(ctx context.Context, token string, callbackU
 	}
 
 	// Verify claims and signature on the JWT; ensure that it's been signed by the provider.
-	idToken, err := client.verifyJWT(token)
+	idToken, err := client.verifyJWT(ctx, token)
 	if err != nil {
 		base.DebugfCtx(ctx, base.KeyAuth, "Client %v could not verify JWT. Error: %v", base.UD(client), err)
 		return nil, err
@@ -661,10 +661,10 @@ func getIssuerWithAudience(token *jwt.JSONWebToken) (issuer string, audiences []
 
 // verifyJWT parses a raw ID Token, verifies it's been signed by the provider
 // and returns the payload. It uses the ID Token Verifier to verify the token.
-func (client *OIDCClient) verifyJWT(token string) (*oidc.IDToken, error) {
+func (client *OIDCClient) verifyJWT(ctx context.Context, token string) (*oidc.IDToken, error) {
 	client.mutex.RLock()
 	defer client.mutex.RUnlock()
-	return client.verifier.Verify(context.Background(), token)
+	return client.verifier.Verify(ctx, token)
 }
 
 func SetURLQueryParam(strURL, name, value string) (string, error) {

auth/oidc_test.go

@@ -1191,7 +1191,7 @@ func TestJWTRolesChannels(t *testing.T) {
 				roleChannels: map[string]ch.TimedSet{},
 			}
 
-			auth := NewAuthenticator(dataStore, &testMockComputer, DefaultAuthenticatorOptions())
+			auth := NewAuthenticator(dataStore, &testMockComputer, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 			provider := &OIDCProvider{
 				Name: "foo",

auth/password_hash_test.go

@@ -62,7 +62,7 @@ func TestSetBcryptCost(t *testing.T) {
 	bucket := base.GetTestBucket(t)
 	defer bucket.Close()
 	dataStore := bucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 	err := auth.SetBcryptCost(DefaultBcryptCost - 1) // below minimum allowed value
 	assert.Equal(t, ErrInvalidBcryptCost, errors.Cause(err))

auth/role_test.go

@@ -45,7 +45,7 @@ func TestAuthorizeChannelsRole(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 	role, err := auth.NewRole("root", channels.BaseSetOf(t, "superuser"))
 	assert.NoError(t, err)
@@ -65,9 +65,9 @@ func TestRoleKeysHash(t *testing.T) {
 			defer testBucket.Close()
 			dataStore := testBucket.DefaultDataStore()
 
-			auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+			auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 			if !metadataDefault {
-				namedMetadataOptions := DefaultAuthenticatorOptions()
+				namedMetadataOptions := DefaultAuthenticatorOptions(base.TestCtx(t))
 				namedMetadataOptions.MetaKeys = base.NewMetadataKeys("foo")
 
 				auth = NewAuthenticator(dataStore, nil, namedMetadataOptions)

auth/session_test.go

@@ -29,7 +29,7 @@ func TestCreateSession(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 	user, err := auth.NewUser(username, "password", base.Set{})
 	require.NoError(t, err)
@@ -74,7 +74,7 @@ func TestDeleteSession(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 	id, err := base.GenerateRandomSecret()
 	require.NoError(t, err)
@@ -103,7 +103,7 @@ func TestMakeSessionCookie(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 	sessionID, err := base.GenerateRandomSecret()
 	require.NoError(t, err)
@@ -129,7 +129,7 @@ func TestMakeSessionCookieProperties(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 	sessionID, err := base.GenerateRandomSecret()
 	require.NoError(t, err)
@@ -164,7 +164,7 @@ func TestDeleteSessionForCookie(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 	sessionID, err := base.GenerateRandomSecret()
 	require.NoError(t, err)
@@ -227,7 +227,7 @@ func TestCreateSessionChangePassword(t *testing.T) {
 			testBucket := base.GetTestBucket(t)
 			defer testBucket.Close()
 			dataStore := testBucket.GetSingleDataStore()
-			auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+			auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 			user, err := auth.NewUser(test.username, test.password, base.Set{})
 			require.NoError(t, err)
@@ -266,7 +266,7 @@ func TestUserWithoutSessionUUID(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 	const username = "Alice"
 	user, err := auth.NewUser(username, "password", base.Set{})
 	require.NoError(t, err)

auth/user_test.go

@@ -35,7 +35,7 @@ func TestUserAuthenticateDisabled(t *testing.T) {
 	defer bucket.Close()
 	dataStore := bucket.GetSingleDataStore()
 	// Create user
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 	u, err := auth.NewUser(username, oldPassword, base.Set{})
 	assert.NoError(t, err)
 	assert.NotNil(t, u)
@@ -70,7 +70,7 @@ func TestUserAuthenticatePasswordHashUpgrade(t *testing.T) {
 	defer bucket.Close()
 	dataStore := bucket.GetSingleDataStore()
 	// Create user
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 	u, err := auth.NewUser(username, oldPassword, base.Set{})
 	require.NoError(t, err)
 	require.NotNil(t, u)
@@ -252,7 +252,7 @@ func TestCanSeeChannelSince(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 	freeChannels := base.SetFromArray([]string{"ESPN", "HBO", "FX", "AMC"})
 	user, err := auth.NewUser("user", "password", freeChannels)
 	assert.Nil(t, err)
@@ -280,7 +280,7 @@ func TestGetAddedChannels(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 	role, err := auth.NewRole("music", channels.BaseSetOf(t, "Spotify", "Youtube"))
 	assert.Nil(t, err)
@@ -323,7 +323,7 @@ func TestUserAuthenticateWithDisabledUserAccount(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 	user, err := auth.NewUser(username, password, base.Set{})
 	assert.NoError(t, err)
@@ -345,7 +345,7 @@ func TestUserAuthenticateWithOldPasswordHash(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 	user, err := auth.NewUser(username, password, base.Set{})
 	assert.NoError(t, err)
@@ -366,7 +366,7 @@ func TestUserAuthenticateWithBadPasswordHash(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 	user, err := auth.NewUser(username, password, base.Set{})
 	assert.NoError(t, err)
@@ -387,7 +387,7 @@ func TestUserAuthenticateWithNoHashAndBadPassword(t *testing.T) {
 	testBucket := base.GetTestBucket(t)
 	defer testBucket.Close()
 	dataStore := testBucket.GetSingleDataStore()
-	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+	auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 
 	user, err := auth.NewUser(username, password, base.Set{})
 	assert.NoError(t, err)
@@ -404,9 +404,9 @@ func TestUserKeysHash(t *testing.T) {
 			defer testBucket.Close()
 			dataStore := testBucket.GetSingleDataStore()
 
-			auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions())
+			auth := NewAuthenticator(dataStore, nil, DefaultAuthenticatorOptions(base.TestCtx(t)))
 			if !metadataDefault {
-				namedMetadataOptions := DefaultAuthenticatorOptions()
+				namedMetadataOptions := DefaultAuthenticatorOptions(base.TestCtx(t))
 				namedMetadataOptions.MetaKeys = base.NewMetadataKeys("foo")
 
 				auth = NewAuthenticator(testBucket.GetSingleDataStore(), nil, namedMetadataOptions)