Merge pull request #780 from mt21625457/feat/codex-remote-compact-outcome-logging
feat(openai-handler): support codex remote compact outcome logging
This commit is contained in:
192
backend/internal/handler/openai_gateway_compact_log_test.go
Normal file
192
backend/internal/handler/openai_gateway_compact_log_test.go
Normal file
@@ -0,0 +1,192 @@
|
|||||||
|
package handler
|
||||||
|
|
||||||
|
import (
|
||||||
|
"fmt"
|
||||||
|
"net/http"
|
||||||
|
"net/http/httptest"
|
||||||
|
"strings"
|
||||||
|
"sync"
|
||||||
|
"testing"
|
||||||
|
"time"
|
||||||
|
|
||||||
|
"github.com/Wei-Shaw/sub2api/internal/pkg/logger"
|
||||||
|
"github.com/gin-gonic/gin"
|
||||||
|
"github.com/stretchr/testify/require"
|
||||||
|
)
|
||||||
|
|
||||||
|
var handlerStructuredLogCaptureMu sync.Mutex
|
||||||
|
|
||||||
|
type handlerInMemoryLogSink struct {
|
||||||
|
mu sync.Mutex
|
||||||
|
events []*logger.LogEvent
|
||||||
|
}
|
||||||
|
|
||||||
|
func (s *handlerInMemoryLogSink) WriteLogEvent(event *logger.LogEvent) {
|
||||||
|
if event == nil {
|
||||||
|
return
|
||||||
|
}
|
||||||
|
cloned := *event
|
||||||
|
if event.Fields != nil {
|
||||||
|
cloned.Fields = make(map[string]any, len(event.Fields))
|
||||||
|
for k, v := range event.Fields {
|
||||||
|
cloned.Fields[k] = v
|
||||||
|
}
|
||||||
|
}
|
||||||
|
s.mu.Lock()
|
||||||
|
s.events = append(s.events, &cloned)
|
||||||
|
s.mu.Unlock()
|
||||||
|
}
|
||||||
|
|
||||||
|
func (s *handlerInMemoryLogSink) ContainsMessageAtLevel(substr, level string) bool {
|
||||||
|
s.mu.Lock()
|
||||||
|
defer s.mu.Unlock()
|
||||||
|
wantLevel := strings.ToLower(strings.TrimSpace(level))
|
||||||
|
for _, ev := range s.events {
|
||||||
|
if ev == nil {
|
||||||
|
continue
|
||||||
|
}
|
||||||
|
if strings.Contains(ev.Message, substr) && strings.ToLower(strings.TrimSpace(ev.Level)) == wantLevel {
|
||||||
|
return true
|
||||||
|
}
|
||||||
|
}
|
||||||
|
return false
|
||||||
|
}
|
||||||
|
|
||||||
|
func (s *handlerInMemoryLogSink) ContainsFieldValue(field, substr string) bool {
|
||||||
|
s.mu.Lock()
|
||||||
|
defer s.mu.Unlock()
|
||||||
|
for _, ev := range s.events {
|
||||||
|
if ev == nil || ev.Fields == nil {
|
||||||
|
continue
|
||||||
|
}
|
||||||
|
if v, ok := ev.Fields[field]; ok && strings.Contains(fmt.Sprint(v), substr) {
|
||||||
|
return true
|
||||||
|
}
|
||||||
|
}
|
||||||
|
return false
|
||||||
|
}
|
||||||
|
|
||||||
|
func captureHandlerStructuredLog(t *testing.T) (*handlerInMemoryLogSink, func()) {
|
||||||
|
t.Helper()
|
||||||
|
handlerStructuredLogCaptureMu.Lock()
|
||||||
|
|
||||||
|
err := logger.Init(logger.InitOptions{
|
||||||
|
Level: "debug",
|
||||||
|
Format: "json",
|
||||||
|
ServiceName: "sub2api",
|
||||||
|
Environment: "test",
|
||||||
|
Output: logger.OutputOptions{
|
||||||
|
ToStdout: true,
|
||||||
|
ToFile: false,
|
||||||
|
},
|
||||||
|
Sampling: logger.SamplingOptions{Enabled: false},
|
||||||
|
})
|
||||||
|
require.NoError(t, err)
|
||||||
|
|
||||||
|
sink := &handlerInMemoryLogSink{}
|
||||||
|
logger.SetSink(sink)
|
||||||
|
return sink, func() {
|
||||||
|
logger.SetSink(nil)
|
||||||
|
handlerStructuredLogCaptureMu.Unlock()
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
func TestIsOpenAIRemoteCompactPath(t *testing.T) {
|
||||||
|
require.False(t, isOpenAIRemoteCompactPath(nil))
|
||||||
|
|
||||||
|
gin.SetMode(gin.TestMode)
|
||||||
|
rec := httptest.NewRecorder()
|
||||||
|
c, _ := gin.CreateTestContext(rec)
|
||||||
|
|
||||||
|
c.Request = httptest.NewRequest(http.MethodPost, "/v1/responses/compact", nil)
|
||||||
|
require.True(t, isOpenAIRemoteCompactPath(c))
|
||||||
|
|
||||||
|
c.Request = httptest.NewRequest(http.MethodPost, "/responses/compact/", nil)
|
||||||
|
require.True(t, isOpenAIRemoteCompactPath(c))
|
||||||
|
|
||||||
|
c.Request = httptest.NewRequest(http.MethodPost, "/v1/responses", nil)
|
||||||
|
require.False(t, isOpenAIRemoteCompactPath(c))
|
||||||
|
}
|
||||||
|
|
||||||
|
func TestLogOpenAIRemoteCompactOutcome_Succeeded(t *testing.T) {
|
||||||
|
gin.SetMode(gin.TestMode)
|
||||||
|
logSink, restore := captureHandlerStructuredLog(t)
|
||||||
|
defer restore()
|
||||||
|
|
||||||
|
rec := httptest.NewRecorder()
|
||||||
|
c, _ := gin.CreateTestContext(rec)
|
||||||
|
c.Request = httptest.NewRequest(http.MethodPost, "/v1/responses/compact", nil)
|
||||||
|
c.Request.Header.Set("User-Agent", "codex_cli_rs/0.104.0")
|
||||||
|
c.Set(opsModelKey, "gpt-5.3-codex")
|
||||||
|
c.Set(opsAccountIDKey, int64(123))
|
||||||
|
c.Header("x-request-id", "rid-compact-ok")
|
||||||
|
c.Status(http.StatusOK)
|
||||||
|
|
||||||
|
h := &OpenAIGatewayHandler{}
|
||||||
|
h.logOpenAIRemoteCompactOutcome(c, time.Now().Add(-8*time.Millisecond))
|
||||||
|
|
||||||
|
require.True(t, logSink.ContainsMessageAtLevel("codex.remote_compact.succeeded", "info"))
|
||||||
|
require.True(t, logSink.ContainsFieldValue("compact_outcome", "succeeded"))
|
||||||
|
require.True(t, logSink.ContainsFieldValue("status_code", "200"))
|
||||||
|
require.True(t, logSink.ContainsFieldValue("path", "/v1/responses/compact"))
|
||||||
|
require.True(t, logSink.ContainsFieldValue("request_model", "gpt-5.3-codex"))
|
||||||
|
require.True(t, logSink.ContainsFieldValue("account_id", "123"))
|
||||||
|
require.True(t, logSink.ContainsFieldValue("upstream_request_id", "rid-compact-ok"))
|
||||||
|
}
|
||||||
|
|
||||||
|
func TestLogOpenAIRemoteCompactOutcome_Failed(t *testing.T) {
|
||||||
|
gin.SetMode(gin.TestMode)
|
||||||
|
logSink, restore := captureHandlerStructuredLog(t)
|
||||||
|
defer restore()
|
||||||
|
|
||||||
|
rec := httptest.NewRecorder()
|
||||||
|
c, _ := gin.CreateTestContext(rec)
|
||||||
|
c.Request = httptest.NewRequest(http.MethodPost, "/responses/compact", nil)
|
||||||
|
c.Request.Header.Set("User-Agent", "codex_cli_rs/0.104.0")
|
||||||
|
c.Status(http.StatusBadGateway)
|
||||||
|
|
||||||
|
h := &OpenAIGatewayHandler{}
|
||||||
|
h.logOpenAIRemoteCompactOutcome(c, time.Now())
|
||||||
|
|
||||||
|
require.True(t, logSink.ContainsMessageAtLevel("codex.remote_compact.failed", "warn"))
|
||||||
|
require.True(t, logSink.ContainsFieldValue("compact_outcome", "failed"))
|
||||||
|
require.True(t, logSink.ContainsFieldValue("status_code", "502"))
|
||||||
|
require.True(t, logSink.ContainsFieldValue("path", "/responses/compact"))
|
||||||
|
}
|
||||||
|
|
||||||
|
func TestLogOpenAIRemoteCompactOutcome_NonCompactSkips(t *testing.T) {
|
||||||
|
gin.SetMode(gin.TestMode)
|
||||||
|
logSink, restore := captureHandlerStructuredLog(t)
|
||||||
|
defer restore()
|
||||||
|
|
||||||
|
rec := httptest.NewRecorder()
|
||||||
|
c, _ := gin.CreateTestContext(rec)
|
||||||
|
c.Request = httptest.NewRequest(http.MethodPost, "/v1/responses", nil)
|
||||||
|
c.Status(http.StatusOK)
|
||||||
|
|
||||||
|
h := &OpenAIGatewayHandler{}
|
||||||
|
h.logOpenAIRemoteCompactOutcome(c, time.Now())
|
||||||
|
|
||||||
|
require.False(t, logSink.ContainsMessageAtLevel("codex.remote_compact.succeeded", "info"))
|
||||||
|
require.False(t, logSink.ContainsMessageAtLevel("codex.remote_compact.failed", "warn"))
|
||||||
|
}
|
||||||
|
|
||||||
|
func TestOpenAIResponses_CompactUnauthorizedLogsFailed(t *testing.T) {
|
||||||
|
gin.SetMode(gin.TestMode)
|
||||||
|
logSink, restore := captureHandlerStructuredLog(t)
|
||||||
|
defer restore()
|
||||||
|
|
||||||
|
rec := httptest.NewRecorder()
|
||||||
|
c, _ := gin.CreateTestContext(rec)
|
||||||
|
c.Request = httptest.NewRequest(http.MethodPost, "/v1/responses/compact", strings.NewReader(`{"model":"gpt-5.3-codex"}`))
|
||||||
|
c.Request.Header.Set("Content-Type", "application/json")
|
||||||
|
c.Request.Header.Set("User-Agent", "codex_cli_rs/0.104.0")
|
||||||
|
|
||||||
|
h := &OpenAIGatewayHandler{}
|
||||||
|
h.Responses(c)
|
||||||
|
|
||||||
|
require.Equal(t, http.StatusUnauthorized, rec.Code)
|
||||||
|
require.True(t, logSink.ContainsMessageAtLevel("codex.remote_compact.failed", "warn"))
|
||||||
|
require.True(t, logSink.ContainsFieldValue("status_code", "401"))
|
||||||
|
require.True(t, logSink.ContainsFieldValue("path", "/v1/responses/compact"))
|
||||||
|
}
|
||||||
@@ -33,6 +33,7 @@ type OpenAIGatewayHandler struct {
|
|||||||
errorPassthroughService *service.ErrorPassthroughService
|
errorPassthroughService *service.ErrorPassthroughService
|
||||||
concurrencyHelper *ConcurrencyHelper
|
concurrencyHelper *ConcurrencyHelper
|
||||||
maxAccountSwitches int
|
maxAccountSwitches int
|
||||||
|
cfg *config.Config
|
||||||
}
|
}
|
||||||
|
|
||||||
// NewOpenAIGatewayHandler creates a new OpenAIGatewayHandler
|
// NewOpenAIGatewayHandler creates a new OpenAIGatewayHandler
|
||||||
@@ -61,6 +62,7 @@ func NewOpenAIGatewayHandler(
|
|||||||
errorPassthroughService: errorPassthroughService,
|
errorPassthroughService: errorPassthroughService,
|
||||||
concurrencyHelper: NewConcurrencyHelper(concurrencyService, SSEPingFormatComment, pingInterval),
|
concurrencyHelper: NewConcurrencyHelper(concurrencyService, SSEPingFormatComment, pingInterval),
|
||||||
maxAccountSwitches: maxAccountSwitches,
|
maxAccountSwitches: maxAccountSwitches,
|
||||||
|
cfg: cfg,
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -70,6 +72,8 @@ func (h *OpenAIGatewayHandler) Responses(c *gin.Context) {
|
|||||||
// 局部兜底:确保该 handler 内部任何 panic 都不会击穿到进程级。
|
// 局部兜底:确保该 handler 内部任何 panic 都不会击穿到进程级。
|
||||||
streamStarted := false
|
streamStarted := false
|
||||||
defer h.recoverResponsesPanic(c, &streamStarted)
|
defer h.recoverResponsesPanic(c, &streamStarted)
|
||||||
|
compactStartedAt := time.Now()
|
||||||
|
defer h.logOpenAIRemoteCompactOutcome(c, compactStartedAt)
|
||||||
setOpenAIClientTransportHTTP(c)
|
setOpenAIClientTransportHTTP(c)
|
||||||
|
|
||||||
requestStart := time.Now()
|
requestStart := time.Now()
|
||||||
@@ -340,6 +344,86 @@ func (h *OpenAIGatewayHandler) Responses(c *gin.Context) {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
func isOpenAIRemoteCompactPath(c *gin.Context) bool {
|
||||||
|
if c == nil || c.Request == nil || c.Request.URL == nil {
|
||||||
|
return false
|
||||||
|
}
|
||||||
|
normalizedPath := strings.TrimRight(strings.TrimSpace(c.Request.URL.Path), "/")
|
||||||
|
return strings.HasSuffix(normalizedPath, "/responses/compact")
|
||||||
|
}
|
||||||
|
|
||||||
|
func (h *OpenAIGatewayHandler) logOpenAIRemoteCompactOutcome(c *gin.Context, startedAt time.Time) {
|
||||||
|
if !isOpenAIRemoteCompactPath(c) {
|
||||||
|
return
|
||||||
|
}
|
||||||
|
|
||||||
|
var (
|
||||||
|
ctx = context.Background()
|
||||||
|
path string
|
||||||
|
status int
|
||||||
|
)
|
||||||
|
if c != nil {
|
||||||
|
if c.Request != nil {
|
||||||
|
ctx = c.Request.Context()
|
||||||
|
if c.Request.URL != nil {
|
||||||
|
path = strings.TrimSpace(c.Request.URL.Path)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
if c.Writer != nil {
|
||||||
|
status = c.Writer.Status()
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
outcome := "failed"
|
||||||
|
if status >= 200 && status < 300 {
|
||||||
|
outcome = "succeeded"
|
||||||
|
}
|
||||||
|
latencyMs := time.Since(startedAt).Milliseconds()
|
||||||
|
if latencyMs < 0 {
|
||||||
|
latencyMs = 0
|
||||||
|
}
|
||||||
|
|
||||||
|
fields := []zap.Field{
|
||||||
|
zap.String("component", "handler.openai_gateway.responses"),
|
||||||
|
zap.Bool("remote_compact", true),
|
||||||
|
zap.String("compact_outcome", outcome),
|
||||||
|
zap.Int("status_code", status),
|
||||||
|
zap.Int64("latency_ms", latencyMs),
|
||||||
|
zap.String("path", path),
|
||||||
|
zap.Bool("force_codex_cli", h != nil && h.cfg != nil && h.cfg.Gateway.ForceCodexCLI),
|
||||||
|
}
|
||||||
|
|
||||||
|
if c != nil {
|
||||||
|
if userAgent := strings.TrimSpace(c.GetHeader("User-Agent")); userAgent != "" {
|
||||||
|
fields = append(fields, zap.String("request_user_agent", userAgent))
|
||||||
|
}
|
||||||
|
if v, ok := c.Get(opsModelKey); ok {
|
||||||
|
if model, ok := v.(string); ok && strings.TrimSpace(model) != "" {
|
||||||
|
fields = append(fields, zap.String("request_model", strings.TrimSpace(model)))
|
||||||
|
}
|
||||||
|
}
|
||||||
|
if v, ok := c.Get(opsAccountIDKey); ok {
|
||||||
|
if accountID, ok := v.(int64); ok && accountID > 0 {
|
||||||
|
fields = append(fields, zap.Int64("account_id", accountID))
|
||||||
|
}
|
||||||
|
}
|
||||||
|
if c.Writer != nil {
|
||||||
|
if upstreamRequestID := strings.TrimSpace(c.Writer.Header().Get("x-request-id")); upstreamRequestID != "" {
|
||||||
|
fields = append(fields, zap.String("upstream_request_id", upstreamRequestID))
|
||||||
|
} else if upstreamRequestID := strings.TrimSpace(c.Writer.Header().Get("X-Request-Id")); upstreamRequestID != "" {
|
||||||
|
fields = append(fields, zap.String("upstream_request_id", upstreamRequestID))
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
log := logger.FromContext(ctx).With(fields...)
|
||||||
|
if outcome == "succeeded" {
|
||||||
|
log.Info("codex.remote_compact.succeeded")
|
||||||
|
return
|
||||||
|
}
|
||||||
|
log.Warn("codex.remote_compact.failed")
|
||||||
|
}
|
||||||
|
|
||||||
func (h *OpenAIGatewayHandler) validateFunctionCallOutputRequest(c *gin.Context, body []byte, reqLog *zap.Logger) bool {
|
func (h *OpenAIGatewayHandler) validateFunctionCallOutputRequest(c *gin.Context, body []byte, reqLog *zap.Logger) bool {
|
||||||
if !gjson.GetBytes(body, `input.#(type=="function_call_output")`).Exists() {
|
if !gjson.GetBytes(body, `input.#(type=="function_call_output")`).Exists() {
|
||||||
return true
|
return true
|
||||||
|
|||||||
Reference in New Issue
Block a user