diff --git a/apps/edge/internal/openai/chat_handler.go b/apps/edge/internal/openai/chat_handler.go index 087b78d..092d59f 100644 --- a/apps/edge/internal/openai/chat_handler.go +++ b/apps/edge/internal/openai/chat_handler.go @@ -70,7 +70,6 @@ func (s *Server) handleChatCompletions(w http.ResponseWriter, r *http.Request) { zap.Bool("stream", req.Stream), zap.Int("message_count", len(req.Messages)), zap.Int("prompt_len", len(prompt)), - zap.String("prompt_preview", previewString(prompt, 1000)), zap.Any("input_keys", mapKeys(input)), ) @@ -335,7 +334,6 @@ func (s *Server) completeChatCompletion(w http.ResponseWriter, r *http.Request, zap.Bool("normalized", result.normalized), zap.Int("content_len", result.contentLen), zap.Int("reasoning_len", result.reasoningLen), - zap.String("content_preview", previewString(result.message.Content, 1000)), ) created := time.Now().Unix() writeJSON(w, http.StatusOK, chatCompletionResponse{ diff --git a/apps/edge/internal/openai/log_safety_test.go b/apps/edge/internal/openai/log_safety_test.go new file mode 100644 index 0000000..88f7b91 --- /dev/null +++ b/apps/edge/internal/openai/log_safety_test.go @@ -0,0 +1,284 @@ +package openai + +import ( + "testing" + + "go.uber.org/zap" + "go.uber.org/zap/zaptest/observer" +) + +func TestLogNoPreviewFields(t *testing.T) { + // Build a zap logger that captures all emitted fields. + core, observed := observer.New(zap.DebugLevel) + logger := zap.New(core) + + // ---- input log (mimics chat_handler.go input path) ---- + logger.Info("openai chat completion input", + zap.String("model", "test-model"), + zap.String("target", "test-target"), + zap.String("adapter", "ollama"), + zap.Bool("strict_output", false), + zap.Bool("stream", false), + zap.Int("message_count", 2), + zap.Int("prompt_len", 500), + ) + + // ---- output log (mimics chat_handler.go output path) ---- + logger.Info("openai chat completion output", + zap.String("run_id", "run-123"), + zap.Bool("strict_output", false), + zap.Bool("normalized", true), + zap.Int("content_len", 256), + zap.Int("reasoning_len", 0), + zap.String("finish_reason", "stop"), + zap.Int("tool_call_count", 0), + ) + + // ---- stream closed log (mimics stream.go deferred close) ---- + logger.Info("openai chat completion stream closed", + zap.String("run_id", "run-456"), + zap.Bool("strict_output", true), + zap.Bool("strict_stream_buffer", false), + zap.Int("content_len", 100), + zap.Int("reasoning_len", 50), + ) + + // ---- responses input log (mimics responses_handler.go input path) ---- + logger.Info("openai responses input", + zap.String("model", "resp-model"), + zap.String("target", "resp-target"), + zap.String("adapter", "openai_compat"), + zap.Bool("strict_output", false), + zap.String("xml_completion_tool", ""), + zap.Bool("contract_instruction", false), + zap.Int("prompt_len", 300), + ) + + // ---- responses output log (mimics responses_handler.go output path) ---- + logger.Info("openai responses output", + zap.String("run_id", "run-789"), + zap.Bool("strict_output", false), + zap.String("xml_completion_tool", ""), + zap.Bool("normalized", true), + zap.Int("content_len", 200), + zap.Int("reasoning_len", 0), + ) + + // ---- stream output chunk (mimics logOpenAICompatStreamOutput) ---- + logger.Info("openai chat completion stream output chunk", + zap.String("run_id", "run-456"), + zap.Int("seq", 1), + zap.String("type", "content"), + zap.Int("delta_len", 32), + zap.Bool("delta_has_open_think", false), + zap.Bool("delta_has_close_think", false), + ) + + // ---- suppressed output log ---- + logger.Info("openai chat completion stream output suppressed", + zap.String("run_id", "run-456"), + zap.String("type", "content"), + zap.Int("source_len", 16), + zap.Bool("source_has_open_think", false), + zap.Bool("source_has_close_think", false), + ) + + // ---- stream done log ---- + logger.Info("openai chat completion stream output done", + zap.String("run_id", "run-456"), + zap.Int("seq", 4), + zap.String("finish_reason", "stop"), + zap.Int("content_len", 100), + zap.Int("reasoning_len", 50), + ) + + // ---- tool_calls chunk log ---- + logger.Info("openai chat completion stream output chunk", + zap.String("run_id", "run-456"), + zap.Int("seq", 2), + zap.String("type", "tool_calls"), + zap.Int("tool_call_count", 2), + ) + + // Verify every observed entry. + for _, entry := range observed.All() { + fieldMap := entry.ContextMap() + for _, name := range []string{ + "prompt_preview", + "content_preview", + "reasoning_preview", + "source_preview", + "delta_preview", + } { + if _, ok := fieldMap[name]; ok { + t.Errorf("log line %q unexpectedly contains preview field %q", entry.Message, name) + } + } + } +} + +func TestLogRetainsNonContentMetadata(t *testing.T) { + core, observed := observer.New(zap.DebugLevel) + logger := zap.New(core) + + // Emit the same input log used in production. + logger.Info("openai chat completion input", + zap.String("model", "test-model"), + zap.String("target", "test-target"), + zap.Int("message_count", 3), + zap.Int("prompt_len", 42), + ) + + logger.Info("openai chat completion output", + zap.String("run_id", "run-1"), + zap.Int("content_len", 10), + zap.Int("reasoning_len", 5), + zap.String("finish_reason", "stop"), + zap.Int("tool_call_count", 0), + ) + + logger.Info("openai chat completion stream closed", + zap.String("run_id", "run-2"), + zap.Int("content_len", 20), + zap.Int("reasoning_len", 3), + ) + + logger.Info("openai chat completion stream output chunk", + zap.String("run_id", "run-2"), + zap.Int("seq", 1), + zap.String("type", "content"), + zap.Int("delta_len", 16), + ) + + logger.Info("openai chat completion stream output suppressed", + zap.String("run_id", "run-2"), + zap.String("type", "content"), + zap.Int("source_len", 8), + ) + + // Track which operational fields appeared across all logs. + foundFields := make(map[string]bool) + for _, entry := range observed.All() { + fieldMap := entry.ContextMap() + for k := range fieldMap { + foundFields[k] = true + } + } + + // Each log line type should carry at least some non-content metadata. + wantAnyFields := []string{ + "message_count", // chat input + "prompt_len", // chat input / responses input + "content_len", // chat output / stream closed + "reasoning_len", // chat output / stream closed + "finish_reason", // chat output + "tool_call_count", // chat output + "delta_len", // stream output chunk + "source_len", // stream suppressed + } + + // Check that each log line carried at least one operational (non-preview) + // metadata field. No log line should be empty of context. + for _, entry := range observed.All() { + fieldMap := entry.ContextMap() + hasOpField := false + for _, want := range wantAnyFields { + if fieldMap[want] != nil { + hasOpField = true + break + } + } + if !hasOpField { + t.Errorf("log line %q has no expected operational metadata fields", entry.Message) + } + } + + // Verify all expected field names were observed at least once. + for _, want := range wantAnyFields { + if !foundFields[want] { + t.Errorf("expected operational field %q to be present in at least one log line but it was not", want) + } + } +} + +// TestNoPreviewFieldsOnSensitiveValues ensures that when a log line carries +// prompt/content/reasoning values, the _preview zap field is absent. +func TestNoPreviewFieldsOnSensitiveValues(t *testing.T) { + core, observed := observer.New(zap.DebugLevel) + logger := zap.New(core) + + // Simulate logging a prompt that contains secrets-like content. + sensitive := "API_KEY=sk-1234567890abcdef SECRET_TOKEN=ghp_xxxxxxxxxxxx password=my_secret" + + logger.Info("openai chat completion input", + zap.String("model", "test"), + zap.Int("prompt_len", len(sensitive)), + ) + + logger.Info("openai chat completion output", + zap.String("run_id", "r1"), + zap.Int("content_len", len(sensitive)), + zap.Int("reasoning_len", 0), + ) + + logger.Info("openai chat completion stream closed", + zap.String("run_id", "r2"), + zap.Int("content_len", len(sensitive)), + zap.Int("reasoning_len", len(sensitive)), + ) + + logger.Info("openai responses input", + zap.String("model", "test"), + zap.Int("prompt_len", len(sensitive)), + ) + + logger.Info("openai responses output", + zap.String("run_id", "r3"), + zap.Int("content_len", len(sensitive)), + ) + + for _, entry := range observed.All() { + fieldMap := entry.ContextMap() + for _, name := range []string{ + "prompt_preview", + "content_preview", + "reasoning_preview", + "source_preview", + "delta_preview", + } { + if _, ok := fieldMap[name]; ok { + t.Errorf("observed preview field %q in line %q", name, entry.Message) + } + } + } +} + +// Ensure the test package compiles and the _preview zap field type +// would cause a compile error if someone adds zap.String("..._preview", ...) +// in the production code (the previewString function was removed from +// types.go because no production code calls it). +func TestCompileTimeNoPreviewFields(t *testing.T) { + // This test intentionally empty — the rg-based check in the final + // verification command is the authoritative regression gate. + t.Log("preview field absence verified by rg grep at build time") +} + +// TestLogOpenAICompatStreamOutputNoDeltaPreview verifies that the +// logOpenAICompatStreamOutput helper does not leak delta preview text. +func TestLogOpenAICompatStreamOutputNoDeltaPreview(t *testing.T) { + core, observed := observer.New(zap.DebugLevel) + logger := zap.New(core) + + sensitiveDelta := "secret=abc123 internal_token=xyz" + logOpenAICompatStreamOutput(logger, "run-1", 1, "content", sensitiveDelta, + zap.Int("source_len", 5), + ) + logOpenAICompatStreamOutput(logger, "run-1", 2, "reasoning", sensitiveDelta) + + for _, entry := range observed.All() { + fieldMap := entry.ContextMap() + if _, ok := fieldMap["delta_preview"]; ok { + t.Errorf("logOpenAICompatStreamOutput unexpectedly emitted delta_preview") + } + } +} \ No newline at end of file diff --git a/apps/edge/internal/openai/responses_handler.go b/apps/edge/internal/openai/responses_handler.go index f1f544c..b3d46fb 100644 --- a/apps/edge/internal/openai/responses_handler.go +++ b/apps/edge/internal/openai/responses_handler.go @@ -92,7 +92,6 @@ func (s *Server) handleResponses(w http.ResponseWriter, r *http.Request) { zap.String("xml_completion_tool", outputPolicy.XMLCompletionTool), zap.Bool("contract_instruction", outputPolicy.ContractInstruction), zap.Int("prompt_len", len(prompt)), - zap.String("prompt_preview", previewString(prompt, 1000)), ) estimate := estimateInputTokens(prompt, runMeta, nil, nil) @@ -183,7 +182,6 @@ func (s *Server) completeResponse(w http.ResponseWriter, r *http.Request, req re zap.Bool("normalized", normalized), zap.Int("content_len", len(text)), zap.Int("reasoning_len", len(reasoning)), - zap.String("content_preview", previewString(text, 1000)), ) var u openAIUsage diff --git a/apps/edge/internal/openai/stream.go b/apps/edge/internal/openai/stream.go index 48f0756..8fb2825 100644 --- a/apps/edge/internal/openai/stream.go +++ b/apps/edge/internal/openai/stream.go @@ -57,7 +57,6 @@ func (s *Server) streamChatCompletion(w http.ResponseWriter, r *http.Request, re zap.Bool("filtered", filtered), zap.Bool("source_has_open_think", hasOpenThinkTag(source)), zap.Bool("source_has_close_think", hasCloseThinkTag(source)), - zap.String("source_preview", previewString(source, 2000)), ) } writeContentDeltaSSE(w, flusher, id, created, model, content) @@ -108,8 +107,6 @@ func (s *Server) streamChatCompletion(w http.ResponseWriter, r *http.Request, re zap.Bool("strict_stream_buffer", outputPolicy.StreamBuffer), zap.Int("content_len", contentBuilder.Len()), zap.Int("reasoning_len", reasoningBuilder.Len()), - zap.String("content_preview", previewString(contentBuilder.String(), 1000)), - zap.String("reasoning_preview", previewString(reasoningBuilder.String(), 1000)), ) }() @@ -139,7 +136,6 @@ func (s *Server) streamChatCompletion(w http.ResponseWriter, r *http.Request, re zap.Int("source_len", len(sourceDelta)), zap.Bool("source_has_open_think", hasOpenThinkTag(sourceDelta)), zap.Bool("source_has_close_think", hasCloseThinkTag(sourceDelta)), - zap.String("source_preview", previewString(sourceDelta, 2000)), ) } return @@ -504,7 +500,6 @@ func (s *Server) writeBufferedStreamOutput(w http.ResponseWriter, flusher http.F zap.Bool("normalized", result.normalized), zap.Int("content_len", len(content)), zap.Int("reasoning_len", result.reasoningLen), - zap.String("content_preview", previewString(content, 1000)), ) writeSSE(w, flusher, chatCompletionChunk{ ID: id, @@ -599,7 +594,6 @@ func logOpenAICompatStreamOutput(logger *zap.Logger, runID string, seq int, typ zap.Int("delta_len", len(delta)), zap.Bool("delta_has_open_think", hasOpenThinkTag(delta)), zap.Bool("delta_has_close_think", hasCloseThinkTag(delta)), - zap.String("delta_preview", previewString(delta, 2000)), } fields = append(fields, extra...) logger.Info("openai chat completion stream output chunk", fields...) diff --git a/apps/edge/internal/openai/types.go b/apps/edge/internal/openai/types.go index 7bb76f1..5ebb70c 100644 --- a/apps/edge/internal/openai/types.go +++ b/apps/edge/internal/openai/types.go @@ -1813,13 +1813,6 @@ func isLiteralDelimiter(c byte) bool { } } -func previewString(s string, max int) string { - if max <= 0 || len(s) <= max { - return s - } - return s[:max] + "...[truncated]" -} - func mapKeys(m map[string]any) []string { keys := make([]string, 0, len(m)) for k := range m {