refactor(sts): consolidate exchange logging into one outcome log

internal/config/testdata/full_config.yaml

@@ -34,7 +34,7 @@ oidc:
 audit:
   backend: sql
   sql:
-    dsn: "postgres://gate:secret@db.example.com:5432/gate?sslmode=require"
+    dsn: "postgres://gate:secret@db.example.com:5432/gate?sslmode=require" # trufflehog:ignore
 
 selector:
   type: redis

internal/sts/authorizer/authorizer.go

@@ -24,7 +24,6 @@ package authorizer
 import (
 	"context"
 	"fmt"
-	"log/slog"
 	"regexp"
 	"time"
 
@@ -43,7 +42,6 @@ type Authorizer struct {
 	fetchSF  singleflight.Group
 	patterns map[string]*regexp.Regexp
 	now      func() time.Time
-	logger   *slog.Logger
 }
 
 // NewAuthorizer creates an authorizer. Claim patterns from provider configs
@@ -52,12 +50,7 @@ func NewAuthorizer(
 	cfg *config.PolicyConfig,
 	sel *selector.Selector,
 	clients map[string]github.ClientIface,
-	logger *slog.Logger,
 ) (*Authorizer, error) {
-	if logger == nil {
-		logger = slog.Default()
-	}
-
 	patterns, err := compileClaimPatterns(cfg.Providers)
 	if err != nil {
 		return nil, err
@@ -70,7 +63,6 @@ func NewAuthorizer(
 		cache:    newPolicyCache(0),
 		patterns: patterns,
 		now:      time.Now,
-		logger:   logger,
 	}, nil
 }
 
@@ -140,28 +132,8 @@ func (a *Authorizer) Authorize(ctx context.Context, req *Request) *Result {
 	}
 
 	if denial := a.authorizeCentral(req); denial != nil {
-		return a.logResult(ctx, req, denied(denial))
+		return denied(denial)
 	}
 
-	return a.logResult(ctx, req, a.authorizeRepository(ctx, req))
-}
-
-// logResult logs the authorization result and returns it unchanged.
-func (a *Authorizer) logResult(ctx context.Context, req *Request, r *Result) *Result {
-	if r.Allowed {
-		a.logger.LogAttrs(ctx, slog.LevelInfo, "authorization granted",
-			slog.String("policy", r.MatchedPolicy),
-			slog.String("repository", req.TargetRepository),
-			slog.Int("ttl", r.EffectiveTTL),
-		)
-	} else {
-		a.logger.LogAttrs(ctx, slog.LevelWarn, "authorization denied",
-			slog.String("code", string(r.DenyReason.Code)),
-			slog.String("message", r.DenyReason.Message),
-			slog.String("details", r.DenyReason.Details),
-			slog.String("issuer", req.Issuer),
-			slog.String("repository", req.TargetRepository),
-		)
-	}
-	return r
+	return a.authorizeRepository(ctx, req)
 }

internal/sts/authorizer/authorizer_test.go

@@ -16,7 +16,6 @@ package authorizer
 
 import (
 	"fmt"
-	"log/slog"
 	"os"
 	"path/filepath"
 	"testing"
@@ -78,7 +77,7 @@ func buildAuthorizer(t *testing.T, cfg *config.PolicyConfig, policyFile string)
 	m := newMockClient(t, policyFile)
 	clients := map[string]github.ClientIface{"client-1": m}
 
-	a, err := NewAuthorizer(cfg, sel, clients, slog.Default())
+	a, err := NewAuthorizer(cfg, sel, clients)
 	require.NoError(t, err)
 	return a
 }
@@ -112,7 +111,7 @@ func TestNewAuthorizer_InvalidClaimPattern(t *testing.T) {
 	cfg.Providers[0].RequiredClaims = map[string]string{
 		"repo": "[invalid",
 	}
-	_, err := NewAuthorizer(cfg, nil, nil, slog.Default())
+	_, err := NewAuthorizer(cfg, nil, nil)
 	require.Error(t, err)
 	assert.Contains(t, err.Error(), "invalid claim pattern")
 }
@@ -379,7 +378,7 @@ func TestLayer2_RepositoryOrInstallationNotFound(t *testing.T) {
 			m := &github.MockClient{}
 			m.On("GetContents", mock.Anything, mock.Anything, mock.Anything).Return(nil, tt.fetchErr)
 
-			a, err := NewAuthorizer(cfg, sel, map[string]github.ClientIface{"client-1": m}, slog.Default())
+			a, err := NewAuthorizer(cfg, sel, map[string]github.ClientIface{"client-1": m})
 			require.NoError(t, err)
 
 			result := a.Authorize(t.Context(), &Request{

internal/sts/authorizer/policy_test.go

@@ -17,7 +17,6 @@ package authorizer
 import (
 	"context"
 	"fmt"
-	"log/slog"
 	"testing"
 	"time"
 
@@ -128,7 +127,7 @@ func TestPolicyCache_CachedHit(t *testing.T) {
 	sel, _ := selector.NewSelector([]selector.App{app}, backends.NewMemoryStore())
 	cfg := baseConfig(map[string]string{"contents": "write", "packages": "write"})
 
-	authorizer, err := NewAuthorizer(cfg, sel, map[string]github.ClientIface{"client-1": m}, slog.Default())
+	authorizer, err := NewAuthorizer(cfg, sel, map[string]github.ClientIface{"client-1": m})
 	require.NoError(t, err)
 
 	req := &Request{
@@ -160,7 +159,7 @@ func TestFetchPolicy_YMLFallback(t *testing.T) {
 
 	cfg := baseConfig(map[string]string{"contents": "write", "packages": "write"})
 	cfg.TrustPolicyPath = ".github/gate/trust-policy" // extension-less to trigger .yml fallback
-	authorizer, err := NewAuthorizer(cfg, sel, map[string]github.ClientIface{"client-1": m}, slog.Default())
+	authorizer, err := NewAuthorizer(cfg, sel, map[string]github.ClientIface{"client-1": m})
 	require.NoError(t, err)
 
 	result := authorizer.Authorize(t.Context(), &Request{
@@ -181,7 +180,7 @@ func TestAuthorize_CancelledContext(t *testing.T) {
 	m := &github.MockClient{}
 	m.On("GetContents", mock.Anything, mock.Anything, mock.Anything).
 		Return(nil, context.Canceled)
-	authorizer, err := NewAuthorizer(cfg, sel, map[string]github.ClientIface{"client-1": m}, slog.Default())
+	authorizer, err := NewAuthorizer(cfg, sel, map[string]github.ClientIface{"client-1": m})
 	require.NoError(t, err)
 
 	ctx, cancel := context.WithCancel(t.Context())

internal/sts/sts.go

@@ -84,15 +84,20 @@ type ExchangeRequest struct {
 }
 
 // ExchangeResponse represents a successful token exchange result.
+// Fields tagged `json:"-"` are populated for internal observers
+// (logging, metrics) and never serialized to the API client.
 type ExchangeResponse struct {
 	Token         string            `json:"token"`
 	ExpiresAt     time.Time         `json:"expires_at"`
 	MatchedPolicy string            `json:"matched_policy"`
 	Permissions   map[string]string `json:"permissions"`
 	RequestID     string            `json:"request_id"`
 
-	Issuer  string `json:"-"`
-	Subject string `json:"-"`
+	Issuer    string `json:"-"`
+	Subject   string `json:"-"`
+	ClientID  string `json:"-"`
+	TokenHash string `json:"-"`
+	TTL       int    `json:"-"`
 }
 
 // Service orchestrates the complete STS token exchange workflow.
@@ -145,7 +150,7 @@ func NewService(cfg *config.Config, dependencies Dependencies) (*Service, error)
 		return nil, fmt.Errorf("creating GitHub clients: %w", err)
 	}
 
-	auth, err := authorizer.NewAuthorizer(&cfg.Policy, dependencies.Selector, clients, dependencies.Logger)
+	auth, err := authorizer.NewAuthorizer(&cfg.Policy, dependencies.Selector, clients)
 	if err != nil {
 		return nil, fmt.Errorf("creating authorizer: %w", err)
 	}
@@ -196,16 +201,73 @@ func buildGitHubClients(cfg *config.Config) (map[string]github.ClientIface, erro
 	return clients, nil
 }
 
-// Exchange exchanges an OIDC token for a GitHub installation token.
-// It validates the OIDC token, authorizes the request against policies,
-// selects an appropriate GitHub App, and generates a scoped token.
-// All operations are audited and rate-limited.
+// logExchange emits one structured log line per Exchange call.
+func (s *Service) logExchange(ctx context.Context, requestID string, req *ExchangeRequest, resp *ExchangeResponse, err error) {
+	if err == nil && resp != nil {
+		s.logger.LogAttrs(ctx, slog.LevelInfo, "token exchange granted",
+			slog.String("request_id", requestID),
+			slog.String("repository", req.TargetRepository),
+			slog.String("issuer", resp.Issuer),
+			slog.String("subject", resp.Subject),
+			slog.String("policy", resp.MatchedPolicy),
+			slog.String("client_id", resp.ClientID),
+			slog.String("token_hash", resp.TokenHash),
+			slog.Int("ttl", resp.TTL),
+			slog.Time("expires_at", resp.ExpiresAt),
+			slog.Int("permissions_count", len(resp.Permissions)),
+		)
+		return
+	}
+
+	var exErr *ExchangeError
+	if errors.As(err, &exErr) {
+		attrs := []slog.Attr{
+			slog.String("request_id", exErr.RequestID),
+			slog.String("repository", req.TargetRepository),
+			slog.String("code", exErr.Code),
+			slog.String("message", exErr.Message),
+		}
+		if exErr.Issuer != "" {
+			attrs = append(attrs, slog.String("issuer", exErr.Issuer))
+		}
+		if exErr.Subject != "" {
+			attrs = append(attrs, slog.String("subject", exErr.Subject))
+		}
+		if exErr.Details != "" {
+			attrs = append(attrs, slog.String("details", exErr.Details))
+		}
+		level := slog.LevelWarn
+		if exErr.Code == ErrInternalError {
+			level = slog.LevelError
+		}
+		s.logger.LogAttrs(ctx, level, "token exchange denied", attrs...)
+		return
+	}
+
+	// Defensive: every Exchange exit returns nil or *ExchangeError today.
+	s.logger.ErrorContext(ctx, "token exchange failed",
+		"request_id", requestID,
+		"repository", req.TargetRepository,
+		"error", err,
+	)
+}
+
+// Exchange exchanges an OIDC token for a GitHub installation token,
+// emitting one structured log line per call.
 func (s *Service) Exchange(ctx context.Context, requestID string, req *ExchangeRequest) (*ExchangeResponse, error) {
-	if err := s.validateRequest(req); err != nil {
+	resp, err := s.exchange(ctx, requestID, req)
+	s.logExchange(ctx, requestID, req, resp, err)
+	return resp, err
+}
+
+// exchange performs the OIDC validation, authorization, app selection,
+// and token mint. The public Exchange wraps this with outcome logging.
+func (s *Service) exchange(ctx context.Context, requestID string, req *ExchangeRequest) (*ExchangeResponse, error) {
+	if validationErr := s.validateRequest(req); validationErr != nil {
 		return nil, &ExchangeError{
 			Code:      ErrInvalidRequest,
 			Message:   "Invalid request",
-			Details:   err.Error(),
+			Details:   validationErr.Error(),
 			RequestID: requestID,
 		}
 	}
@@ -224,6 +286,12 @@ func (s *Service) Exchange(ctx context.Context, requestID string, req *ExchangeR
 		}
 	}
 	validateSpan.SetAttributes(attribute.String("issuer", claims.Issuer))
+	s.logger.LogAttrs(ctx, slog.LevelDebug, "oidc validated",
+		slog.String("request_id", requestID),
+		slog.String("issuer", claims.Issuer),
+		slog.String("subject", claims.Subject),
+		slog.Time("expires_at", claims.ExpiresAt),
+	)
 
 	authReq := &authorizer.Request{
 		Claims:               claimsToMap(claims),
@@ -273,6 +341,10 @@ func (s *Service) Exchange(ctx context.Context, requestID string, req *ExchangeR
 		}).WithCaller(claims.Issuer, claims.Subject)
 	}
 	selectSpan.SetAttributes(attribute.String("client_id", app.ClientID))
+	s.logger.LogAttrs(ctx, slog.LevelDebug, "github app selected",
+		slog.String("request_id", requestID),
+		slog.String("client_id", app.ClientID),
+	)
 
 	client, ok := s.clients[app.ClientID]
 	if !ok {
@@ -334,6 +406,9 @@ func (s *Service) Exchange(ctx context.Context, requestID string, req *ExchangeR
 		RequestID:     requestID,
 		Issuer:        claims.Issuer,
 		Subject:       claims.Subject,
+		ClientID:      app.ClientID,
+		TokenHash:     tokenHash,
+		TTL:           result.EffectiveTTL,
 	}, nil
 }