From 0e4148b2296f25df2df5966909268c29a0cf5d22 Mon Sep 17 00:00:00 2001 From: Michael Velbaum Date: Sun, 28 Dec 2025 15:22:36 +0200 Subject: [PATCH 1/5] 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 d16fc1ae8..df3d8b3ee 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). From 79fbcb3ec40ba919d72fbe2d17e0392e7b5dfa4a Mon Sep 17 00:00:00 2001 From: Michael Velbaum Date: Sun, 28 Dec 2025 15:32:54 +0200 Subject: [PATCH 2/5] fix(logging): quote OAuth account field Use strconv.Quote when embedding the OAuth account in debug logs so unexpected characters (e.g. quotes) can't break key=value parsing. --- sdk/cliproxy/auth/conductor.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sdk/cliproxy/auth/conductor.go b/sdk/cliproxy/auth/conductor.go index df3d8b3ee..281216ede 100644 --- a/sdk/cliproxy/auth/conductor.go +++ b/sdk/cliproxy/auth/conductor.go @@ -1655,7 +1655,7 @@ func formatOauthIdentity(auth *Auth, provider string, accountInfo string) string if accountInfo == "" { return strings.Join(parts, " ") } - return strings.Join(parts, " ") + " account=\"" + accountInfo + "\"" + return strings.Join(parts, " ") + " account=" + strconv.Quote(accountInfo) } // InjectCredentials delegates per-provider HTTP request preparation when supported. From 48f6d7abdf8409fef1f67c5a3c5ff49123a500e1 Mon Sep 17 00:00:00 2001 From: Michael Velbaum Date: Sun, 28 Dec 2025 15:42:35 +0200 Subject: [PATCH 3/5] refactor(logging): dedupe auth selection debug logs Extract repeated debug logging for selected auth credentials into a helper so execute, count, and stream paths stay consistent. --- sdk/cliproxy/auth/conductor.go | 89 ++++++++++++---------------------- 1 file changed, 32 insertions(+), 57 deletions(-) diff --git a/sdk/cliproxy/auth/conductor.go b/sdk/cliproxy/auth/conductor.go index 281216ede..fe41ae01f 100644 --- a/sdk/cliproxy/auth/conductor.go +++ b/sdk/cliproxy/auth/conductor.go @@ -386,25 +386,7 @@ func (m *Manager) executeWithProvider(ctx context.Context, provider string, req return cliproxyexecutor.Response{}, errPick } - entry := logEntryWithRequestID(ctx) - 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) - } - } - } + debugLogAuthSelection(ctx, auth, provider, req.Model) tried[auth.ID] = struct{}{} execCtx := ctx @@ -450,25 +432,7 @@ func (m *Manager) executeCountWithProvider(ctx context.Context, provider string, return cliproxyexecutor.Response{}, errPick } - entry := logEntryWithRequestID(ctx) - 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) - } - } - } + debugLogAuthSelection(ctx, auth, provider, req.Model) tried[auth.ID] = struct{}{} execCtx := ctx @@ -514,25 +478,7 @@ func (m *Manager) executeStreamWithProvider(ctx context.Context, provider string return nil, errPick } - entry := logEntryWithRequestID(ctx) - 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) - } - } - } + debugLogAuthSelection(ctx, auth, provider, req.Model) tried[auth.ID] = struct{}{} execCtx := ctx @@ -1620,6 +1566,35 @@ func logEntryWithRequestID(ctx context.Context) *log.Entry { return log.NewEntry(log.StandardLogger()) } +func debugLogAuthSelection(ctx context.Context, auth *Auth, provider string, model string) { + if !log.IsLevelEnabled(log.DebugLevel) { + return + } + if auth == nil { + return + } + entry := logEntryWithRequestID(ctx) + 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), model, proxyInfo) + } else { + entry.Debugf("Use API key %s for model %s", util.HideAPIKey(accountInfo), model) + } + return + } + if accountType != "oauth" { + return + } + ident := formatOauthIdentity(auth, provider, accountInfo) + if proxyInfo != "" { + entry.Debugf("Use OAuth %s for model %s %s", ident, model, proxyInfo) + return + } + entry.Debugf("Use OAuth %s for model %s", ident, model) +} + func formatOauthIdentity(auth *Auth, provider string, accountInfo string) string { if auth == nil { return "" From 48f19aab51d6656469e255c53689f61f0337b692 Mon Sep 17 00:00:00 2001 From: Michael Velbaum Date: Sun, 28 Dec 2025 15:51:11 +0200 Subject: [PATCH 4/5] refactor(logging): pass request entry into auth selection log Avoid re-creating the request-scoped log entry in the helper and use a switch for account type dispatch. --- sdk/cliproxy/auth/conductor.go | 47 ++++++++++++++++++---------------- 1 file changed, 25 insertions(+), 22 deletions(-) diff --git a/sdk/cliproxy/auth/conductor.go b/sdk/cliproxy/auth/conductor.go index fe41ae01f..330d308af 100644 --- a/sdk/cliproxy/auth/conductor.go +++ b/sdk/cliproxy/auth/conductor.go @@ -386,7 +386,10 @@ func (m *Manager) executeWithProvider(ctx context.Context, provider string, req return cliproxyexecutor.Response{}, errPick } - debugLogAuthSelection(ctx, auth, provider, req.Model) + if log.IsLevelEnabled(log.DebugLevel) { + entry := logEntryWithRequestID(ctx) + debugLogAuthSelection(entry, auth, provider, req.Model) + } tried[auth.ID] = struct{}{} execCtx := ctx @@ -432,7 +435,10 @@ func (m *Manager) executeCountWithProvider(ctx context.Context, provider string, return cliproxyexecutor.Response{}, errPick } - debugLogAuthSelection(ctx, auth, provider, req.Model) + if log.IsLevelEnabled(log.DebugLevel) { + entry := logEntryWithRequestID(ctx) + debugLogAuthSelection(entry, auth, provider, req.Model) + } tried[auth.ID] = struct{}{} execCtx := ctx @@ -478,7 +484,10 @@ func (m *Manager) executeStreamWithProvider(ctx context.Context, provider string return nil, errPick } - debugLogAuthSelection(ctx, auth, provider, req.Model) + if log.IsLevelEnabled(log.DebugLevel) { + entry := logEntryWithRequestID(ctx) + debugLogAuthSelection(entry, auth, provider, req.Model) + } tried[auth.ID] = struct{}{} execCtx := ctx @@ -1566,33 +1575,27 @@ func logEntryWithRequestID(ctx context.Context) *log.Entry { return log.NewEntry(log.StandardLogger()) } -func debugLogAuthSelection(ctx context.Context, auth *Auth, provider string, model string) { - if !log.IsLevelEnabled(log.DebugLevel) { +func debugLogAuthSelection(entry *log.Entry, auth *Auth, provider string, model string) { + if entry == nil || auth == nil { return } - if auth == nil { - return - } - entry := logEntryWithRequestID(ctx) accountType, accountInfo := auth.AccountInfo() proxyInfo := auth.ProxyInfo() - if accountType == "api_key" { + switch accountType { + case "api_key": if proxyInfo != "" { entry.Debugf("Use API key %s for model %s %s", util.HideAPIKey(accountInfo), model, proxyInfo) - } else { - entry.Debugf("Use API key %s for model %s", util.HideAPIKey(accountInfo), model) + return } - return - } - if accountType != "oauth" { - return - } - ident := formatOauthIdentity(auth, provider, accountInfo) - if proxyInfo != "" { - entry.Debugf("Use OAuth %s for model %s %s", ident, model, proxyInfo) - return + entry.Debugf("Use API key %s for model %s", util.HideAPIKey(accountInfo), model) + case "oauth": + ident := formatOauthIdentity(auth, provider, accountInfo) + if proxyInfo != "" { + entry.Debugf("Use OAuth %s for model %s %s", ident, model, proxyInfo) + return + } + entry.Debugf("Use OAuth %s for model %s", ident, model) } - entry.Debugf("Use OAuth %s for model %s", ident, model) } func formatOauthIdentity(auth *Auth, provider string, accountInfo string) string { From cb3bdffb43a58ff32760a22222980648da18be32 Mon Sep 17 00:00:00 2001 From: Michael Velbaum Date: Sun, 28 Dec 2025 16:10:11 +0200 Subject: [PATCH 5/5] refactor(logging): streamline auth selection debug messages Reduce duplicate Debugf calls by appending proxy info via an optional suffix and keep the debug-level guard inside the helper. --- sdk/cliproxy/auth/conductor.go | 37 ++++++++++++++-------------------- 1 file changed, 15 insertions(+), 22 deletions(-) diff --git a/sdk/cliproxy/auth/conductor.go b/sdk/cliproxy/auth/conductor.go index 330d308af..ada400632 100644 --- a/sdk/cliproxy/auth/conductor.go +++ b/sdk/cliproxy/auth/conductor.go @@ -386,10 +386,8 @@ func (m *Manager) executeWithProvider(ctx context.Context, provider string, req return cliproxyexecutor.Response{}, errPick } - if log.IsLevelEnabled(log.DebugLevel) { - entry := logEntryWithRequestID(ctx) - debugLogAuthSelection(entry, auth, provider, req.Model) - } + entry := logEntryWithRequestID(ctx) + debugLogAuthSelection(entry, auth, provider, req.Model) tried[auth.ID] = struct{}{} execCtx := ctx @@ -435,10 +433,8 @@ func (m *Manager) executeCountWithProvider(ctx context.Context, provider string, return cliproxyexecutor.Response{}, errPick } - if log.IsLevelEnabled(log.DebugLevel) { - entry := logEntryWithRequestID(ctx) - debugLogAuthSelection(entry, auth, provider, req.Model) - } + entry := logEntryWithRequestID(ctx) + debugLogAuthSelection(entry, auth, provider, req.Model) tried[auth.ID] = struct{}{} execCtx := ctx @@ -484,10 +480,8 @@ func (m *Manager) executeStreamWithProvider(ctx context.Context, provider string return nil, errPick } - if log.IsLevelEnabled(log.DebugLevel) { - entry := logEntryWithRequestID(ctx) - debugLogAuthSelection(entry, auth, provider, req.Model) - } + entry := logEntryWithRequestID(ctx) + debugLogAuthSelection(entry, auth, provider, req.Model) tried[auth.ID] = struct{}{} execCtx := ctx @@ -1576,25 +1570,24 @@ func logEntryWithRequestID(ctx context.Context) *log.Entry { } func debugLogAuthSelection(entry *log.Entry, auth *Auth, provider string, model string) { + if !log.IsLevelEnabled(log.DebugLevel) { + return + } if entry == nil || auth == nil { return } accountType, accountInfo := auth.AccountInfo() proxyInfo := auth.ProxyInfo() + suffix := "" + if proxyInfo != "" { + suffix = " " + proxyInfo + } switch accountType { case "api_key": - if proxyInfo != "" { - entry.Debugf("Use API key %s for model %s %s", util.HideAPIKey(accountInfo), model, proxyInfo) - return - } - entry.Debugf("Use API key %s for model %s", util.HideAPIKey(accountInfo), model) + entry.Debugf("Use API key %s for model %s%s", util.HideAPIKey(accountInfo), model, suffix) case "oauth": ident := formatOauthIdentity(auth, provider, accountInfo) - if proxyInfo != "" { - entry.Debugf("Use OAuth %s for model %s %s", ident, model, proxyInfo) - return - } - entry.Debugf("Use OAuth %s for model %s", ident, model) + entry.Debugf("Use OAuth %s for model %s%s", ident, model, suffix) } }