Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions plugins/logging/changelog.md
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
[fix]: sanitize ErrorDetailsParsed so raw payloads honor disable_content_logging [@citrocat](https://github.com/citrocat)
61 changes: 38 additions & 23 deletions plugins/logging/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -108,6 +108,38 @@ func applyLargePayloadPreviewsToEntry(ctx *schemas.BifrostContext, entry *logsto
}
}

// applyErrorDetailsToEntry stores the sanitized error on the entry. Both the
// serialized string and the parsed struct must hold the sanitized copy:
// logstore's SerializeFields re-serializes ErrorDetailsParsed on write (it
// takes precedence over ErrorDetails), so an unsanitized parsed struct would
// leak raw request/response payloads to the store even when content logging
// is disabled. Serialization happens immediately since bifrostErr may be
// released back to the pool before the async batch writer processes the entry.
func applyErrorDetailsToEntry(entry *logstore.Log, bifrostErr *schemas.BifrostError, contentLoggingEnabled, shouldStoreRaw bool) {
if bifrostErr == nil {
return
}
sanitizedErr := sanitizeErrorForLogging(bifrostErr, contentLoggingEnabled, shouldStoreRaw)
if data, err := sonic.Marshal(sanitizedErr); err == nil {
entry.ErrorDetails = string(data)
}
entry.ErrorDetailsParsed = sanitizedErr
}

// applyErrorDetailsToMCPEntry is the MCPToolLog counterpart of
// applyErrorDetailsToEntry: same sanitize-once, serialize-immediately,
// store-sanitized-copy-in-both-fields semantics.
func applyErrorDetailsToMCPEntry(entry *logstore.MCPToolLog, bifrostErr *schemas.BifrostError, contentLoggingEnabled, shouldStoreRaw bool) {
if bifrostErr == nil {
return
}
sanitizedErr := sanitizeErrorForLogging(bifrostErr, contentLoggingEnabled, shouldStoreRaw)
if data, err := sonic.Marshal(sanitizedErr); err == nil {
entry.ErrorDetails = string(data)
}
entry.ErrorDetailsParsed = sanitizedErr
}

// sanitizeErrorForLogging returns a shallow copy of err with ExtraFields.RawRequest and
// RawResponse cleared when raw-byte persistence is disabled, preventing raw bytes from
// leaking into entry.ErrorDetails via JSON serialization.
Expand Down Expand Up @@ -921,10 +953,7 @@ func (p *LoggerPlugin) PostLLMHook(ctx *schemas.BifrostContext, result *schemas.
}
applyModelAlias(entry, originalModelRequested, resolvedModelUsed)
applyResolvedAliasInfo(entry, resolvedKeyAlias)
if data, err := sonic.Marshal(sanitizeErrorForLogging(bifrostErr, contentLoggingEnabled, shouldStoreRaw)); err == nil {
entry.ErrorDetails = string(data)
}
entry.ErrorDetailsParsed = bifrostErr
applyErrorDetailsToEntry(entry, bifrostErr, contentLoggingEnabled, shouldStoreRaw)
if nodeID, _ := p.clusterNodeID.Load().(string); nodeID != "" {
entry.ClusterNodeID = &nodeID
}
Expand Down Expand Up @@ -1058,13 +1087,7 @@ func (p *LoggerPlugin) PostLLMHook(ctx *schemas.BifrostContext, result *schemas.
tracer.CleanupStreamAccumulator(traceID)
}

// Serialize error details immediately since bifrostErr may be released
// back to the pool before the async batch writer processes this entry.
// Also set ErrorDetailsParsed for UI callback (JSON serialization uses this field).
if data, err := sonic.Marshal(sanitizeErrorForLogging(bifrostErr, contentLoggingEnabled, shouldStoreRaw)); err == nil {
entry.ErrorDetails = string(data)
}
entry.ErrorDetailsParsed = bifrostErr
applyErrorDetailsToEntry(entry, bifrostErr, contentLoggingEnabled, shouldStoreRaw)
if shouldStoreRaw && contentLoggingEnabled {
if bifrostErr.ExtraFields.RawRequest != nil {
rawReqBytes, err := sonic.Marshal(bifrostErr.ExtraFields.RawRequest)
Expand Down Expand Up @@ -1105,10 +1128,7 @@ func (p *LoggerPlugin) PostLLMHook(ctx *schemas.BifrostContext, result *schemas.
entry.Status = logStatusForError(bifrostErr)
entry.Stream = true
applyModelAlias(entry, originalModelRequested, resolvedModelUsed)
if data, err := sonic.Marshal(sanitizeErrorForLogging(bifrostErr, contentLoggingEnabled, shouldStoreRaw)); err == nil {
entry.ErrorDetails = string(data)
}
entry.ErrorDetailsParsed = bifrostErr
applyErrorDetailsToEntry(entry, bifrostErr, contentLoggingEnabled, shouldStoreRaw)
// Backfill raw request/response on streaming-error path so cancellation/timeout
// log entries still carry raw payloads when content logging + raw storage are
// enabled. Mirrors the non-streaming Path A pattern at line 872. Prefer the
Expand Down Expand Up @@ -1187,13 +1207,7 @@ func (p *LoggerPlugin) PostLLMHook(ctx *schemas.BifrostContext, result *schemas.
if bifrostErr != nil {
entry.Status = logStatusForError(bifrostErr)
applyModelAlias(entry, originalModelRequested, resolvedModelUsed)
// Serialize error details immediately since bifrostErr may be released
// back to the pool before the async batch writer processes this entry.
// Also set ErrorDetailsParsed for UI callback (JSON serialization uses this field).
if data, err := sonic.Marshal(sanitizeErrorForLogging(bifrostErr, contentLoggingEnabled, shouldStoreRaw)); err == nil {
entry.ErrorDetails = string(data)
}
entry.ErrorDetailsParsed = bifrostErr
applyErrorDetailsToEntry(entry, bifrostErr, contentLoggingEnabled, shouldStoreRaw)
// Realtime turns that fail mid-stream still need their input transcript
// surfaced — backfill from bifrostErr.ExtraFields.RawRequest if present.
if requestType == schemas.RealtimeRequest {
Expand Down Expand Up @@ -1597,7 +1611,8 @@ func (p *LoggerPlugin) PostMCPHook(ctx *schemas.BifrostContext, resp *schemas.Bi

if bifrostErr != nil {
entry.Status = "error"
entry.ErrorDetailsParsed = bifrostErr
shouldStoreRaw, _ := ctx.Value(schemas.BifrostContextKeyShouldStoreRawInLogs).(bool)
applyErrorDetailsToMCPEntry(entry, bifrostErr, p.contentLoggingEnabled(ctx), shouldStoreRaw)
} else if resp != nil {
entry.Status = "success"
if p.contentLoggingEnabled(ctx) {
Expand Down
9 changes: 4 additions & 5 deletions plugins/logging/operations.go
Original file line number Diff line number Diff line change
Expand Up @@ -386,11 +386,10 @@ func (p *LoggerPlugin) applyStreamingOutputToEntry(entry *logstore.Log, streamRe
// Handle error case first
if streamResponse.Data.ErrorDetails != nil {
entry.Status = logStatusForError(streamResponse.Data.ErrorDetails)
entry.ErrorDetailsParsed = streamResponse.Data.ErrorDetails
// Serialize error details immediately to avoid use-after-free with pooled errors
if data, err := sonic.Marshal(streamResponse.Data.ErrorDetails); err == nil {
entry.ErrorDetails = string(data)
}
// Serializes immediately to avoid use-after-free with pooled errors, and
// stores the sanitized copy in both fields (SerializeFields re-serializes
// ErrorDetailsParsed on write, so it must not hold raw payloads).
applyErrorDetailsToEntry(entry, streamResponse.Data.ErrorDetails, contentLoggingEnabled, shouldStoreRaw)
latF := float64(streamResponse.Data.Latency)
entry.Latency = &latF
} else {
Expand Down
108 changes: 108 additions & 0 deletions plugins/logging/sanitize_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,108 @@
package logging

import (
"strings"
"testing"

"github.com/maximhq/bifrost/core/schemas"
"github.com/maximhq/bifrost/framework/logstore"
)

func errorWithRawPayloads() *schemas.BifrostError {
return &schemas.BifrostError{
IsBifrostError: false,
Error: &schemas.ErrorField{Message: "provider rejected request"},
ExtraFields: schemas.BifrostErrorExtraFields{
RawRequest: map[string]any{"messages": "RAW_REQUEST_MARKER"},
RawResponse: map[string]any{"body": "RAW_RESPONSE_MARKER"},
},
}
}

// Regression test: logstore's SerializeFields re-serializes ErrorDetailsParsed
// on write, overwriting ErrorDetails. If the parsed field holds the
// unsanitized error, raw request/response payloads reach the store even when
// content logging is disabled.
func TestApplyErrorDetailsToEntry_SanitizedSurvivesSerializeFields(t *testing.T) {
entry := &logstore.Log{ID: "req-1"}
applyErrorDetailsToEntry(entry, errorWithRawPayloads(), false, false)

if entry.ErrorDetailsParsed == nil {
t.Fatal("ErrorDetailsParsed should be set")
}
if entry.ErrorDetailsParsed.ExtraFields.RawRequest != nil ||
entry.ErrorDetailsParsed.ExtraFields.RawResponse != nil {
t.Error("ErrorDetailsParsed should not retain raw payloads when content logging is disabled")
}

// Simulate the DB write path (BeforeCreate calls SerializeFields).
if err := entry.SerializeFields(); err != nil {
t.Fatalf("SerializeFields() error: %v", err)
}
if strings.Contains(entry.ErrorDetails, "RAW_REQUEST_MARKER") ||
strings.Contains(entry.ErrorDetails, "RAW_RESPONSE_MARKER") {
t.Error("serialized ErrorDetails must not contain raw payloads when content logging is disabled")
}
if !strings.Contains(entry.ErrorDetails, "provider rejected request") {
t.Error("serialized ErrorDetails should still contain the error message")
}
}

// When content logging and raw storage are both enabled, raw payloads are
// intentionally preserved.
func TestApplyErrorDetailsToEntry_RawPreservedWhenEnabled(t *testing.T) {
entry := &logstore.Log{ID: "req-2"}
applyErrorDetailsToEntry(entry, errorWithRawPayloads(), true, true)

if entry.ErrorDetailsParsed == nil {
t.Fatal("ErrorDetailsParsed should be set")
}
if entry.ErrorDetailsParsed.ExtraFields.RawRequest == nil {
t.Error("raw payloads should be preserved when content logging and raw storage are enabled")
}
if err := entry.SerializeFields(); err != nil {
t.Fatalf("SerializeFields() error: %v", err)
}
if !strings.Contains(entry.ErrorDetails, "RAW_REQUEST_MARKER") {
t.Error("serialized ErrorDetails should contain raw payloads when explicitly enabled")
}
}

func TestApplyErrorDetailsToEntry_NilError(t *testing.T) {
entry := &logstore.Log{ID: "req-3"}
applyErrorDetailsToEntry(entry, nil, false, false)
if entry.ErrorDetailsParsed != nil {
t.Error("nil error should leave ErrorDetailsParsed nil")
}
if entry.ErrorDetails != "" {
t.Error("nil error should leave ErrorDetails empty")
}
}

// MCPToolLog counterpart: same sanitization semantics, and ErrorDetails is
// serialized immediately rather than deferred to the BeforeCreate hook.
func TestApplyErrorDetailsToMCPEntry_SanitizedAndSerializedImmediately(t *testing.T) {
entry := &logstore.MCPToolLog{ID: "mcp-1"}
applyErrorDetailsToMCPEntry(entry, errorWithRawPayloads(), false, false)

if entry.ErrorDetailsParsed == nil {
t.Fatal("ErrorDetailsParsed should be set")
}
if entry.ErrorDetailsParsed.ExtraFields.RawRequest != nil ||
entry.ErrorDetailsParsed.ExtraFields.RawResponse != nil {
t.Error("ErrorDetailsParsed should not retain raw payloads when content logging is disabled")
}
if entry.ErrorDetails == "" {
t.Error("ErrorDetails should be serialized immediately, not deferred to BeforeCreate")
}
if strings.Contains(entry.ErrorDetails, "RAW_REQUEST_MARKER") {
t.Error("serialized ErrorDetails must not contain raw payloads when content logging is disabled")
}

if err := entry.SerializeFields(); err != nil {
t.Fatalf("SerializeFields() error: %v", err)
}
if strings.Contains(entry.ErrorDetails, "RAW_REQUEST_MARKER") {
t.Error("serialized ErrorDetails must not contain raw payloads after SerializeFields")
}
}