In LDAP, do not log username until we know the user exists.

This prevents accidentally logging a password if the user enters it into the username field by mistake.

Signed-off-by: Matt Moyer <moyerm@vmware.com>

internal/upstreamldap/upstreamldap.go

@@ -395,13 +395,27 @@ func (p *Provider) validateConfig() error {
 func (p *Provider) searchAndBindUser(conn Conn, username string, bindFunc func(conn Conn, foundUserDN string) error) (string, string, []string, error) {
 	searchResult, err := conn.Search(p.userSearchRequest(username))
 	if err != nil {
-		return "", "", nil, fmt.Errorf(`error searching for user "%s": %w`, username, err)
+		plog.All(`error searching for user`,
+			"upstreamName", p.GetName(),
+			"username", username,
+			"err", err,
+		)
+		return "", "", nil, fmt.Errorf(`error searching for user: %w`, err)
 	}
 	if len(searchResult.Entries) == 0 {
-		plog.Debug("error finding user: user not found (if this username is valid, please check the user search configuration)",
+		if plog.Enabled(plog.LevelAll) {
-			"upstreamName", p.GetName(), "username", username)
+			plog.All("error finding user: user not found (if this username is valid, please check the user search configuration)",
+				"upstreamName", p.GetName(),
+				"username", username,
+			)
+		} else {
+			plog.Debug("error finding user: user not found (cowardly avoiding printing username because log level is not 'all')", "upstreamName", p.GetName())
+		}
 		return "", "", nil, nil
 	}
+
+	// At this point, we have matched at least one entry, so we can be confident that the username is not actually
+	// someone's password mistakenly entered into the username field, so we can log it without concern.
 	if len(searchResult.Entries) > 1 {
 		return "", "", nil, fmt.Errorf(`searching for user "%s" resulted in %d search results, but expected 1 result`,
 			username, len(searchResult.Entries),

internal/upstreamldap/upstreamldap_test.go

@@ -546,7 +546,7 @@ func TestEndUserAuthentication(t *testing.T) {
 				conn.EXPECT().Search(expectedUserSearch(nil)).Return(nil, errors.New("some user search error")).Times(1)
 				conn.EXPECT().Close().Times(1)
 			},
-			wantError: fmt.Sprintf(`error searching for user "%s": some user search error`, testUpstreamUsername),
+			wantError: `error searching for user: some user search error`,
 		},
 		{
 			name:           "when searching for the user's groups returns an error",

test/integration/ldap_client_test.go

@@ -348,7 +348,7 @@ func TestLDAPSearch(t *testing.T) {
 			username:  "pinny",
 			password:  pinnyPassword,
 			provider:  upstreamldap.New(*providerConfig(func(p *upstreamldap.ProviderConfig) { p.UserSearch.Filter = "*" })),
-			wantError: `error searching for user "pinny": LDAP Result Code 201 "Filter Compile Error": ldap: error parsing filter`,
+			wantError: `error searching for user: LDAP Result Code 201 "Filter Compile Error": ldap: error parsing filter`,
 		},
 		{
 			name:      "when the group search filter does not compile",
@@ -364,7 +364,7 @@ func TestLDAPSearch(t *testing.T) {
 			provider: upstreamldap.New(*providerConfig(func(p *upstreamldap.ProviderConfig) {
 				p.UserSearch.Filter = "objectClass=*" // overly broad search filter
 			})),
-			wantError: `error searching for user "pinny": LDAP Result Code 4 "Size Limit Exceeded": `,
+			wantError: `error searching for user: LDAP Result Code 4 "Size Limit Exceeded": `,
 		},
 		{
 			name:      "when the server is unreachable with TLS",
@@ -536,7 +536,7 @@ func TestLDAPSearch(t *testing.T) {
 			username:  "pinny",
 			password:  pinnyPassword,
 			provider:  upstreamldap.New(*providerConfig(func(p *upstreamldap.ProviderConfig) { p.UserSearch.Base = "invalid-base" })),
-			wantError: `error searching for user "pinny": LDAP Result Code 34 "Invalid DN Syntax": invalid DN`,
+			wantError: `error searching for user: LDAP Result Code 34 "Invalid DN Syntax": invalid DN`,
 		},
 		{
 			name:      "when the group search base is invalid",
@@ -550,7 +550,7 @@ func TestLDAPSearch(t *testing.T) {
 			username:  "pinny",
 			password:  pinnyPassword,
 			provider:  upstreamldap.New(*providerConfig(func(p *upstreamldap.ProviderConfig) { p.UserSearch.Base = "ou=does-not-exist,dc=pinniped,dc=dev" })),
-			wantError: `error searching for user "pinny": LDAP Result Code 32 "No Such Object": `,
+			wantError: `error searching for user: LDAP Result Code 32 "No Such Object": `,
 		},
 		{
 			name:      "when the group search base does not exist",