| 1 | package session |
| 2 | |
| 3 | import ( |
| 4 | "context" |
| 5 | "crypto/sha256" |
| 6 | "encoding/json" |
| 7 | "errors" |
| 8 | "fmt" |
| 9 | "log/slog" |
| 10 | "os" |
| 11 | "path/filepath" |
| 12 | "strings" |
| 13 | "testing" |
| 14 | |
| 15 | "reasonix/internal/provider" |
| 16 | "reasonix/internal/transcript" |
| 17 | ) |
| 18 | |
| 19 | type unlockedRuntimeLogHandler struct { |
| 20 | slog.Handler |
| 21 | session *Session |
| 22 | t *testing.T |
| 23 | } |
| 24 | |
| 25 | func (h unlockedRuntimeLogHandler) Handle(ctx context.Context, record slog.Record) error { |
| 26 | if !h.session.mu.TryLock() { |
| 27 | h.t.Error("runtime diagnostic logged while holding the session lock") |
| 28 | } else { |
| 29 | h.session.mu.Unlock() |
| 30 | } |
| 31 | return h.Handler.Handle(ctx, record) |
| 32 | } |
| 33 | |
| 34 | func TestRuntimeFailureDiagnosticIsWrittenToLocalLog(t *testing.T) { |
| 35 | const secret = "PRIVATE-USER-DATA" |
| 36 | session := &Session{id: secret + "-session", next: 43} |
| 37 | for index := range 100 { |
| 38 | call := fmt.Sprintf("%s-%d", secret, index) |
| 39 | if index >= 98 { |
| 40 | call = secret + "-duplicate" |
| 41 | } |
| 42 | session.recentMessages = append(session.recentMessages, provider.Message{ |
| 43 | ID: fmt.Sprintf("%s-message-%d", secret, index), Role: provider.RoleTool, |
| 44 | ToolCallID: call, Content: secret, ReasoningContent: secret, |
| 45 | }) |
| 46 | } |
| 47 | path := filepath.Join(t.TempDir(), "service.log") |
| 48 | file, err := os.Create(path) |
| 49 | if err != nil { |
| 50 | t.Fatal(err) |
| 51 | } |
| 52 | t.Cleanup(func() { _ = file.Close() }) |
| 53 | previous := slog.Default() |
| 54 | slog.SetDefault(slog.New(unlockedRuntimeLogHandler{Handler: slog.NewJSONHandler(file, nil), session: session, t: t})) |
| 55 | t.Cleanup(func() { slog.SetDefault(previous) }) |
| 56 | ref := SessionRef{HostID: "local", SessionID: session.id} |
| 57 | for range 2 { |
| 58 | runtime, err := newRuntime(ref, session) |
| 59 | var initialization *TranscriptInitializationError |
| 60 | var baseline *transcript.BaselineError |
| 61 | if runtime != nil || !errors.As(err, &initialization) || !errors.As(err, &baseline) { |
| 62 | t.Fatalf("lost typed cause: runtime = %v, error = %v", runtime, err) |
| 63 | } |
| 64 | if initialization.Classification() != "duplicate_record_identity" { |
| 65 | t.Fatalf("online classification = %q", initialization.Classification()) |
| 66 | } |
| 67 | } |
| 68 | body, err := os.ReadFile(path) |
| 69 | if err != nil { |
| 70 | t.Fatal(err) |
| 71 | } |
| 72 | if strings.Contains(string(body), secret) || len(body) > 4000 { |
| 73 | t.Fatal("local log contains private data or unbounded diagnostics") |
| 74 | } |
| 75 | lines := strings.Split(strings.TrimSpace(string(body)), "\n") |
| 76 | if len(lines) != 2 { |
| 77 | t.Fatalf("expected one diagnostic per failed attempt, got %d", len(lines)) |
| 78 | } |
| 79 | for _, line := range lines { |
| 80 | var entry struct { |
| 81 | Message string `json:"msg"` |
| 82 | Diagnostic map[string]any `json:"diagnostic"` |
| 83 | } |
| 84 | if err := json.Unmarshal([]byte(line), &entry); err != nil { |
| 85 | t.Fatal(err) |
| 86 | } |
| 87 | diagnostic := entry.Diagnostic |
| 88 | if entry.Message != "session transcript initialization failed" || diagnostic["session_key"] != fmt.Sprintf("%x", sha256.Sum256([]byte(session.id))) || |
| 89 | diagnostic["covered_sequence"] != float64(42) || diagnostic["baseline_message_count"] != float64(96) || diagnostic["baseline_total_message_count"] != float64(100) { |
| 90 | t.Fatalf("incomplete local diagnostic: %+v", entry) |
| 91 | } |
| 92 | baseline, ok := diagnostic["baseline"].(map[string]any) |
| 93 | if !ok || baseline["code"] != "duplicate_record_identity" || baseline["record_index"] != float64(95) || baseline["previous_record_index"] != float64(94) { |
| 94 | t.Fatalf("lost bounded-tail conflict details: %+v", baseline) |
| 95 | } |
| 96 | } |
| 97 | } |
| 98 |