From 0e4148b2296f25df2df5966909268c29a0cf5d22 Mon Sep 17 00:00:00 2001 From: Michael Velbaum Date: Sun, 28 Dec 2025 15:22:36 +0200 Subject: [PATCH] feat(logging): disambiguate OAuth credential selection in debug logs When multiple OAuth providers share an account email, the existing "Use OAuth" debug lines are ambiguous and hard to correlate with management usage stats. Include provider, auth file, and auth index in the selection log, and only compute these fields when debug logging is enabled to avoid impacting normal request performance. Before: [debug] Use OAuth user@example.com for model gemini-3-flash-preview [debug] Use OAuth user@example.com (project-1234) for model gemini-3-flash-preview After: [debug] Use OAuth provider=antigravity auth_file=antigravity-user_example_com.json auth_index=1a2b3c4d5e6f7788 account="user@example.com" for model gemini-3-flash-preview [debug] Use OAuth provider=gemini-cli auth_file=gemini-user@example.com-project-1234.json auth_index=99aabbccddeeff00 account="user@example.com (project-1234)" for model gemini-3-flash-preview --- sdk/cliproxy/auth/conductor.go | 126 +++++++++++++++++++++++---------- 1 file changed, 87 insertions(+), 39 deletions(-) diff --git a/sdk/cliproxy/auth/conductor.go b/sdk/cliproxy/auth/conductor.go index d16fc1ae..df3d8b3e 100644 --- a/sdk/cliproxy/auth/conductor.go +++ b/sdk/cliproxy/auth/conductor.go @@ -5,6 +5,7 @@ import ( "encoding/json" "errors" "net/http" + "path/filepath" "strconv" "strings" "sync" @@ -385,20 +386,23 @@ func (m *Manager) executeWithProvider(ctx context.Context, provider string, req return cliproxyexecutor.Response{}, errPick } - accountType, accountInfo := auth.AccountInfo() - proxyInfo := auth.ProxyInfo() entry := logEntryWithRequestID(ctx) - if accountType == "api_key" { - if proxyInfo != "" { - entry.Debugf("Use API key %s for model %s %s", util.HideAPIKey(accountInfo), req.Model, proxyInfo) - } else { - entry.Debugf("Use API key %s for model %s", util.HideAPIKey(accountInfo), req.Model) - } - } else if accountType == "oauth" { - if proxyInfo != "" { - entry.Debugf("Use OAuth %s for model %s %s", accountInfo, req.Model, proxyInfo) - } else { - entry.Debugf("Use OAuth %s for model %s", accountInfo, req.Model) + if log.IsLevelEnabled(log.DebugLevel) { + accountType, accountInfo := auth.AccountInfo() + proxyInfo := auth.ProxyInfo() + if accountType == "api_key" { + if proxyInfo != "" { + entry.Debugf("Use API key %s for model %s %s", util.HideAPIKey(accountInfo), req.Model, proxyInfo) + } else { + entry.Debugf("Use API key %s for model %s", util.HideAPIKey(accountInfo), req.Model) + } + } else if accountType == "oauth" { + ident := formatOauthIdentity(auth, provider, accountInfo) + if proxyInfo != "" { + entry.Debugf("Use OAuth %s for model %s %s", ident, req.Model, proxyInfo) + } else { + entry.Debugf("Use OAuth %s for model %s", ident, req.Model) + } } } @@ -446,20 +450,23 @@ func (m *Manager) executeCountWithProvider(ctx context.Context, provider string, return cliproxyexecutor.Response{}, errPick } - accountType, accountInfo := auth.AccountInfo() - proxyInfo := auth.ProxyInfo() entry := logEntryWithRequestID(ctx) - if accountType == "api_key" { - if proxyInfo != "" { - entry.Debugf("Use API key %s for model %s %s", util.HideAPIKey(accountInfo), req.Model, proxyInfo) - } else { - entry.Debugf("Use API key %s for model %s", util.HideAPIKey(accountInfo), req.Model) - } - } else if accountType == "oauth" { - if proxyInfo != "" { - entry.Debugf("Use OAuth %s for model %s %s", accountInfo, req.Model, proxyInfo) - } else { - entry.Debugf("Use OAuth %s for model %s", accountInfo, req.Model) + if log.IsLevelEnabled(log.DebugLevel) { + accountType, accountInfo := auth.AccountInfo() + proxyInfo := auth.ProxyInfo() + if accountType == "api_key" { + if proxyInfo != "" { + entry.Debugf("Use API key %s for model %s %s", util.HideAPIKey(accountInfo), req.Model, proxyInfo) + } else { + entry.Debugf("Use API key %s for model %s", util.HideAPIKey(accountInfo), req.Model) + } + } else if accountType == "oauth" { + ident := formatOauthIdentity(auth, provider, accountInfo) + if proxyInfo != "" { + entry.Debugf("Use OAuth %s for model %s %s", ident, req.Model, proxyInfo) + } else { + entry.Debugf("Use OAuth %s for model %s", ident, req.Model) + } } } @@ -507,20 +514,23 @@ func (m *Manager) executeStreamWithProvider(ctx context.Context, provider string return nil, errPick } - accountType, accountInfo := auth.AccountInfo() - proxyInfo := auth.ProxyInfo() entry := logEntryWithRequestID(ctx) - if accountType == "api_key" { - if proxyInfo != "" { - entry.Debugf("Use API key %s for model %s %s", util.HideAPIKey(accountInfo), req.Model, proxyInfo) - } else { - entry.Debugf("Use API key %s for model %s", util.HideAPIKey(accountInfo), req.Model) - } - } else if accountType == "oauth" { - if proxyInfo != "" { - entry.Debugf("Use OAuth %s for model %s %s", accountInfo, req.Model, proxyInfo) - } else { - entry.Debugf("Use OAuth %s for model %s", accountInfo, req.Model) + if log.IsLevelEnabled(log.DebugLevel) { + accountType, accountInfo := auth.AccountInfo() + proxyInfo := auth.ProxyInfo() + if accountType == "api_key" { + if proxyInfo != "" { + entry.Debugf("Use API key %s for model %s %s", util.HideAPIKey(accountInfo), req.Model, proxyInfo) + } else { + entry.Debugf("Use API key %s for model %s", util.HideAPIKey(accountInfo), req.Model) + } + } else if accountType == "oauth" { + ident := formatOauthIdentity(auth, provider, accountInfo) + if proxyInfo != "" { + entry.Debugf("Use OAuth %s for model %s %s", ident, req.Model, proxyInfo) + } else { + entry.Debugf("Use OAuth %s for model %s", ident, req.Model) + } } } @@ -1610,6 +1620,44 @@ func logEntryWithRequestID(ctx context.Context) *log.Entry { return log.NewEntry(log.StandardLogger()) } +func formatOauthIdentity(auth *Auth, provider string, accountInfo string) string { + if auth == nil { + return "" + } + authIndex := auth.EnsureIndex() + // Prefer the auth's provider when available. + providerName := strings.TrimSpace(auth.Provider) + if providerName == "" { + providerName = strings.TrimSpace(provider) + } + // Only log the basename to avoid leaking host paths. + // FileName may be unset for some auth backends; fall back to ID. + authFile := strings.TrimSpace(auth.FileName) + if authFile == "" { + authFile = strings.TrimSpace(auth.ID) + } + if authFile != "" { + authFile = filepath.Base(authFile) + } + parts := make([]string, 0, 3) + if providerName != "" { + parts = append(parts, "provider="+providerName) + } + if authFile != "" { + parts = append(parts, "auth_file="+authFile) + } + if authIndex != "" { + parts = append(parts, "auth_index="+authIndex) + } + if len(parts) == 0 { + return accountInfo + } + if accountInfo == "" { + return strings.Join(parts, " ") + } + return strings.Join(parts, " ") + " account=\"" + accountInfo + "\"" +} + // InjectCredentials delegates per-provider HTTP request preparation when supported. // If the registered executor for the auth provider implements RequestPreparer, // it will be invoked to modify the request (e.g., add headers).