87 lines
3.3 KiB
Go
87 lines
3.3 KiB
Go
package main
|
|
|
|
import (
|
|
"bytes"
|
|
"context"
|
|
"log/slog"
|
|
"strings"
|
|
"testing"
|
|
)
|
|
|
|
// debugLogger builds a JSON slog.Logger over buf wrapped in the contextHandler, at the
|
|
// given level — the same wrapping newLogger applies, so these tests exercise the real
|
|
// trace-injection path.
|
|
func debugLogger(buf *bytes.Buffer, level slog.Level) *slog.Logger {
|
|
h := slog.NewJSONHandler(buf, &slog.HandlerOptions{Level: level})
|
|
return slog.New(contextHandler{h})
|
|
}
|
|
|
|
// TestContextHandlerInjectsTraceID proves a record logged with a *Context method carries
|
|
// the request's trace_id, and that a record with no traced context carries none.
|
|
func TestContextHandlerInjectsTraceID(t *testing.T) {
|
|
var buf bytes.Buffer
|
|
log := debugLogger(&buf, slog.LevelInfo)
|
|
|
|
ctx := withRequestTrace(context.Background(), "trace-abc", "@u:vojo.chat", false)
|
|
log.InfoContext(ctx, "with trace")
|
|
if !strings.Contains(buf.String(), `"trace_id":"trace-abc"`) {
|
|
t.Fatalf("traced line missing trace_id: %s", buf.String())
|
|
}
|
|
|
|
buf.Reset()
|
|
log.InfoContext(context.Background(), "no trace")
|
|
if strings.Contains(buf.String(), "trace_id") {
|
|
t.Fatalf("untraced line should carry no trace_id: %s", buf.String())
|
|
}
|
|
}
|
|
|
|
// TestLogLLMExchangeGate proves bodies are logged ONLY for a verbose (allowlisted)
|
|
// sender, never otherwise — the per-user privacy gate.
|
|
func TestLogLLMExchangeGate(t *testing.T) {
|
|
req := []byte(`{"model":"grok","messages":[{"role":"user","content":"secret question"}]}`)
|
|
resp := []byte(`{"choices":[{"message":{"content":"secret answer"}}]}`)
|
|
|
|
// Not on the allowlist → nothing logged, even at debug level.
|
|
var off bytes.Buffer
|
|
logOff := debugLogger(&off, slog.LevelDebug)
|
|
ctxOff := withRequestTrace(context.Background(), "t1", "@stranger:vojo.chat", false)
|
|
logLLMExchange(ctxOff, logOff, "xai", req, 200, resp)
|
|
if off.Len() != 0 {
|
|
t.Fatalf("non-allowlisted sender must not log bodies, got: %s", off.String())
|
|
}
|
|
|
|
// On the allowlist → request + response bodies appear, tagged with the trace_id.
|
|
var on bytes.Buffer
|
|
logOn := debugLogger(&on, slog.LevelDebug)
|
|
ctxOn := withRequestTrace(context.Background(), "t2", "@heaven:vojo.chat", true)
|
|
logLLMExchange(ctxOn, logOn, "xai", req, 200, resp)
|
|
out := on.String()
|
|
for _, want := range []string{"llm exchange", "secret question", "secret answer", `"trace_id":"t2"`, `"sender":"@heaven:vojo.chat"`} {
|
|
if !strings.Contains(out, want) {
|
|
t.Fatalf("allowlisted body log missing %q: %s", want, out)
|
|
}
|
|
}
|
|
}
|
|
|
|
// TestLogLLMExchangeRequiresDebug proves that even an allowlisted sender logs nothing at
|
|
// info level — bodies need LOG_LEVEL=debug, the second half of the gate.
|
|
func TestLogLLMExchangeRequiresDebug(t *testing.T) {
|
|
var buf bytes.Buffer
|
|
log := debugLogger(&buf, slog.LevelInfo)
|
|
ctx := withRequestTrace(context.Background(), "t3", "@heaven:vojo.chat", true)
|
|
logLLMExchange(ctx, log, "xai", []byte("req"), 200, []byte("resp"))
|
|
if buf.Len() != 0 {
|
|
t.Fatalf("bodies must stay suppressed at info level, got: %s", buf.String())
|
|
}
|
|
}
|
|
|
|
// TestTruncateForLog bounds body size and marks truncation.
|
|
func TestTruncateForLog(t *testing.T) {
|
|
if got := truncateForLog([]byte("short"), 100); got != "short" {
|
|
t.Fatalf("under-cap should pass through, got %q", got)
|
|
}
|
|
got := truncateForLog([]byte("0123456789"), 4)
|
|
if got != "0123…(truncated)" {
|
|
t.Fatalf("over-cap truncation = %q", got)
|
|
}
|
|
}
|