toki/iop
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

fix(edge/openai): remove preview fields from production logs

Browse source 
Remove all *_preview zap.String/Any fields from OpenAI-compatible log
calls (chat_handler, responses_handler, stream) so that prompt, content,
reasoning, source, and delta values are never written in plain to
operational logs.

Replace preview fields with non-content metadata:
  - prompt_len, content_len, reasoning_len, delta_len, source_len
  - message_count, content_len, finish_reason, tool_call_count

Also remove the now-unused previewString helper from types.go.

Add log_safety_test.go with regression tests that:
  - verify no *_preview fields exist on any log line
  - verify operational metadata fields are retained for observability
  - verify logOpenAICompatStreamOutput does not emit delta_preview
This commit is contained in:
toki 2026-07-06 15:21:50 +09:00
parent 18b2880738
commit 2b3793149c
5 changed files with 284 additions and 17 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

2
apps/edge/internal/openai/chat_handler.go
View file

@ -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{

284
apps/edge/internal/openai/log_safety_test.go Normal file
View file

@ -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")
}
}
}

2
apps/edge/internal/openai/responses_handler.go
View file

@ -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

6
apps/edge/internal/openai/stream.go
View file

@ -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...)

7
apps/edge/internal/openai/types.go
View file

@ -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 {