| @@ -26,6 +26,7 @@ import ( · 25 unmodified lines |
| 26 | 26 | "github.com/router-for-me/CLIProxyAPI/v7/internal/redisqueue" |
| 27 | 27 | "github.com/router-for-me/CLIProxyAPI/v7/internal/registry" |
| 28 | 28 | "github.com/router-for-me/CLIProxyAPI/v7/internal/runtime/executor" |
| 29 | + runtimehelps "github.com/router-for-me/CLIProxyAPI/v7/internal/runtime/executor/helps" |
| 29 | 30 | sdkaccess "github.com/router-for-me/CLIProxyAPI/v7/sdk/access" |
| 30 | 31 | "github.com/router-for-me/CLIProxyAPI/v7/sdk/cliproxy/auth" |
| 31 | 32 | "github.com/router-for-me/CLIProxyAPI/v7/sdk/cliproxy/executionregistry" |
| @@ -2707,3 +2708,263 @@ func TestUpdateClientsContext_AntigravityConnectionPoolPurgesTransports(t *testi · 2675 unmodified lines |
| 2707 | 2708 | t.Fatalf("AntigravityTransportsLen() after reload = %d, want 0", got) |
| 2708 | 2709 | } |
| 2709 | 2710 | } |
| 2711 | + |
| 2712 | +type mockServerStreamingCaptureExecutor struct { |
| 2713 | + cfg *proxyconfig.Config |
| 2714 | + capturedCtx context.Context |
| 2715 | + executionCalls int |
| 2716 | +} |
| 2717 | + |
| 2718 | +func (e *mockServerStreamingCaptureExecutor) Identifier() string { return "codex-test" } |
| 2719 | + |
| 2720 | +func (e *mockServerStreamingCaptureExecutor) Execute(ctx context.Context, _ *auth.Auth, _ coreexecutor.Request, _ coreexecutor.Options) (coreexecutor.Response, error) { |
| 2721 | + e.capturedCtx = ctx |
| 2722 | + return coreexecutor.Response{Payload: []byte(`{"id":"resp-1","status":"completed"}`)}, nil |
| 2723 | +} |
| 2724 | + |
| 2725 | +func (e *mockServerStreamingCaptureExecutor) ExecuteStream(ctx context.Context, _ *auth.Auth, _ coreexecutor.Request, _ coreexecutor.Options) (*coreexecutor.StreamResult, error) { |
| 2726 | + e.capturedCtx = ctx |
| 2727 | + e.executionCalls++ |
| 2728 | + |
| 2729 | + runtimehelps.RecordAPIRequest(ctx, e.cfg, runtimehelps.UpstreamRequestLog{ |
| 2730 | + URL: "https://api.example.com/v1/responses", |
| 2731 | + Method: http.MethodPost, |
| 2732 | + Headers: http.Header{"Content-Type": []string{"application/json"}}, |
| 2733 | + Body: []byte(`{"model":"gpt-5-codex","input":[]}`), |
| 2734 | + }) |
| 2735 | + |
| 2736 | + ch := make(chan coreexecutor.StreamChunk, 2) |
| 2737 | + chunkPayload := []byte("event: response.output_item.added\ndata: {\"type\":\"response.output_item.added\"}\n\n") |
| 2738 | + runtimehelps.AppendAPIResponseChunk(ctx, e.cfg, chunkPayload) |
| 2739 | + ch <- coreexecutor.StreamChunk{Payload: chunkPayload} |
| 2740 | + |
| 2741 | + terminalPayload := []byte("event: response.completed\ndata: {\"type\":\"response.completed\"}\n\n") |
| 2742 | + runtimehelps.AppendAPIResponseChunk(ctx, e.cfg, terminalPayload) |
| 2743 | + ch <- coreexecutor.StreamChunk{Payload: terminalPayload} |
| 2744 | + close(ch) |
| 2745 | + |
| 2746 | + return &coreexecutor.StreamResult{Chunks: ch}, nil |
| 2747 | +} |
| 2748 | + |
| 2749 | +func (e *mockServerStreamingCaptureExecutor) Refresh(_ context.Context, auth *auth.Auth) (*auth.Auth, error) { |
| 2750 | + return auth, nil |
| 2751 | +} |
| 2752 | + |
| 2753 | +func (e *mockServerStreamingCaptureExecutor) CountTokens(_ context.Context, _ *auth.Auth, _ coreexecutor.Request, _ coreexecutor.Options) (coreexecutor.Response, error) { |
| 2754 | + return coreexecutor.Response{}, errors.New("not implemented") |
| 2755 | +} |
| 2756 | + |
| 2757 | +func (e *mockServerStreamingCaptureExecutor) HttpRequest(_ context.Context, _ *auth.Auth, _ *http.Request) (*http.Response, error) { |
| 2758 | + return nil, errors.New("not implemented") |
| 2759 | +} |
| 2760 | + |
| 2761 | +func TestServerResponsesStreamingRequestLogCapturesUpstreamSections(t *testing.T) { |
| 2762 | + gin.SetMode(gin.TestMode) |
| 2763 | + |
| 2764 | + tmpDir := t.TempDir() |
| 2765 | + logsDir := filepath.Join(tmpDir, "logs") |
| 2766 | + if err := os.MkdirAll(logsDir, 0o700); err != nil { |
| 2767 | + t.Fatalf("failed to create logs dir: %v", err) |
| 2768 | + } |
| 2769 | + |
| 2770 | + mockLogger := internallogging.NewFileRequestLogger(true, logsDir, "", 10) |
| 2771 | + server := newTestServerWithOptions(t, WithRequestLoggerFactory(func(*proxyconfig.Config, string) internallogging.RequestLogger { |
| 2772 | + return mockLogger |
| 2773 | + })) |
| 2774 | + server.cfg.RequestLog = true |
| 2775 | + server.cfg.LoggingToFile = true |
| 2776 | + |
| 2777 | + mockExec := &mockServerStreamingCaptureExecutor{cfg: server.cfg} |
| 2778 | + server.handlers.AuthManager.RegisterExecutor(mockExec) |
| 2779 | + |
| 2780 | + credential := &auth.Auth{ |
| 2781 | + ID: "codex-stream-auth", |
| 2782 | + Provider: mockExec.Identifier(), |
| 2783 | + Status: auth.StatusActive, |
| 2784 | + } |
| 2785 | + if _, err := server.handlers.AuthManager.Register(context.Background(), credential); err != nil { |
| 2786 | + t.Fatalf("register auth: %v", err) |
| 2787 | + } |
| 2788 | + registry.GetGlobalRegistry().RegisterClient(credential.ID, credential.Provider, []*registry.ModelInfo{{ID: "gpt-5-codex"}}) |
| 2789 | + t.Cleanup(func() { |
| 2790 | + registry.GetGlobalRegistry().UnregisterClient(credential.ID) |
| 2791 | + }) |
| 2792 | + |
| 2793 | + rr := httptest.NewRecorder() |
| 2794 | + body := `{"model":"gpt-5-codex","input":[{"type":"message","role":"user","content":"hi"}],"stream":true}` |
| 2795 | + req := httptest.NewRequest(http.MethodPost, "/v1/responses", strings.NewReader(body)) |
| 2796 | + req.Header.Set("Authorization", "Bearer test-key") |
| 2797 | + req.Header.Set("Content-Type", "application/json") |
| 2798 | + server.engine.ServeHTTP(rr, req) |
| 2799 | + |
| 2800 | + if rr.Code != http.StatusOK { |
| 2801 | + t.Fatalf("status = %d, want 200; body=%s", rr.Code, rr.Body.String()) |
| 2802 | + } |
| 2803 | + if mockExec.executionCalls != 1 { |
| 2804 | + t.Fatalf("executor calls = %d, want 1", mockExec.executionCalls) |
| 2805 | + } |
| 2806 | + |
| 2807 | + entries, errReadDir := os.ReadDir(logsDir) |
| 2808 | + if errReadDir != nil { |
| 2809 | + t.Fatalf("read logs dir: %v", errReadDir) |
| 2810 | + } |
| 2811 | + var logPath string |
| 2812 | + for _, entry := range entries { |
| 2813 | + if strings.HasPrefix(entry.Name(), "v1-responses-") && strings.HasSuffix(entry.Name(), ".log") { |
| 2814 | + logPath = filepath.Join(logsDir, entry.Name()) |
| 2815 | + break |
| 2816 | + } |
| 2817 | + } |
| 2818 | + if logPath == "" { |
| 2819 | + t.Fatal("streaming request log was not created in logs dir") |
| 2820 | + } |
| 2821 | + content, errReadLog := os.ReadFile(logPath) |
| 2822 | + if errReadLog != nil { |
| 2823 | + t.Fatalf("read log file: %v", errReadLog) |
| 2824 | + } |
| 2825 | + logText := string(content) |
| 2826 | + apiRequestIdx := strings.Index(logText, "=== API REQUEST 1 ===") |
| 2827 | + if apiRequestIdx == -1 { |
| 2828 | + t.Fatalf("streaming log missing API REQUEST 1:\n%s", logText) |
| 2829 | + } |
| 2830 | + apiResponseIdx := strings.Index(logText, "=== API RESPONSE 1 ===") |
| 2831 | + if apiResponseIdx == -1 { |
| 2832 | + t.Fatalf("streaming log missing API RESPONSE 1:\n%s", logText) |
| 2833 | + } |
| 2834 | + downstreamResponseIdx := strings.Index(logText, "=== RESPONSE ===") |
| 2835 | + if downstreamResponseIdx == -1 { |
| 2836 | + t.Fatalf("streaming log missing downstream RESPONSE:\n%s", logText) |
| 2837 | + } |
| 2838 | + if apiRequestIdx >= apiResponseIdx || apiResponseIdx >= downstreamResponseIdx { |
| 2839 | + t.Fatalf("unexpected section order (req=%d, apiResp=%d, resp=%d):\n%s", apiRequestIdx, apiResponseIdx, downstreamResponseIdx, logText) |
| 2840 | + } |
| 2841 | + apiRequestSection := logText[apiRequestIdx:apiResponseIdx] |
| 2842 | + apiResponseSection := logText[apiResponseIdx:downstreamResponseIdx] |
| 2843 | + if !strings.Contains(apiRequestSection, "https://api.example.com/v1/responses") { |
| 2844 | + t.Fatalf("API REQUEST section missing upstream URL:\n%s", apiRequestSection) |
| 2845 | + } |
| 2846 | + if !strings.Contains(apiRequestSection, `"gpt-5-codex"`) { |
| 2847 | + t.Fatalf("API REQUEST section missing request body:\n%s", apiRequestSection) |
| 2848 | + } |
| 2849 | + if !strings.Contains(apiResponseSection, "response.output_item.added") { |
| 2850 | + t.Fatalf("API RESPONSE section missing response chunk data:\n%s", apiResponseSection) |
| 2851 | + } |
| 2852 | +} |
| 2853 | + |
| 2854 | +func TestServerCodexAPIKeyResponsesStreamingRequestLog(t *testing.T) { |
| 2855 | + gin.SetMode(gin.TestMode) |
| 2856 | + |
| 2857 | + upstreamReceived := make(chan struct{}, 1) |
| 2858 | + mockUpstream := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { |
| 2859 | + select { |
| 2860 | + case upstreamReceived <- struct{}{}: |
| 2861 | + default: |
| 2862 | + } |
| 2863 | + w.Header().Set("Content-Type", "text/event-stream") |
| 2864 | + w.WriteHeader(http.StatusOK) |
| 2865 | + _, _ = w.Write([]byte("data: {\"type\":\"response.output_item.added\"}\n\n")) |
| 2866 | + if f, ok := w.(http.Flusher); ok { |
| 2867 | + f.Flush() |
| 2868 | + } |
| 2869 | + _, _ = w.Write([]byte("data: {\"type\":\"response.completed\"}\n\n")) |
| 2870 | + if f, ok := w.(http.Flusher); ok { |
| 2871 | + f.Flush() |
| 2872 | + } |
| 2873 | + })) |
| 2874 | + defer mockUpstream.Close() |
| 2875 | + |
| 2876 | + tmpDir := t.TempDir() |
| 2877 | + logsDir := filepath.Join(tmpDir, "logs") |
| 2878 | + if err := os.MkdirAll(logsDir, 0o700); err != nil { |
| 2879 | + t.Fatalf("failed to create logs dir: %v", err) |
| 2880 | + } |
| 2881 | + |
| 2882 | + mockLogger := internallogging.NewFileRequestLogger(true, logsDir, "", 10) |
| 2883 | + server := newTestServerWithOptions(t, WithRequestLoggerFactory(func(*proxyconfig.Config, string) internallogging.RequestLogger { |
| 2884 | + return mockLogger |
| 2885 | + })) |
| 2886 | + server.cfg.RequestLog = true |
| 2887 | + server.cfg.LoggingToFile = true |
| 2888 | + |
| 2889 | + codexExec := executor.NewCodexExecutor(server.cfg) |
| 2890 | + server.handlers.AuthManager.RegisterExecutor(codexExec) |
| 2891 | + |
| 2892 | + credential := &auth.Auth{ |
| 2893 | + ID: "codex-api-key-test", |
| 2894 | + Provider: "codex", |
| 2895 | + Status: auth.StatusActive, |
| 2896 | + Attributes: map[string]string{ |
| 2897 | + auth.AttributeAPIKey: "test-codex-key", |
| 2898 | + "base_url": mockUpstream.URL, |
| 2899 | + }, |
| 2900 | + } |
| 2901 | + if _, err := server.handlers.AuthManager.Register(context.Background(), credential); err != nil { |
| 2902 | + t.Fatalf("register auth: %v", err) |
| 2903 | + } |
| 2904 | + registry.GetGlobalRegistry().RegisterClient(credential.ID, credential.Provider, []*registry.ModelInfo{{ID: "gpt-5-codex"}}) |
| 2905 | + t.Cleanup(func() { |
| 2906 | + registry.GetGlobalRegistry().UnregisterClient(credential.ID) |
| 2907 | + }) |
| 2908 | + |
| 2909 | + rr := httptest.NewRecorder() |
| 2910 | + body := `{"model":"gpt-5-codex","input":[{"type":"message","role":"user","content":"hello"}],"stream":true}` |
| 2911 | + req := httptest.NewRequest(http.MethodPost, "/v1/responses", strings.NewReader(body)) |
| 2912 | + req.Header.Set("Authorization", "Bearer test-key") |
| 2913 | + req.Header.Set("Content-Type", "application/json") |
| 2914 | + server.engine.ServeHTTP(rr, req) |
| 2915 | + |
| 2916 | + if rr.Code != http.StatusOK { |
| 2917 | + t.Fatalf("status = %d, want 200; body=%s", rr.Code, rr.Body.String()) |
| 2918 | + } |
| 2919 | + select { |
| 2920 | + case <-upstreamReceived: |
| 2921 | + case <-time.After(5 * time.Second): |
| 2922 | + t.Fatal("timeout waiting for upstream request") |
| 2923 | + } |
| 2924 | + |
| 2925 | + entries, errReadDir := os.ReadDir(logsDir) |
| 2926 | + if errReadDir != nil { |
| 2927 | + t.Fatalf("read logs dir: %v", errReadDir) |
| 2928 | + } |
| 2929 | + var logPath string |
| 2930 | + for _, entry := range entries { |
| 2931 | + if strings.HasPrefix(entry.Name(), "v1-responses-") && strings.HasSuffix(entry.Name(), ".log") { |
| 2932 | + logPath = filepath.Join(logsDir, entry.Name()) |
| 2933 | + break |
| 2934 | + } |
| 2935 | + } |
| 2936 | + if logPath == "" { |
| 2937 | + t.Fatal("streaming request log was not created in logs dir") |
| 2938 | + } |
| 2939 | + content, errReadLog := os.ReadFile(logPath) |
| 2940 | + if errReadLog != nil { |
| 2941 | + t.Fatalf("read log file: %v", errReadLog) |
| 2942 | + } |
| 2943 | + logText := string(content) |
| 2944 | + apiRequestIdx := strings.Index(logText, "=== API REQUEST 1 ===") |
| 2945 | + if apiRequestIdx == -1 { |
| 2946 | + t.Fatalf("streaming log missing API REQUEST 1:\n%s", logText) |
| 2947 | + } |
| 2948 | + apiResponseIdx := strings.Index(logText, "=== API RESPONSE 1 ===") |
| 2949 | + if apiResponseIdx == -1 { |
| 2950 | + t.Fatalf("streaming log missing API RESPONSE 1:\n%s", logText) |
| 2951 | + } |
| 2952 | + downstreamResponseIdx := strings.Index(logText, "=== RESPONSE ===") |
| 2953 | + if downstreamResponseIdx == -1 { |
| 2954 | + t.Fatalf("streaming log missing downstream RESPONSE:\n%s", logText) |
| 2955 | + } |
| 2956 | + if apiRequestIdx >= apiResponseIdx || apiResponseIdx >= downstreamResponseIdx { |
| 2957 | + t.Fatalf("unexpected section order (req=%d, apiResp=%d, resp=%d):\n%s", apiRequestIdx, apiResponseIdx, downstreamResponseIdx, logText) |
| 2958 | + } |
| 2959 | + apiRequestSection := logText[apiRequestIdx:apiResponseIdx] |
| 2960 | + apiResponseSection := logText[apiResponseIdx:downstreamResponseIdx] |
| 2961 | + if !strings.Contains(apiRequestSection, mockUpstream.URL) { |
| 2962 | + t.Fatalf("API REQUEST section missing upstream URL %s:\n%s", mockUpstream.URL, apiRequestSection) |
| 2963 | + } |
| 2964 | + if !strings.Contains(apiRequestSection, `"gpt-5-codex"`) { |
| 2965 | + t.Fatalf("API REQUEST section missing request body:\n%s", apiRequestSection) |
| 2966 | + } |
| 2967 | + if !strings.Contains(apiResponseSection, "response.output_item.added") { |
| 2968 | + t.Fatalf("API RESPONSE section missing response chunk data:\n%s", apiResponseSection) |
| 2969 | + } |
| 2970 | +} |