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