feat(server): log successful token exchange requests (#4780)

The authorization code flow emits an "login successful" info log in
finalizeLogin with the resolved identity (user_id, username, email,
groups). The token exchange flow (RFC 8693) never logged a corresponding
success line, making CI/CD-style flows that rely on token exchange
effectively invisible in operator logs even at debug level.

Add an equivalent "token exchange successful" info log after
TokenIdentity returns, mirroring the fields in finalizeLogin and adding
client_id, subject_token_type and requested_token_type for the context
specific to this grant.

Signed-off-by: Helio Machado <0x2b3bfa0+git@googlemail.com>

Author: 0x2b3bfa0

server/handlers.go

@@ -1856,6 +1856,18 @@ func (s *Server) handleTokenExchange(w http.ResponseWriter, r *http.Request, cli
 		return
 	}
 
+	email := identity.Email
+	if !identity.EmailVerified {
+		email += " (unverified)"
+	}
+
+	s.logger.InfoContext(ctx, "token exchange successful",
+		"connector_id", connID, "client_id", client.ID,
+		"user_id", identity.UserID,
+		"username", identity.Username, "preferred_username", identity.PreferredUsername,
+		"email", email, "groups", identity.Groups,
+		"subject_token_type", subjectTokenType, "requested_token_type", requestedTokenType)
+
 	claims := storage.Claims{
 		UserID:            identity.UserID,
 		Username:          identity.Username,

server/handlers_test.go

@@ -6,6 +6,7 @@ import (
 	"encoding/json"
 	"errors"
 	"fmt"
+	"log/slog"
 	"net/http"
 	"net/http/httptest"
 	"net/url"
@@ -1741,6 +1742,56 @@ func TestHandleTokenExchange(t *testing.T) {
 	}
 }
 
+func TestHandleTokenExchangeLogsSuccess(t *testing.T) {
+	ctx := t.Context()
+	var logBuf bytes.Buffer
+	httpServer, s := newTestServer(t, func(c *Config) {
+		c.Logger = slog.New(slog.NewJSONHandler(&logBuf, &slog.HandlerOptions{Level: slog.LevelInfo}))
+		c.Storage.CreateClient(ctx, storage.Client{
+			ID:     "client_1",
+			Secret: "secret_1",
+		})
+	})
+	defer httpServer.Close()
+
+	vals := make(url.Values)
+	vals.Set("grant_type", grantTypeTokenExchange)
+	vals.Set("connector_id", "mock")
+	vals.Set("scope", "openid")
+	vals.Set("requested_token_type", tokenTypeAccess)
+	vals.Set("subject_token_type", tokenTypeID)
+	vals.Set("subject_token", "foobar")
+	vals.Set("client_id", "client_1")
+	vals.Set("client_secret", "secret_1")
+
+	rr := httptest.NewRecorder()
+	req := httptest.NewRequest(http.MethodPost, httpServer.URL+"/token", strings.NewReader(vals.Encode()))
+	req.Header.Set("content-type", "application/x-www-form-urlencoded")
+
+	s.handleToken(rr, req)
+	require.Equal(t, http.StatusOK, rr.Code, rr.Body.String())
+
+	var found map[string]any
+	for _, line := range strings.Split(strings.TrimSpace(logBuf.String()), "\n") {
+		var entry map[string]any
+		require.NoError(t, json.Unmarshal([]byte(line), &entry))
+		if entry["msg"] == "token exchange successful" {
+			found = entry
+			break
+		}
+	}
+	require.NotNil(t, found, "expected \"token exchange successful\" log line, got: %s", logBuf.String())
+	require.Equal(t, "INFO", found["level"])
+	require.Equal(t, "mock", found["connector_id"])
+	require.Equal(t, "client_1", found["client_id"])
+	require.Equal(t, "0-385-28089-0", found["user_id"])
+	require.Equal(t, "Kilgore Trout", found["username"])
+	require.Equal(t, "kilgore@kilgore.trout", found["email"])
+	require.Equal(t, []any{"authors"}, found["groups"])
+	require.Equal(t, tokenTypeID, found["subject_token_type"])
+	require.Equal(t, tokenTypeAccess, found["requested_token_type"])
+}
+
 func TestHandleTokenExchangeConnectorGrantTypeRestriction(t *testing.T) {
 	ctx := t.Context()
 	httpServer, s := newTestServer(t, func(c *Config) {