manasight_parser/log/entry.rs
1//! Log entry prefix identification and multi-line JSON accumulation.
2//!
3//! Detects log entry boundaries using the `[UnityCrossThreadLogger]`,
4//! `[ConnectionManager]`, and `Matchmaking:` header patterns,
5//! then accumulates subsequent lines until the entry is structurally complete.
6//!
7//! # Header classification (Phase 1 of #153)
8//!
9//! Each detected header is classified as either single-line or multi-line:
10//!
11//! - **Single-line**: `[UnityCrossThreadLogger]` followed by anything other
12//! than a date digit (e.g., alpha labels like `STATE CHANGED`,
13//! `Client.SceneChange`, or `==>` API request markers),
14//! `[ConnectionManager]…`, and `Matchmaking:…`. These entries are
15//! flushed in the same [`LineBuffer::push_line`] call that received them
16//! — no continuation accumulation.
17//! - **Multi-line**: `[UnityCrossThreadLogger]<digit>` (date-prefixed API
18//! responses, match events). These entries accumulate continuation lines
19//! until the entry's JSON body is structurally complete (brace-balance
20//! flush) or the next header arrives (fallback for non-JSON bodies).
21//!
22//! # Brace-balance flush (Phase 3 of #153 / #193)
23//!
24//! Multi-line entries whose body contains a `{` are flushed the moment the
25//! brace depth returns to 0 — they no longer wait for the next header to
26//! arrive. A small state machine counts `{` and `}` while tracking string
27//! literals (`"`) and backslash escapes (`\\`), so braces appearing inside
28//! JSON string values do not count. Corpus analysis (44 sessions, 47,412
29//! multi-line entries) shows every entry that opens a `{` closes it within
30//! the entry boundary; bodies that never open a `{` (a few `true`-only REST
31//! responses and the [`EntryHeader::TruncationMarker`] entries whose
32//! follow-on `:: ... Count = N` lines carry no JSON braces) still flush on
33//! the next header via the original fallback path.
34//!
35//! This behavior is enabled by default via the `brace_depth_flush` cargo
36//! feature. Disabling the feature reverts to the original "flush on next
37//! header" behavior for every multi-line entry — kept as a one-flip rollback
38//! in case a string-literal edge case surfaces in live Arena traffic.
39//!
40//! # Data flow
41//!
42//! ```text
43//! File Tailer ──(raw lines)──▸ LineBuffer ──(complete entries)──▸ Router
44//! ```
45//!
46//! The [`LineBuffer`] receives individual lines from the file tailer. When a
47//! new log entry header is detected, it flushes the previously accumulated
48//! lines as a complete [`LogEntry`] and either emits the new entry
49//! immediately (single-line class) or begins accumulating it (multi-line
50//! class).
51
52use regex::Regex;
53
54use crate::util::truncate_for_log;
55
56/// Prefix of MTGA's GSM truncation marker line.
57///
58/// The full line in the log is
59/// `[Message summarized because one or more GameStateMessages exceeded the 50
60/// GameObject or 50 Annotation limit.]`. The shorter `"[Message summarized"`
61/// prefix is sufficient to detect the marker without coupling to the exact
62/// wording (Arena could vary punctuation or rephrase the suffix) and has zero
63/// false-positive matches in the corpus.
64const TRUNCATION_MARKER_PREFIX: &str = "[Message summarized";
65
66/// The known log entry header prefixes in MTG Arena's `Player.log`.
67#[derive(Debug, Clone, Copy, PartialEq, Eq)]
68#[non_exhaustive]
69pub enum EntryHeader {
70 /// `[UnityCrossThreadLogger]` — the most common header, used for
71 /// game state, client actions, match lifecycle, and most other events.
72 UnityCrossThreadLogger,
73 /// `[ConnectionManager]` — emitted for Arena's connection-lifecycle
74 /// diagnostics (e.g., `Reconnect result : ...`, `Reconnect succeeded`,
75 /// `Reconnect failed`). These lines are plain-text, single-line entries
76 /// in practice.
77 ConnectionManager,
78 /// `Matchmaking:` — a bare (non-bracketed) prefix Arena emits for
79 /// matchmaking-side connection markers such as
80 /// `Matchmaking: GRE connection lost`. These lines are plain-text,
81 /// single-line entries in practice.
82 Matchmaking,
83 /// Metadata lines that appear outside bracket-delimited entries.
84 ///
85 /// Currently covers `DETAILED LOGS: ENABLED` and `DETAILED LOGS: DISABLED`,
86 /// which Arena writes near the top of every session (typically line 24).
87 Metadata,
88 /// `[Message summarized because one or more GameStateMessages exceeded the
89 /// 50 GameObject or 50 Annotation limit.]` — Arena's truncation marker
90 /// emitted in place of an oversized `GameStateMessage` body. The marker
91 /// is followed by `::: GameStateMessage`, `:: GameObject Count = N`,
92 /// `:: Annotation Count = M`, and the next sibling message header. The
93 /// GSM body itself is irrecoverable from `Player.log`; this header
94 /// surfaces the signal so downstream consumers can detect a missed
95 /// `gsm_id` via the gap.
96 TruncationMarker,
97}
98
99impl EntryHeader {
100 /// Returns the header string as it appears in the log.
101 ///
102 /// Bracket-delimited headers return the full `[...]` prefix.
103 /// `Metadata` returns `"METADATA"` as a synthetic label (metadata
104 /// lines have no bracket prefix in the actual log).
105 pub fn as_str(self) -> &'static str {
106 match self {
107 Self::UnityCrossThreadLogger => "[UnityCrossThreadLogger]",
108 Self::ConnectionManager => "[ConnectionManager]",
109 Self::Matchmaking => "Matchmaking:",
110 Self::Metadata => "METADATA",
111 Self::TruncationMarker => "[Message summarized]",
112 }
113 }
114}
115
116impl std::fmt::Display for EntryHeader {
117 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
118 f.write_str(self.as_str())
119 }
120}
121
122/// A complete log entry extracted from the line buffer.
123///
124/// Contains the detected header prefix and the full raw text of the entry
125/// (header line plus any continuation lines for multi-line payloads).
126#[derive(Debug, Clone, PartialEq, Eq)]
127pub struct LogEntry {
128 /// Which header prefix introduced this entry.
129 pub header: EntryHeader,
130 /// The full raw text of the entry, including the header line and all
131 /// continuation lines. Lines are joined with `'\n'`.
132 pub body: String,
133}
134
135/// Internal classification of a header line for flush-timing decisions.
136///
137/// See module-level docs for the full classification rule.
138#[derive(Debug, Clone, Copy, PartialEq, Eq)]
139enum HeaderClass {
140 /// The entry is self-contained — flush immediately.
141 SingleLine,
142 /// The entry may span multiple lines — accumulate until the next header.
143 MultiLine,
144}
145
146/// Accumulates raw lines and produces complete [`LogEntry`] values when an
147/// entry is structurally complete.
148///
149/// # Usage
150///
151/// Feed lines one at a time via [`push_line`](Self::push_line). Each call
152/// returns a `Vec<LogEntry>` containing zero, one, or two complete entries:
153///
154/// - **Zero entries**: continuation line for an in-progress multi-line entry,
155/// or a headerless line discarded with a warning.
156/// - **One entry**: a single-line entry emitted on arrival, a multi-line
157/// entry being brace-balance-flushed (default feature behavior), or a
158/// multi-line entry being flushed by the arrival of the next header.
159/// - **Two entries**: a multi-line entry being flushed by a new header
160/// *plus* the new single-line entry that triggered the flush, both
161/// emitted from one call.
162///
163/// After the input stream ends (EOF or file rotation), call
164/// [`flush`](Self::flush) to retrieve any remaining buffered entry.
165///
166/// # Flush triggers
167///
168/// With the default `brace_depth_flush` feature enabled, a multi-line
169/// entry flushes the moment its body's JSON depth returns to 0 — no need
170/// to wait for the next header. Bodies that never contain a `{` (rare
171/// non-JSON GRE markers and `true`-bodied REST responses) still fall back
172/// to the original "flush on next header" path. See the module-level docs
173/// for the corpus analysis backing this design.
174///
175/// # Example
176///
177/// ```
178/// use manasight_parser::log::entry::LineBuffer;
179///
180/// let mut buf = LineBuffer::new();
181///
182/// // First header (multi-line, date-prefixed) — nothing to flush yet.
183/// assert!(buf.push_line("[UnityCrossThreadLogger]1/1/2025 12:00:00 PM").is_empty());
184///
185/// // Continuation line opens a `{` — still accumulating until the body
186/// // brace-balances (or, with the feature disabled, until the next header).
187/// assert!(buf.push_line(r#"{"key": "ba"#).is_empty());
188///
189/// // The body's brace depth returns to 0 — entry flushes immediately
190/// // (default feature on); the next header is not required.
191/// let entries = buf.push_line(r#" r"}"#);
192/// # #[cfg(feature = "brace_depth_flush")]
193/// assert_eq!(entries.len(), 1);
194/// ```
195pub struct LineBuffer {
196 /// Compiled regex for detecting log entry header boundaries.
197 header_re: Regex,
198 /// Header of the entry currently being accumulated, if any.
199 ///
200 /// Only ever populated for multi-line entries. Single-line entries are
201 /// emitted immediately and never set this field — leaving the buffer in
202 /// an idle state after every single-line flush.
203 current_header: Option<EntryHeader>,
204 /// Lines accumulated for the current entry.
205 lines: Vec<String>,
206 /// Whether this buffer has ever emitted (or begun accumulating) an entry.
207 ///
208 /// Armed by [`push_line`](Self::push_line) when a real header is detected
209 /// or a metadata line is emitted. Cleared back to `false` by
210 /// [`reset`](Self::reset) so post-rotation orphan lines still surface a
211 /// warning. Used to silence the routine post-flush "orphan discarded"
212 /// warning (Phase 2 of #153 / #161): once any entry has been seen, an
213 /// arriving headerless line is Unity stdout noise rather than a true
214 /// file-start anomaly.
215 has_emitted_anything: bool,
216
217 /// Brace-balance state machine used to detect structurally complete
218 /// JSON bodies inside multi-line entries. See [`BraceState`].
219 #[cfg(feature = "brace_depth_flush")]
220 brace_state: BraceState,
221}
222
223/// In-entry brace-depth and string-literal state for the brace-balance
224/// flush trigger. See [`LineBuffer::advance_brace_state`].
225///
226/// Grouped into its own struct so [`LineBuffer`] does not exceed clippy's
227/// pedantic `struct_excessive_bools` threshold once all four fields are
228/// added — and to make the "reset to defaults on take/reset/new" pattern
229/// a single field swap rather than four parallel writes.
230#[cfg(feature = "brace_depth_flush")]
231#[derive(Default)]
232struct BraceState {
233 /// Running brace depth for the current entry's body. Zero when no `{`
234 /// has been seen yet in this entry. Combined with [`Self::ever_opened`],
235 /// returning to 0 signals a structurally complete JSON body.
236 depth: u32,
237 /// Whether the character cursor is currently inside a JSON string literal.
238 /// Toggled by an unescaped `"`; braces inside a string literal are
239 /// ignored so structurally-complete JSON bodies cannot be falsely
240 /// signaled by `{`/`}` characters embedded in string values.
241 in_string: bool,
242 /// Whether the next character should be treated as escaped — i.e., the
243 /// previous character was a backslash inside a string literal.
244 escape_pending: bool,
245 /// True once any `{` has been observed in the current entry's body.
246 /// Combined with `depth == 0`, signals a complete JSON body and triggers
247 /// an immediate flush. Entries that never open a `{` keep this false
248 /// and fall through to the next-header flush path.
249 ever_opened: bool,
250}
251
252impl LineBuffer {
253 /// Creates a new, empty line buffer with the compiled header regex.
254 pub fn new() -> Self {
255 // The regex crate documents that `Regex::new` only fails on invalid
256 // patterns. This pattern is a compile-time constant and is valid, so
257 // the `Err` branch is unreachable in practice.
258 let header_re = match Regex::new(r"^\[(UnityCrossThreadLogger|ConnectionManager)\]") {
259 Ok(re) => re,
260 Err(e) => unreachable!("invalid header regex: {e}"),
261 };
262 Self {
263 header_re,
264 current_header: None,
265 lines: Vec::new(),
266 has_emitted_anything: false,
267 #[cfg(feature = "brace_depth_flush")]
268 brace_state: BraceState::default(),
269 }
270 }
271
272 /// Feeds a single line into the buffer.
273 ///
274 /// Returns a `Vec<LogEntry>` containing 0, 1, or 2 complete entries
275 /// — see the [type-level documentation](Self) for the full semantics.
276 ///
277 /// # Header classification
278 ///
279 /// When `line` matches a known header pattern, it is classified as either
280 /// single-line or multi-line (see module-level docs). Single-line
281 /// headers (`[UnityCrossThreadLogger]<non-digit>`, `[ConnectionManager]…`,
282 /// `Matchmaking:…`) flush any prior multi-line entry and emit the new
283 /// entry in the same call. Multi-line headers
284 /// (`[UnityCrossThreadLogger]<digit>`) flush any prior
285 /// entry and begin a fresh accumulation.
286 ///
287 /// Metadata lines (`DETAILED LOGS: ENABLED` / `DISABLED`) are
288 /// self-contained — treated as single-line entries that flush any prior
289 /// in-progress entry alongside themselves.
290 ///
291 /// Lines that arrive before any header has been seen are discarded with
292 /// a warning log — this handles partial entries at the start of a file
293 /// or after rotation.
294 ///
295 /// # Input contract
296 ///
297 /// Callers must strip any trailing `\r` (Windows CRLF) before invoking
298 /// this method. [`crate::log::tailer::FileTailer::poll`] already does
299 /// this; direct callers in tests must do the same to keep classification
300 /// well-defined.
301 pub fn push_line(&mut self, line: &str) -> Vec<LogEntry> {
302 // Check for metadata lines first — these are self-contained.
303 if Self::is_metadata_line(line) {
304 let mut out = Vec::new();
305 if let Some(prior) = self.take_entry() {
306 out.push(prior);
307 }
308 out.push(LogEntry {
309 header: EntryHeader::Metadata,
310 body: line.to_owned(),
311 });
312 // Metadata is a successfully emitted entry — subsequent orphan
313 // lines are routine post-flush noise, not a file-start anomaly.
314 self.has_emitted_anything = true;
315 return out;
316 }
317
318 if let Some(header) = self.detect_header(line) {
319 let class = Self::classify_header(header, line);
320 let mut out = Vec::new();
321 if let Some(prior) = self.take_entry() {
322 out.push(prior);
323 }
324 match class {
325 HeaderClass::SingleLine => {
326 // Emit the new entry immediately; leave the buffer idle
327 // so Phase 2 (#161) can distinguish post-flush orphans.
328 out.push(LogEntry {
329 header,
330 body: line.to_owned(),
331 });
332 }
333 HeaderClass::MultiLine => {
334 // Begin accumulating the new multi-line entry.
335 self.current_header = Some(header);
336 self.lines.push(line.to_owned());
337 }
338 }
339 // A real header was seen — arm the flag so subsequent orphans
340 // are silenced.
341 self.has_emitted_anything = true;
342 out
343 } else if self.current_header.is_some() {
344 // Continuation line for the current multi-line entry.
345 self.lines.push(line.to_owned());
346 #[cfg(feature = "brace_depth_flush")]
347 if self.advance_brace_state(line) {
348 // The body's JSON depth has returned to 0 with at least one
349 // `{` seen — the entry is structurally complete. Flush now
350 // rather than waiting for the next header to arrive.
351 if let Some(entry) = self.take_entry() {
352 return vec![entry];
353 }
354 }
355 Vec::new()
356 } else {
357 // Headerless line with no entry in progress. Two cases:
358 //
359 // 1. True file-start / post-rotation anomaly (no header has ever
360 // been seen): warn — this is what the message is meant to
361 // flag.
362 // 2. Routine post-flush orphan (Unity stdout noise arriving
363 // between Arena entries after Phase 1's single-line flush
364 // landed): silently discard — the warn would be pure noise.
365 if !self.has_emitted_anything {
366 ::log::warn!(
367 "Discarding headerless line at start of input: {:?}",
368 truncate_for_log(line, 120),
369 );
370 }
371 Vec::new()
372 }
373 }
374
375 /// Flushes any remaining buffered entry.
376 ///
377 /// Call this when the input stream ends (EOF or file rotation) to
378 /// retrieve the last accumulated multi-line entry, if any. Single-line
379 /// entries are never buffered — they are emitted by [`push_line`] in the
380 /// same call that received them — so this method only ever returns at
381 /// most one entry.
382 pub fn flush(&mut self) -> Option<LogEntry> {
383 self.take_entry()
384 }
385
386 /// Resets the buffer, discarding any in-progress entry.
387 ///
388 /// Useful on file rotation when the previous partial entry should be
389 /// abandoned. Also re-arms the orphan-warning flag so the first
390 /// post-rotation orphan still surfaces a warning (the rotation case
391 /// the warning was originally meant to detect).
392 pub fn reset(&mut self) {
393 self.current_header = None;
394 self.lines.clear();
395 self.has_emitted_anything = false;
396 #[cfg(feature = "brace_depth_flush")]
397 {
398 self.brace_state = BraceState::default();
399 }
400 }
401
402 /// Returns `true` if no entry is currently being accumulated.
403 pub fn is_empty(&self) -> bool {
404 self.current_header.is_none()
405 }
406
407 /// Returns `true` if the line is a metadata line that should be
408 /// treated as a self-contained entry.
409 ///
410 /// Currently matches `DETAILED LOGS: ENABLED` and
411 /// `DETAILED LOGS: DISABLED`.
412 fn is_metadata_line(line: &str) -> bool {
413 let trimmed = line.trim();
414 trimmed == "DETAILED LOGS: ENABLED" || trimmed == "DETAILED LOGS: DISABLED"
415 }
416
417 /// Detects whether `line` starts with a known header prefix.
418 ///
419 /// Bracketed headers (`[UnityCrossThreadLogger]`, `[ConnectionManager]`)
420 /// are matched via the compiled regex. The
421 /// bare `Matchmaking: ` prefix is matched via a separate
422 /// `starts_with` check because it has no brackets.
423 fn detect_header(&self, line: &str) -> Option<EntryHeader> {
424 if let Some(caps) = self.header_re.captures(line) {
425 let prefix = caps.get(1)?.as_str();
426 return match prefix {
427 "UnityCrossThreadLogger" => Some(EntryHeader::UnityCrossThreadLogger),
428 "ConnectionManager" => Some(EntryHeader::ConnectionManager),
429 _ => None,
430 };
431 }
432 if line.starts_with("Matchmaking: ") {
433 return Some(EntryHeader::Matchmaking);
434 }
435 if line.starts_with(TRUNCATION_MARKER_PREFIX) {
436 return Some(EntryHeader::TruncationMarker);
437 }
438 None
439 }
440
441 /// Classifies a header line as single-line or multi-line.
442 ///
443 /// Rule (corpus-verified across 27 sessions / 37,593 entries; see #153
444 /// analysis comment):
445 ///
446 /// - `[UnityCrossThreadLogger]` followed by an ASCII digit → multi-line
447 /// (date-prefixed API responses and match events).
448 /// - `[UnityCrossThreadLogger]` followed by anything else → single-line
449 /// (alpha labels and `==>` request markers).
450 /// - `[ConnectionManager]…` → single-line.
451 /// - `Matchmaking:…` → single-line.
452 fn classify_header(header: EntryHeader, line: &str) -> HeaderClass {
453 match header {
454 EntryHeader::UnityCrossThreadLogger => {
455 // Look at the first byte after the closing bracket.
456 let after = line
457 .strip_prefix("[UnityCrossThreadLogger]")
458 .unwrap_or(line);
459 if after.bytes().next().is_some_and(|b| b.is_ascii_digit()) {
460 HeaderClass::MultiLine
461 } else {
462 HeaderClass::SingleLine
463 }
464 }
465 // `TruncationMarker` is followed by 3 sub-header lines
466 // (`::: GameStateMessage`, `:: GameObject Count = N`,
467 // `:: Annotation Count = M`) that must accumulate into the entry
468 // body so the thin truncation parser can extract the counts.
469 // Its body never opens a `{`, so brace-balance flush doesn't
470 // fire — accumulation terminates when the next header arrives.
471 EntryHeader::TruncationMarker => HeaderClass::MultiLine,
472 // ConnectionManager and Matchmaking are corpus-confirmed
473 // single-line. Metadata (`DETAILED LOGS: …`) is handled directly
474 // in `push_line` and never reaches this function — but it must
475 // appear here because `EntryHeader` is non_exhaustive, and a
476 // single-line classification is the safe default.
477 EntryHeader::ConnectionManager | EntryHeader::Matchmaking | EntryHeader::Metadata => {
478 HeaderClass::SingleLine
479 }
480 }
481 }
482
483 /// Takes the current entry out of the buffer, leaving it empty.
484 fn take_entry(&mut self) -> Option<LogEntry> {
485 let header = self.current_header.take()?;
486 let body = self.lines.join("\n");
487 self.lines.clear();
488 #[cfg(feature = "brace_depth_flush")]
489 {
490 self.brace_state = BraceState::default();
491 }
492 Some(LogEntry { header, body })
493 }
494
495 /// Walks `line` one character at a time, updating the in-string /
496 /// escape / depth state used by the brace-balance flush trigger.
497 ///
498 /// Returns `true` when the entry's body is structurally complete — i.e.,
499 /// the running brace depth is 0 *and* at least one `{` has been observed
500 /// since the entry started accumulating. Returning `true` signals
501 /// [`push_line`](Self::push_line) to flush the entry immediately.
502 ///
503 /// The state machine treats `"` as a string-literal toggle (when not
504 /// preceded by an unescaped backslash) and `\\` as an escape marker for
505 /// the next character. Braces appearing inside string literals are
506 /// ignored. Corpus analysis (44 sessions, 47,412 multi-line entries)
507 /// shows this state machine balances correctly on every entry that
508 /// opens a `{`, including 585 with nested JSON-in-string values.
509 #[cfg(feature = "brace_depth_flush")]
510 fn advance_brace_state(&mut self, line: &str) -> bool {
511 let state = &mut self.brace_state;
512 for ch in line.chars() {
513 if state.escape_pending {
514 state.escape_pending = false;
515 continue;
516 }
517 if state.in_string {
518 match ch {
519 '\\' => state.escape_pending = true,
520 '"' => state.in_string = false,
521 _ => {}
522 }
523 continue;
524 }
525 match ch {
526 '"' => state.in_string = true,
527 '{' => {
528 state.depth = state.depth.saturating_add(1);
529 state.ever_opened = true;
530 }
531 '}' => {
532 if state.depth == 0 {
533 // Corpus has zero unbalanced cases — log an
534 // observability warning so any future drift surfaces
535 // rather than being silently floored at zero.
536 ::log::warn!(
537 "brace_depth underflow at unbalanced '}}' in entry body \
538 (line prefix: {:?})",
539 truncate_for_log(line, 120),
540 );
541 }
542 state.depth = state.depth.saturating_sub(1);
543 }
544 _ => {}
545 }
546 }
547 state.ever_opened && state.depth == 0
548 }
549}
550
551impl Default for LineBuffer {
552 fn default() -> Self {
553 Self::new()
554 }
555}
556
557// ---------------------------------------------------------------------------
558// Tests
559// ---------------------------------------------------------------------------
560
561#[cfg(test)]
562mod tests {
563 use super::*;
564
565 /// Helper: build an expected `LogEntry` for concise assertions.
566 fn expected(header: EntryHeader, body: &str) -> LogEntry {
567 LogEntry {
568 header,
569 body: body.to_owned(),
570 }
571 }
572
573 // -- EntryHeader --------------------------------------------------------
574
575 mod entry_header {
576 use super::*;
577
578 #[test]
579 fn test_as_str_unity() {
580 assert_eq!(
581 EntryHeader::UnityCrossThreadLogger.as_str(),
582 "[UnityCrossThreadLogger]"
583 );
584 }
585
586 #[test]
587 fn test_display_unity() {
588 assert_eq!(
589 EntryHeader::UnityCrossThreadLogger.to_string(),
590 "[UnityCrossThreadLogger]"
591 );
592 }
593
594 #[test]
595 fn test_clone_and_eq() {
596 let a = EntryHeader::UnityCrossThreadLogger;
597 let b = a;
598 assert_eq!(a, b);
599 }
600 }
601
602 // -- LineBuffer: basic operation ----------------------------------------
603
604 mod push_line {
605 use super::*;
606
607 #[test]
608 fn test_push_line_first_multi_line_header_returns_empty() {
609 let mut buf = LineBuffer::new();
610 // Date-prefixed UCTL = multi-line; nothing to flush yet.
611 assert!(buf
612 .push_line("[UnityCrossThreadLogger]1/1/2025 12:00:00 Event")
613 .is_empty());
614 }
615
616 #[test]
617 fn test_push_line_second_multi_line_header_flushes_first_entry() {
618 let mut buf = LineBuffer::new();
619 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event1");
620 assert_eq!(
621 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event2"),
622 vec![expected(
623 EntryHeader::UnityCrossThreadLogger,
624 "[UnityCrossThreadLogger]1/1/2025 Event1",
625 )],
626 );
627 }
628
629 #[test]
630 fn test_push_line_continuation_appended() {
631 // Body has no `{`/`}`, so brace-balance flush does not trigger
632 // — the entry accumulates until the next header arrives under
633 // both feature configurations.
634 let mut buf = LineBuffer::new();
635 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event1");
636 buf.push_line("plain text continuation one");
637 buf.push_line("plain text continuation two");
638 assert_eq!(
639 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event2"),
640 vec![expected(
641 EntryHeader::UnityCrossThreadLogger,
642 "[UnityCrossThreadLogger]1/1/2025 Event1\n\
643 plain text continuation one\n\
644 plain text continuation two",
645 )],
646 );
647 }
648
649 #[test]
650 fn test_push_line_alternating_multi_line_headers() {
651 let mut buf = LineBuffer::new();
652 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event1");
653
654 assert_eq!(
655 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event2"),
656 vec![expected(
657 EntryHeader::UnityCrossThreadLogger,
658 "[UnityCrossThreadLogger]1/1/2025 Event1",
659 )],
660 );
661
662 assert_eq!(
663 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event3"),
664 vec![expected(
665 EntryHeader::UnityCrossThreadLogger,
666 "[UnityCrossThreadLogger]1/1/2025 Event2",
667 )],
668 );
669
670 assert_eq!(
671 buf.flush(),
672 Some(expected(
673 EntryHeader::UnityCrossThreadLogger,
674 "[UnityCrossThreadLogger]1/1/2025 Event3",
675 )),
676 );
677 }
678 }
679
680 // -- LineBuffer: single-line flush (Phase 1 of #153) -------------------
681
682 mod single_line_flush {
683 use super::*;
684
685 /// `[UnityCrossThreadLogger]` followed by an alpha label (e.g.,
686 /// `STATE CHANGED`) is single-line — emit immediately, leave the
687 /// buffer idle.
688 #[test]
689 fn test_push_line_single_line_uctl_label_flushes_immediately() {
690 let mut buf = LineBuffer::new();
691 let entries = buf.push_line(
692 "[UnityCrossThreadLogger]STATE CHANGED \
693 {\"old\":\"None\",\"new\":\"ConnectedToMatchDoor\"}",
694 );
695 assert_eq!(
696 entries,
697 vec![expected(
698 EntryHeader::UnityCrossThreadLogger,
699 "[UnityCrossThreadLogger]STATE CHANGED \
700 {\"old\":\"None\",\"new\":\"ConnectedToMatchDoor\"}",
701 )],
702 );
703 assert!(
704 buf.is_empty(),
705 "buffer must be idle after a single-line flush",
706 );
707 }
708
709 /// `[UnityCrossThreadLogger]==>` API request markers are single-line.
710 #[test]
711 fn test_push_line_single_line_uctl_arrow_flushes_immediately() {
712 let mut buf = LineBuffer::new();
713 let entries = buf.push_line(
714 "[UnityCrossThreadLogger]==> GraphGetGraphState \
715 {\"id\":\"abc\",\"request\":\"{}\"}",
716 );
717 assert_eq!(entries.len(), 1);
718 assert_eq!(entries[0].header, EntryHeader::UnityCrossThreadLogger);
719 assert!(buf.is_empty());
720 }
721
722 /// `[UnityCrossThreadLogger]Client.SceneChange {…}` exercises a
723 /// nested-bracket case where the continuation-detection logic must
724 /// not be confused by the inner `{` body.
725 #[test]
726 fn test_push_line_single_line_uctl_nested_bracket_flushes_immediately() {
727 let mut buf = LineBuffer::new();
728 let entries = buf.push_line(
729 "[UnityCrossThreadLogger]Client.SceneChange \
730 {\"fromSceneName\":\"Home\",\"toSceneName\":\"Draft\"}",
731 );
732 assert_eq!(entries.len(), 1);
733 assert_eq!(entries[0].header, EntryHeader::UnityCrossThreadLogger);
734 assert!(buf.is_empty());
735 }
736
737 /// `[ConnectionManager]…` is single-line.
738 #[test]
739 fn test_push_line_single_line_connection_manager_flushes_immediately() {
740 let mut buf = LineBuffer::new();
741 let entries = buf.push_line("[ConnectionManager] Reconnect succeeded");
742 assert_eq!(
743 entries,
744 vec![expected(
745 EntryHeader::ConnectionManager,
746 "[ConnectionManager] Reconnect succeeded",
747 )],
748 );
749 assert!(buf.is_empty());
750 }
751
752 /// `Matchmaking:…` is single-line.
753 #[test]
754 fn test_push_line_single_line_matchmaking_flushes_immediately() {
755 let mut buf = LineBuffer::new();
756 let entries = buf.push_line("Matchmaking: GRE connection lost");
757 assert_eq!(
758 entries,
759 vec![expected(
760 EntryHeader::Matchmaking,
761 "Matchmaking: GRE connection lost",
762 )],
763 );
764 assert!(buf.is_empty());
765 }
766
767 /// Multi-line headers (`[UnityCrossThreadLogger]<digit>`) accumulate
768 /// continuation lines and produce the same body under both feature
769 /// configurations. The only difference is *when* the entry is
770 /// emitted: with `brace_depth_flush` on, the closing `}` of
771 /// `{"Courses":[]}` flushes it; without the feature, the next
772 /// header flushes it alongside its own single-line emission.
773 #[test]
774 fn test_push_line_multi_line_date_header_accumulates() {
775 let expected_multi_body = "[UnityCrossThreadLogger]3/11/2026 6:08:24 PM\n\
776 <== EventGetCoursesV2(abc-123)\n\
777 {\"Courses\":[]}";
778 let expected_single_body = "[UnityCrossThreadLogger]Client.SceneChange {}";
779
780 let mut buf = LineBuffer::new();
781 assert!(buf
782 .push_line("[UnityCrossThreadLogger]3/11/2026 6:08:24 PM")
783 .is_empty());
784 assert!(buf.push_line("<== EventGetCoursesV2(abc-123)").is_empty());
785 let closing = buf.push_line(r#"{"Courses":[]}"#);
786
787 #[cfg(feature = "brace_depth_flush")]
788 {
789 // The closing `}` of `{"Courses":[]}` brace-balance flushes.
790 assert_eq!(
791 closing,
792 vec![expected(
793 EntryHeader::UnityCrossThreadLogger,
794 expected_multi_body
795 )],
796 );
797 // The next single-line header now stands alone.
798 let entries = buf.push_line("[UnityCrossThreadLogger]Client.SceneChange {}");
799 assert_eq!(entries.len(), 1);
800 assert_eq!(entries[0].header, EntryHeader::UnityCrossThreadLogger);
801 assert_eq!(entries[0].body, expected_single_body);
802 }
803 #[cfg(not(feature = "brace_depth_flush"))]
804 {
805 assert!(closing.is_empty());
806 let entries = buf.push_line("[UnityCrossThreadLogger]Client.SceneChange {}");
807 assert_eq!(entries.len(), 2);
808 assert_eq!(entries[0].header, EntryHeader::UnityCrossThreadLogger);
809 assert_eq!(entries[0].body, expected_multi_body);
810 assert_eq!(entries[1].header, EntryHeader::UnityCrossThreadLogger);
811 assert_eq!(entries[1].body, expected_single_body);
812 }
813 }
814
815 /// Unity stdout noise that arrives *after* a single-line flush is
816 /// orphaned (the buffer is idle) and discarded — it must not be
817 /// absorbed into the prior entry's body.
818 #[test]
819 fn test_push_line_post_single_line_orphan_discarded() {
820 let mut buf = LineBuffer::new();
821 // Single-line header — buffer goes idle immediately after.
822 let first = buf.push_line("[UnityCrossThreadLogger]STATE CHANGED {\"x\":1}");
823 assert_eq!(first.len(), 1);
824 assert!(buf.is_empty());
825
826 // Unity stdout noise → orphan, discarded.
827 let noise = buf.push_line("PreviousPlayBladeVisualState is being set ...");
828 assert!(noise.is_empty());
829 assert!(buf.is_empty());
830
831 // Next header — emit cleanly with no contamination from the noise.
832 let next = buf.push_line("[UnityCrossThreadLogger]Connecting to matchId abc");
833 assert_eq!(next.len(), 1);
834 assert!(!next[0].body.contains("PreviousPlayBladeVisualState"));
835 }
836
837 /// A multi-line entry being flushed by a single-line header must
838 /// emit BOTH entries from one `push_line` call.
839 #[test]
840 fn test_push_line_multi_line_then_single_line_emits_two() {
841 let mut buf = LineBuffer::new();
842 buf.push_line("[UnityCrossThreadLogger]3/11/2026 6:08:24 PM");
843 buf.push_line("<== Foo(123)");
844
845 let entries = buf.push_line("[ConnectionManager] Reconnect failed");
846 assert_eq!(entries.len(), 2);
847 assert_eq!(entries[0].header, EntryHeader::UnityCrossThreadLogger);
848 assert!(entries[0].body.contains("<== Foo(123)"));
849 assert_eq!(entries[1].header, EntryHeader::ConnectionManager);
850 assert_eq!(entries[1].body, "[ConnectionManager] Reconnect failed");
851 assert!(buf.is_empty());
852 }
853 }
854
855 // -- LineBuffer: headerless lines ---------------------------------------
856
857 mod headerless {
858 use super::*;
859
860 #[test]
861 fn test_push_line_headerless_before_first_header_returns_empty() {
862 let mut buf = LineBuffer::new();
863 assert!(buf.push_line("some random line").is_empty());
864 assert!(buf.push_line("another orphan").is_empty());
865 // After discarding, the next header should still work.
866 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Real entry");
867 assert_eq!(
868 buf.flush(),
869 Some(expected(
870 EntryHeader::UnityCrossThreadLogger,
871 "[UnityCrossThreadLogger]1/1/2025 Real entry",
872 )),
873 );
874 }
875
876 #[test]
877 fn test_push_line_empty_line_as_continuation() {
878 let mut buf = LineBuffer::new();
879 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event");
880 buf.push_line("");
881 buf.push_line("continuation");
882 assert_eq!(
883 buf.flush(),
884 Some(expected(
885 EntryHeader::UnityCrossThreadLogger,
886 "[UnityCrossThreadLogger]1/1/2025 Event\n\ncontinuation",
887 )),
888 );
889 }
890 }
891
892 // -- LineBuffer: flush --------------------------------------------------
893
894 mod flush {
895 use super::*;
896
897 #[test]
898 fn test_flush_empty_buffer_returns_none() {
899 let mut buf = LineBuffer::new();
900 assert!(buf.flush().is_none());
901 }
902
903 #[test]
904 fn test_flush_returns_buffered_multi_line_entry() {
905 let mut buf = LineBuffer::new();
906 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event");
907 assert_eq!(
908 buf.flush(),
909 Some(expected(
910 EntryHeader::UnityCrossThreadLogger,
911 "[UnityCrossThreadLogger]1/1/2025 Event",
912 )),
913 );
914 }
915
916 #[test]
917 fn test_flush_clears_buffer() {
918 let mut buf = LineBuffer::new();
919 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event");
920 buf.flush();
921 assert!(buf.flush().is_none());
922 assert!(buf.is_empty());
923 }
924
925 #[test]
926 fn test_flush_multi_line_entry() {
927 let expected_body = [
928 "[UnityCrossThreadLogger]1/1/2025 GreToClientEvent",
929 "{",
930 r#" "gameObjects": ["obj1", "obj2"],"#,
931 r#" "actions": []"#,
932 "}",
933 ]
934 .join("\n");
935
936 let mut buf = LineBuffer::new();
937 buf.push_line("[UnityCrossThreadLogger]1/1/2025 GreToClientEvent");
938 buf.push_line("{");
939 buf.push_line(r#" "gameObjects": ["obj1", "obj2"],"#);
940 buf.push_line(r#" "actions": []"#);
941 let closing = buf.push_line("}");
942
943 #[cfg(feature = "brace_depth_flush")]
944 {
945 // The closing `}` brace-balance flushes the entry; `flush()`
946 // is left with nothing to return.
947 assert_eq!(
948 closing,
949 vec![expected(
950 EntryHeader::UnityCrossThreadLogger,
951 &expected_body
952 )],
953 );
954 assert!(buf.flush().is_none());
955 }
956 #[cfg(not(feature = "brace_depth_flush"))]
957 {
958 assert!(closing.is_empty());
959 assert_eq!(
960 buf.flush(),
961 Some(expected(
962 EntryHeader::UnityCrossThreadLogger,
963 &expected_body
964 )),
965 );
966 }
967 }
968 }
969
970 // -- LineBuffer: reset --------------------------------------------------
971
972 mod reset {
973 use super::*;
974
975 #[test]
976 fn test_reset_clears_in_progress_entry() {
977 let mut buf = LineBuffer::new();
978 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event");
979 // Continuation with an open `{` so brace state is non-trivial
980 // when we reset — depth=1, ever_opened=true, in_string=true.
981 buf.push_line(r#"{"k": "unfinished"#);
982 buf.reset();
983 assert!(buf.is_empty());
984 assert!(buf.flush().is_none());
985
986 // Brace state must also clear so the next accumulation starts
987 // from a clean slate (otherwise stale `ever_opened` would
988 // spuriously flush the next entry).
989 #[cfg(feature = "brace_depth_flush")]
990 {
991 assert_eq!(buf.brace_state.depth, 0, "reset() must clear depth");
992 assert!(!buf.brace_state.in_string, "reset() must clear in_string");
993 assert!(
994 !buf.brace_state.escape_pending,
995 "reset() must clear escape_pending",
996 );
997 assert!(
998 !buf.brace_state.ever_opened,
999 "reset() must clear ever_opened",
1000 );
1001 }
1002 }
1003
1004 #[test]
1005 fn test_reset_allows_fresh_accumulation() {
1006 let mut buf = LineBuffer::new();
1007 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Old");
1008 buf.reset();
1009 buf.push_line("[UnityCrossThreadLogger]1/1/2025 New");
1010 assert_eq!(
1011 buf.flush(),
1012 Some(expected(
1013 EntryHeader::UnityCrossThreadLogger,
1014 "[UnityCrossThreadLogger]1/1/2025 New",
1015 )),
1016 );
1017 }
1018 }
1019
1020 // -- LineBuffer: is_empty -----------------------------------------------
1021
1022 mod is_empty {
1023 use super::*;
1024
1025 #[test]
1026 fn test_is_empty_on_new_buffer() {
1027 let buf = LineBuffer::new();
1028 assert!(buf.is_empty());
1029 }
1030
1031 #[test]
1032 fn test_is_empty_false_after_multi_line_header() {
1033 let mut buf = LineBuffer::new();
1034 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event");
1035 assert!(!buf.is_empty());
1036 }
1037
1038 /// Single-line entries leave the buffer idle — invariant relied on
1039 /// by Phase 2 (#161).
1040 #[test]
1041 fn test_is_empty_true_after_single_line_flush() {
1042 let mut buf = LineBuffer::new();
1043 buf.push_line("[UnityCrossThreadLogger]STATE CHANGED");
1044 assert!(buf.is_empty());
1045 }
1046
1047 #[test]
1048 fn test_is_empty_true_after_flush() {
1049 let mut buf = LineBuffer::new();
1050 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event");
1051 buf.flush();
1052 assert!(buf.is_empty());
1053 }
1054
1055 #[test]
1056 fn test_is_empty_true_after_headerless_lines() {
1057 let mut buf = LineBuffer::new();
1058 buf.push_line("orphan line");
1059 assert!(buf.is_empty());
1060 }
1061 }
1062
1063 // -- LineBuffer: default ------------------------------------------------
1064
1065 mod default_impl {
1066 use super::*;
1067
1068 #[test]
1069 fn test_default_creates_functional_buffer() {
1070 let mut buf = LineBuffer::default();
1071 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event");
1072 assert_eq!(
1073 buf.flush(),
1074 Some(expected(
1075 EntryHeader::UnityCrossThreadLogger,
1076 "[UnityCrossThreadLogger]1/1/2025 Event",
1077 )),
1078 );
1079 }
1080 }
1081
1082 // -- Header detection edge cases ----------------------------------------
1083
1084 mod header_detection {
1085 use super::*;
1086
1087 #[test]
1088 fn test_header_not_at_start_of_line_is_continuation() {
1089 let mut buf = LineBuffer::new();
1090 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event");
1091 // Header pattern in the middle of a line is NOT a boundary.
1092 buf.push_line("some text [UnityCrossThreadLogger] not a header");
1093 assert_eq!(
1094 buf.flush(),
1095 Some(expected(
1096 EntryHeader::UnityCrossThreadLogger,
1097 "[UnityCrossThreadLogger]1/1/2025 Event\n\
1098 some text [UnityCrossThreadLogger] not a header",
1099 )),
1100 );
1101 }
1102
1103 #[test]
1104 fn test_similar_but_wrong_header_is_continuation() {
1105 let mut buf = LineBuffer::new();
1106 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event");
1107 buf.push_line("[UnityMainThreadLogger] not a valid header");
1108 let result = buf.flush();
1109 assert!(result.is_some());
1110 if let Some(e) = result {
1111 assert!(e.body.contains("[UnityMainThreadLogger]"));
1112 }
1113 }
1114
1115 #[test]
1116 fn test_bracket_only_is_not_header() {
1117 let mut buf = LineBuffer::new();
1118 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event");
1119 buf.push_line("[]");
1120 assert_eq!(
1121 buf.flush(),
1122 Some(expected(
1123 EntryHeader::UnityCrossThreadLogger,
1124 "[UnityCrossThreadLogger]1/1/2025 Event\n[]",
1125 )),
1126 );
1127 }
1128
1129 #[test]
1130 fn test_header_with_nothing_after_bracket() {
1131 let mut buf = LineBuffer::new();
1132 // `[UnityCrossThreadLogger]` with no trailing content classifies
1133 // as single-line (no leading digit) — emit and go idle.
1134 let entries = buf.push_line("[UnityCrossThreadLogger]");
1135 assert_eq!(
1136 entries,
1137 vec![expected(
1138 EntryHeader::UnityCrossThreadLogger,
1139 "[UnityCrossThreadLogger]",
1140 )],
1141 );
1142 assert!(buf.is_empty());
1143 }
1144 }
1145
1146 // -- Realistic multi-line entry -----------------------------------------
1147
1148 mod realistic_entries {
1149 use super::*;
1150
1151 #[test]
1152 fn test_realistic_game_state_message() {
1153 let mut buf = LineBuffer::new();
1154 buf.push_line(
1155 "[UnityCrossThreadLogger]1/15/2025 3:42:17 PM \
1156 greToClientEvent",
1157 );
1158 buf.push_line("{");
1159 buf.push_line(r#" "greToClientMessages": ["#);
1160 buf.push_line(r" {");
1161 buf.push_line(r#" "type": "GREMessageType_GameStateMessage","#);
1162 buf.push_line(r#" "gameStateMessage": {"#);
1163 buf.push_line(r#" "gameObjects": []"#);
1164 buf.push_line(r" }");
1165 buf.push_line(r" }");
1166 buf.push_line(r" ]");
1167 let final_brace = buf.push_line("}");
1168
1169 #[cfg(feature = "brace_depth_flush")]
1170 {
1171 // The matching final `}` brace-balance flushes the UCTL
1172 // entry inside the same `push_line` that received it.
1173 assert_eq!(final_brace.len(), 1);
1174 assert_eq!(final_brace[0].header, EntryHeader::UnityCrossThreadLogger);
1175 assert!(final_brace[0].body.contains("greToClientMessages"));
1176 assert!(final_brace[0].body.contains("GameStateMessage"));
1177
1178 // A second UCTL multi-line entry begins accumulating.
1179 // No `{` in the body, so it falls through to the next-header flush.
1180 assert!(buf
1181 .push_line("[UnityCrossThreadLogger]1/15/2025 Next event")
1182 .is_empty());
1183
1184 assert_eq!(
1185 buf.push_line("[UnityCrossThreadLogger]1/15/2025 After"),
1186 vec![expected(
1187 EntryHeader::UnityCrossThreadLogger,
1188 "[UnityCrossThreadLogger]1/15/2025 Next event",
1189 )],
1190 );
1191 }
1192 #[cfg(not(feature = "brace_depth_flush"))]
1193 {
1194 assert!(final_brace.is_empty());
1195
1196 // Second UCTL (multi-line) flushes the first UCTL entry.
1197 let unity_entries = buf.push_line("[UnityCrossThreadLogger]1/15/2025 Next event");
1198 assert_eq!(unity_entries.len(), 1);
1199 assert_eq!(unity_entries[0].header, EntryHeader::UnityCrossThreadLogger);
1200 assert!(unity_entries[0].body.contains("greToClientMessages"));
1201 assert!(unity_entries[0].body.contains("GameStateMessage"));
1202
1203 // The next header flushes the second entry.
1204 assert_eq!(
1205 buf.push_line("[UnityCrossThreadLogger]1/15/2025 After"),
1206 vec![expected(
1207 EntryHeader::UnityCrossThreadLogger,
1208 "[UnityCrossThreadLogger]1/15/2025 Next event",
1209 )],
1210 );
1211 }
1212 }
1213
1214 #[test]
1215 fn test_many_single_line_entries_in_sequence() {
1216 let mut buf = LineBuffer::new();
1217 let mut entries = Vec::new();
1218
1219 for i in 0..5 {
1220 // Single-line UCTL alpha labels — each flushes immediately.
1221 entries.extend(buf.push_line(&format!("[UnityCrossThreadLogger]Event{i}")));
1222 }
1223 entries.extend(buf.flush());
1224
1225 assert_eq!(entries.len(), 5);
1226 for (i, e) in entries.iter().enumerate() {
1227 assert_eq!(e.header, EntryHeader::UnityCrossThreadLogger);
1228 assert_eq!(e.body, format!("[UnityCrossThreadLogger]Event{i}"));
1229 }
1230 }
1231 }
1232
1233 // -- Metadata line detection -----------------------------------------------
1234
1235 mod metadata_lines {
1236 use super::*;
1237
1238 #[test]
1239 fn test_push_line_detailed_logs_enabled_as_first_line() {
1240 let mut buf = LineBuffer::new();
1241 let result = buf.push_line("DETAILED LOGS: ENABLED");
1242
1243 assert_eq!(
1244 result,
1245 vec![expected(EntryHeader::Metadata, "DETAILED LOGS: ENABLED")],
1246 );
1247 // Buffer should be empty after — metadata is self-contained.
1248 assert!(buf.is_empty());
1249 }
1250
1251 #[test]
1252 fn test_push_line_detailed_logs_disabled_as_first_line() {
1253 let mut buf = LineBuffer::new();
1254 let result = buf.push_line("DETAILED LOGS: DISABLED");
1255
1256 assert_eq!(
1257 result,
1258 vec![expected(EntryHeader::Metadata, "DETAILED LOGS: DISABLED")],
1259 );
1260 assert!(buf.is_empty());
1261 }
1262
1263 /// Metadata after an in-progress multi-line entry flushes the prior
1264 /// entry AND emits the metadata entry — both in one call.
1265 #[test]
1266 fn test_push_line_metadata_flushes_buffered_entry() {
1267 let mut buf = LineBuffer::new();
1268 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event1");
1269
1270 let entries = buf.push_line("DETAILED LOGS: ENABLED");
1271 assert_eq!(
1272 entries,
1273 vec![
1274 expected(
1275 EntryHeader::UnityCrossThreadLogger,
1276 "[UnityCrossThreadLogger]1/1/2025 Event1",
1277 ),
1278 expected(EntryHeader::Metadata, "DETAILED LOGS: ENABLED"),
1279 ],
1280 );
1281 // Buffer is idle after — metadata is self-contained.
1282 assert!(buf.is_empty());
1283 }
1284
1285 #[test]
1286 fn test_push_line_metadata_then_header_flushes_metadata() {
1287 let mut buf = LineBuffer::new();
1288 buf.push_line("DETAILED LOGS: ENABLED");
1289
1290 // Next multi-line header — nothing to flush (metadata was emitted
1291 // immediately on its own call).
1292 assert!(buf
1293 .push_line("[UnityCrossThreadLogger]1/1/2025 Event")
1294 .is_empty());
1295 assert_eq!(
1296 buf.flush(),
1297 Some(expected(
1298 EntryHeader::UnityCrossThreadLogger,
1299 "[UnityCrossThreadLogger]1/1/2025 Event",
1300 )),
1301 );
1302 }
1303
1304 #[test]
1305 fn test_push_line_metadata_similar_text_not_matched() {
1306 let mut buf = LineBuffer::new();
1307 // Similar but not exact — should be treated as headerless.
1308 assert!(buf.push_line("DETAILED LOGS: UNKNOWN").is_empty());
1309 assert!(buf.push_line("detailed logs: enabled").is_empty());
1310 assert!(buf.push_line("DETAILED LOGS:ENABLED").is_empty());
1311 }
1312
1313 #[test]
1314 fn test_push_line_metadata_with_leading_trailing_whitespace() {
1315 let mut buf = LineBuffer::new();
1316 // Whitespace around the exact text should still match.
1317 let result = buf.push_line(" DETAILED LOGS: ENABLED ");
1318 assert_eq!(result.len(), 1);
1319 assert_eq!(result[0].header, EntryHeader::Metadata);
1320 }
1321
1322 #[test]
1323 fn test_entry_header_metadata_as_str() {
1324 assert_eq!(EntryHeader::Metadata.as_str(), "METADATA");
1325 }
1326
1327 #[test]
1328 fn test_entry_header_metadata_display() {
1329 assert_eq!(EntryHeader::Metadata.to_string(), "METADATA");
1330 }
1331 }
1332
1333 // -- Phase 2 (#161): orphan-warn gating ---------------------------------
1334
1335 mod orphan_warn_gating {
1336 use super::*;
1337 use std::sync::{Mutex, OnceLock};
1338
1339 /// In-test log capture: records every record's level + message so the
1340 /// gating tests can assert whether a warn fired.
1341 ///
1342 /// `log` only allows one global logger per process. We install it
1343 /// once via `OnceLock` and serialize the gating tests through a mutex
1344 /// so the captured-record buffer can be inspected race-free.
1345 struct CaptureLogger {
1346 records: Mutex<Vec<(::log::Level, String)>>,
1347 }
1348
1349 impl ::log::Log for CaptureLogger {
1350 fn enabled(&self, _metadata: &::log::Metadata<'_>) -> bool {
1351 true
1352 }
1353 fn log(&self, record: &::log::Record<'_>) {
1354 let mut guard = match self.records.lock() {
1355 Ok(g) => g,
1356 Err(poisoned) => poisoned.into_inner(),
1357 };
1358 guard.push((record.level(), record.args().to_string()));
1359 }
1360 fn flush(&self) {}
1361 }
1362
1363 static LOGGER: OnceLock<&'static CaptureLogger> = OnceLock::new();
1364
1365 type RecordsRef = &'static Mutex<Vec<(::log::Level, String)>>;
1366
1367 /// Installs the capture logger (idempotent) and returns a handle to
1368 /// the global capture buffer.
1369 ///
1370 /// The capture buffer accumulates records from every test that runs
1371 /// in this process, so callers MUST filter the captured records by a
1372 /// per-test sentinel marker — see [`warn_count_matching`]. This
1373 /// avoids the parallel-test race that a "clear before each test"
1374 /// strategy would introduce.
1375 fn install_capture() -> RecordsRef {
1376 let logger = LOGGER.get_or_init(|| {
1377 let leaked: &'static CaptureLogger = Box::leak(Box::new(CaptureLogger {
1378 records: Mutex::new(Vec::new()),
1379 }));
1380 // `set_logger` errors if a logger is already installed by
1381 // another test setup; in that case our captures will be
1382 // silently dropped, which is acceptable here because the
1383 // gating logic is also covered by behavioral tests
1384 // (`is_empty`, header round-trips) above.
1385 let _ = ::log::set_logger(leaked);
1386 ::log::set_max_level(::log::LevelFilter::Trace);
1387 leaked
1388 });
1389 &logger.records
1390 }
1391
1392 /// Counts captured warn-level records that contain `marker` in the
1393 /// message body.
1394 ///
1395 /// Tests pass a per-test sentinel string as the orphan input so the
1396 /// captured warning's truncated payload contains that sentinel.
1397 /// Filtering on the sentinel makes the count race-free even though
1398 /// Rust's test harness runs tests in parallel by default and other
1399 /// modules' tests share the same global logger.
1400 fn warn_count_matching(
1401 records: &Mutex<Vec<(::log::Level, String)>>,
1402 marker: &str,
1403 ) -> usize {
1404 let guard = match records.lock() {
1405 Ok(g) => g,
1406 Err(poisoned) => poisoned.into_inner(),
1407 };
1408 guard
1409 .iter()
1410 .filter(|(lvl, msg)| {
1411 *lvl == ::log::Level::Warn
1412 && msg.starts_with("Discarding headerless line at start of input")
1413 && msg.contains(marker)
1414 })
1415 .count()
1416 }
1417
1418 /// Orphan line before any header has been seen still produces the
1419 /// existing warning — this is the file-start anomaly the message was
1420 /// originally meant to flag.
1421 #[test]
1422 fn test_push_line_first_orphan_warns() {
1423 const MARKER: &str = "P2-MARKER-FIRST-ORPHAN-WARNS-zX9q";
1424 let records = install_capture();
1425 let mut buf = LineBuffer::new();
1426
1427 assert!(buf.push_line(MARKER).is_empty());
1428
1429 assert_eq!(
1430 warn_count_matching(records, MARKER),
1431 1,
1432 "first orphan at file start must warn (rotation/file-start anomaly)",
1433 );
1434 }
1435
1436 /// After a single-line entry has flushed, a subsequent headerless
1437 /// line is routine Unity stdout noise — silently discard, no warn.
1438 #[test]
1439 fn test_push_line_post_flush_orphan_silent() {
1440 const MARKER: &str = "P2-MARKER-POST-FLUSH-SILENT-kJ7w";
1441 let records = install_capture();
1442 let mut buf = LineBuffer::new();
1443
1444 // Single-line flush arms the gating flag.
1445 let entries = buf.push_line("[UnityCrossThreadLogger]STATE CHANGED {\"x\":1}");
1446 assert_eq!(entries.len(), 1);
1447 assert!(buf.is_empty());
1448
1449 // Unity stdout noise — should be silently dropped.
1450 assert!(buf.push_line(MARKER).is_empty());
1451
1452 assert_eq!(
1453 warn_count_matching(records, MARKER),
1454 0,
1455 "post-flush orphan must be silently discarded (no warn)",
1456 );
1457 }
1458
1459 /// `reset()` re-arms the warning so post-rotation orphans still
1460 /// surface — the rotation case the warn was originally meant to
1461 /// catch.
1462 #[test]
1463 fn test_push_line_orphan_after_reset_warns() {
1464 const MARKER: &str = "P2-MARKER-AFTER-RESET-WARNS-vN2t";
1465 let records = install_capture();
1466 let mut buf = LineBuffer::new();
1467
1468 // Flush an entry to arm the flag.
1469 assert_eq!(
1470 buf.push_line("[UnityCrossThreadLogger]STATE CHANGED {}")
1471 .len(),
1472 1,
1473 );
1474
1475 // Simulate file rotation — flag must drop back to false.
1476 buf.reset();
1477
1478 // First orphan after reset must warn again.
1479 assert!(buf.push_line(MARKER).is_empty());
1480
1481 assert_eq!(
1482 warn_count_matching(records, MARKER),
1483 1,
1484 "first orphan after reset must warn (rotation anomaly)",
1485 );
1486 }
1487
1488 /// A metadata line (`DETAILED LOGS: ENABLED`) is a successfully
1489 /// emitted entry, so subsequent orphan lines are post-flush noise
1490 /// and must be silently discarded.
1491 #[test]
1492 fn test_push_line_orphan_after_metadata_silent() {
1493 const MARKER: &str = "P2-MARKER-AFTER-METADATA-SILENT-bH4r";
1494 let records = install_capture();
1495 let mut buf = LineBuffer::new();
1496
1497 // Metadata arms the flag.
1498 let entries = buf.push_line("DETAILED LOGS: ENABLED");
1499 assert_eq!(entries.len(), 1);
1500 assert_eq!(entries[0].header, EntryHeader::Metadata);
1501
1502 // Subsequent orphan — silent.
1503 assert!(buf.push_line(MARKER).is_empty());
1504
1505 assert_eq!(
1506 warn_count_matching(records, MARKER),
1507 0,
1508 "orphan after metadata must be silently discarded (no warn)",
1509 );
1510 }
1511 }
1512
1513 // -- ConnectionManager / Matchmaking header framing ---------------------
1514
1515 mod connection_and_matchmaking_headers {
1516 use super::*;
1517
1518 #[test]
1519 fn test_as_str_connection_manager() {
1520 assert_eq!(
1521 EntryHeader::ConnectionManager.as_str(),
1522 "[ConnectionManager]"
1523 );
1524 }
1525
1526 #[test]
1527 fn test_as_str_matchmaking() {
1528 // The `Matchmaking:` prefix keeps the colon — this matches how
1529 // the line appears in Arena's actual log.
1530 assert_eq!(EntryHeader::Matchmaking.as_str(), "Matchmaking:");
1531 }
1532
1533 #[test]
1534 fn test_display_connection_manager() {
1535 assert_eq!(
1536 EntryHeader::ConnectionManager.to_string(),
1537 "[ConnectionManager]"
1538 );
1539 }
1540
1541 #[test]
1542 fn test_display_matchmaking() {
1543 assert_eq!(EntryHeader::Matchmaking.to_string(), "Matchmaking:");
1544 }
1545
1546 #[test]
1547 fn test_connection_manager_header_mid_stream_flushes_unity() {
1548 let mut buf = LineBuffer::new();
1549 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event1");
1550
1551 let entries = buf.push_line("[ConnectionManager] Reconnect result : Error");
1552 assert_eq!(
1553 entries,
1554 vec![
1555 expected(
1556 EntryHeader::UnityCrossThreadLogger,
1557 "[UnityCrossThreadLogger]1/1/2025 Event1",
1558 ),
1559 expected(
1560 EntryHeader::ConnectionManager,
1561 "[ConnectionManager] Reconnect result : Error",
1562 ),
1563 ],
1564 );
1565 // ConnectionManager is single-line — buffer is idle.
1566 assert!(buf.is_empty());
1567 }
1568
1569 #[test]
1570 fn test_matchmaking_header_mid_stream_flushes_unity() {
1571 let mut buf = LineBuffer::new();
1572 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event1");
1573
1574 let entries = buf.push_line("Matchmaking: GRE connection lost");
1575 assert_eq!(
1576 entries,
1577 vec![
1578 expected(
1579 EntryHeader::UnityCrossThreadLogger,
1580 "[UnityCrossThreadLogger]1/1/2025 Event1",
1581 ),
1582 expected(EntryHeader::Matchmaking, "Matchmaking: GRE connection lost",),
1583 ],
1584 );
1585 assert!(buf.is_empty());
1586 }
1587
1588 #[test]
1589 fn test_connection_manager_as_first_line_emits_immediately() {
1590 // Single-line semantics: the ConnectionManager entry is emitted
1591 // by the same `push_line` call that received it.
1592 let mut buf = LineBuffer::new();
1593 let entries = buf.push_line("[ConnectionManager] Reconnect succeeded");
1594 assert_eq!(
1595 entries,
1596 vec![expected(
1597 EntryHeader::ConnectionManager,
1598 "[ConnectionManager] Reconnect succeeded",
1599 )],
1600 );
1601 assert!(buf.is_empty());
1602 }
1603
1604 #[test]
1605 fn test_matchmaking_as_first_line_emits_immediately() {
1606 let mut buf = LineBuffer::new();
1607 let entries = buf.push_line("Matchmaking: GRE connection lost");
1608 assert_eq!(
1609 entries,
1610 vec![expected(
1611 EntryHeader::Matchmaking,
1612 "Matchmaking: GRE connection lost",
1613 )],
1614 );
1615 assert!(buf.is_empty());
1616 }
1617
1618 #[test]
1619 fn test_four_way_interleave_yields_four_entries() {
1620 // Realistic corpus-derived pattern from issues #528/#529:
1621 // Unity STATE CHANGED → Matchmaking: GRE connection lost →
1622 // ConnectionManager Reconnect result → Unity (next event).
1623 // All four are single-line, so each `push_line` returns 1 entry.
1624 let mut buf = LineBuffer::new();
1625 let mut entries = Vec::new();
1626
1627 entries.extend(buf.push_line(
1628 "[UnityCrossThreadLogger]STATE CHANGED \
1629 {\"old\":\"Playing\",\"new\":\"Disconnected\"}",
1630 ));
1631 entries.extend(buf.push_line("Matchmaking: GRE connection lost"));
1632 entries.extend(buf.push_line("[ConnectionManager] Reconnect result : Error"));
1633 entries.extend(buf.push_line("[UnityCrossThreadLogger]Next event"));
1634 entries.extend(buf.flush());
1635
1636 assert_eq!(entries.len(), 4);
1637 assert_eq!(entries[0].header, EntryHeader::UnityCrossThreadLogger);
1638 assert!(entries[0].body.contains("STATE CHANGED"));
1639 assert_eq!(entries[1].header, EntryHeader::Matchmaking);
1640 assert_eq!(entries[1].body, "Matchmaking: GRE connection lost");
1641 assert_eq!(entries[2].header, EntryHeader::ConnectionManager);
1642 assert_eq!(
1643 entries[2].body,
1644 "[ConnectionManager] Reconnect result : Error"
1645 );
1646 assert_eq!(entries[3].header, EntryHeader::UnityCrossThreadLogger);
1647 assert_eq!(entries[3].body, "[UnityCrossThreadLogger]Next event");
1648 }
1649
1650 #[test]
1651 fn test_matchmaking_without_trailing_space_is_not_header() {
1652 // The starts_with check requires the trailing space ("Matchmaking: ")
1653 // to avoid matching unrelated prefixes that happen to start
1654 // with "Matchmaking:". Without the space it should be a
1655 // headerless line (discarded at start of stream).
1656 let mut buf = LineBuffer::new();
1657 assert!(buf.push_line("Matchmaking:compact-no-space").is_empty());
1658 assert!(buf.is_empty());
1659 }
1660
1661 #[test]
1662 fn test_connection_manager_mid_line_is_continuation() {
1663 let mut buf = LineBuffer::new();
1664 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event");
1665 // ConnectionManager bracket pattern in the middle of a line is
1666 // NOT a boundary — same rule as other bracketed headers.
1667 buf.push_line("some text [ConnectionManager] not a header");
1668 assert_eq!(
1669 buf.flush(),
1670 Some(expected(
1671 EntryHeader::UnityCrossThreadLogger,
1672 "[UnityCrossThreadLogger]1/1/2025 Event\n\
1673 some text [ConnectionManager] not a header",
1674 )),
1675 );
1676 }
1677 }
1678
1679 // -- Brace-depth flush (#193) -------------------------------------------
1680
1681 #[cfg(feature = "brace_depth_flush")]
1682 mod brace_depth_flush {
1683 use super::*;
1684
1685 /// Header + single-line `{...}` body — the closing `}` flushes the
1686 /// entry immediately, no next header required.
1687 #[test]
1688 fn test_single_line_json_body_flushes_immediately() {
1689 let mut buf = LineBuffer::new();
1690 assert!(buf
1691 .push_line("[UnityCrossThreadLogger]1/1/2025 Event")
1692 .is_empty());
1693 let result = buf.push_line(r#"{"key":"value"}"#);
1694 assert_eq!(
1695 result,
1696 vec![expected(
1697 EntryHeader::UnityCrossThreadLogger,
1698 "[UnityCrossThreadLogger]1/1/2025 Event\n{\"key\":\"value\"}",
1699 )],
1700 );
1701 assert!(buf.is_empty(), "buffer must be idle after brace-flush");
1702 }
1703
1704 /// Pretty-printed multi-line JSON: opening `{`, key/value lines,
1705 /// closing `}` on its own line. The closing `}` flushes the entry.
1706 #[test]
1707 fn test_multi_line_pretty_printed_json_flushes_on_closing_brace() {
1708 let mut buf = LineBuffer::new();
1709 buf.push_line("[UnityCrossThreadLogger]1/1/2025 GreToClientEvent");
1710 buf.push_line("{");
1711 buf.push_line(r#" "key": "val""#);
1712 let result = buf.push_line("}");
1713 assert_eq!(result.len(), 1);
1714 assert_eq!(result[0].header, EntryHeader::UnityCrossThreadLogger);
1715 assert_eq!(
1716 result[0].body,
1717 "[UnityCrossThreadLogger]1/1/2025 GreToClientEvent\n{\n \"key\": \"val\"\n}",
1718 );
1719 assert!(buf.is_empty());
1720 }
1721
1722 /// Header + `<==` response marker continuation + JSON body. The
1723 /// response marker has no `{`; the JSON body line flushes on its
1724 /// closing `}`.
1725 #[test]
1726 fn test_response_marker_then_json_flushes() {
1727 let mut buf = LineBuffer::new();
1728 assert!(buf
1729 .push_line("[UnityCrossThreadLogger]1/1/2025 12:00:00 PM")
1730 .is_empty());
1731 assert!(buf.push_line("<== EventGetCoursesV2(abc)").is_empty());
1732 let result = buf.push_line(r#"{"Courses":[]}"#);
1733 assert_eq!(result.len(), 1);
1734 assert_eq!(result[0].header, EntryHeader::UnityCrossThreadLogger);
1735 assert!(result[0].body.contains("<== EventGetCoursesV2(abc)"));
1736 assert!(result[0].body.contains(r#"{"Courses":[]}"#));
1737 assert!(buf.is_empty());
1738 }
1739
1740 /// Non-JSON bodies (no `{` anywhere) fall through to the legacy
1741 /// "flush on next header" path — corresponds to the rare
1742 /// `true`-bodied REST responses and similar header-less continuations
1743 /// whose body never opens a brace.
1744 #[test]
1745 fn test_non_json_body_falls_through_to_next_header() {
1746 let mut buf = LineBuffer::new();
1747 buf.push_line("[UnityCrossThreadLogger]1/1/2025 GreToClientEvent");
1748 assert!(buf.push_line("(payload elided)").is_empty());
1749 assert!(buf.push_line(":: 12345 entries").is_empty());
1750 assert!(buf.push_line(":: payload trimmed").is_empty());
1751
1752 // Next header flushes the accumulating entry — never brace-flushed
1753 // because no `{` appeared.
1754 let entries = buf.push_line("[UnityCrossThreadLogger]1/1/2025 After");
1755 assert_eq!(entries.len(), 1);
1756 assert_eq!(entries[0].header, EntryHeader::UnityCrossThreadLogger);
1757 assert!(entries[0].body.contains("(payload elided)"));
1758 assert!(entries[0].body.contains(":: 12345 entries"));
1759 }
1760
1761 /// Brace state must not leak between entries: after a brace-flush,
1762 /// a follow-up entry with no `{` must NOT trigger a stale flush.
1763 #[test]
1764 fn test_brace_state_clears_between_entries() {
1765 let mut buf = LineBuffer::new();
1766
1767 // First entry — brace-balance flushes it.
1768 buf.push_line("[UnityCrossThreadLogger]1/1/2025 First");
1769 let first = buf.push_line(r#"{"a":1}"#);
1770 assert_eq!(first.len(), 1);
1771 assert!(buf.is_empty());
1772
1773 // Brace state should be reset — internal sanity check so a
1774 // regression here surfaces directly rather than through
1775 // downstream behavior.
1776 assert_eq!(buf.brace_state.depth, 0);
1777 assert!(!buf.brace_state.in_string);
1778 assert!(!buf.brace_state.escape_pending);
1779 assert!(!buf.brace_state.ever_opened);
1780
1781 // Second entry has no `{`. Without proper state reset, stale
1782 // `ever_opened=true` would falsely flush this entry's first
1783 // continuation line. With reset, it accumulates normally and
1784 // the next header flushes it.
1785 buf.push_line("[UnityCrossThreadLogger]1/1/2025 PlainBodyEvent");
1786 assert!(buf.push_line("just text").is_empty());
1787 let entries = buf.push_line("[UnityCrossThreadLogger]1/1/2025 Third");
1788 assert_eq!(entries.len(), 1);
1789 assert_eq!(entries[0].header, EntryHeader::UnityCrossThreadLogger);
1790 assert_eq!(
1791 entries[0].body,
1792 "[UnityCrossThreadLogger]1/1/2025 PlainBodyEvent\njust text",
1793 );
1794 }
1795
1796 /// After a brace-flush, subsequent headerless lines must be treated
1797 /// as routine post-flush noise (silently discarded, no warn) — the
1798 /// brace-flush path must arm the same `has_emitted_anything` gate
1799 /// the next-header flush path arms.
1800 #[test]
1801 fn test_brace_flush_arms_orphan_warn_gating() {
1802 let mut buf = LineBuffer::new();
1803
1804 // Brace-flush an entry.
1805 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Event");
1806 let flushed = buf.push_line(r#"{"k":"v"}"#);
1807 assert_eq!(flushed.len(), 1);
1808
1809 // `has_emitted_anything` was armed by the header detection,
1810 // not by the flush itself — verify the gate is still set
1811 // after brace-flush so the next orphan is silenced.
1812 assert!(
1813 buf.has_emitted_anything,
1814 "brace-flush path must leave has_emitted_anything armed",
1815 );
1816
1817 // A subsequent orphan line must be silently discarded.
1818 assert!(buf.push_line("orphan stdout noise").is_empty());
1819 assert!(buf.is_empty());
1820 }
1821 }
1822
1823 // -- Brace-depth string-literal handling (property tests) ---------------
1824
1825 // proptest is not available for wasm32 targets (it uses host-only OS APIs);
1826 // gate these tests to non-wasm host builds only.
1827 #[cfg(all(feature = "brace_depth_flush", not(target_arch = "wasm32")))]
1828 mod brace_depth_property {
1829 use super::*;
1830 use proptest::prelude::*;
1831 use serde_json::Value;
1832
1833 /// Recursive strategy producing arbitrary JSON values. Strings include
1834 /// the `{`, `}`, `"`, and `\` characters specifically because those
1835 /// are the characters the brace-state machine must handle without
1836 /// being fooled by content inside string literals.
1837 fn arb_json_value() -> impl Strategy<Value = Value> {
1838 // Strings sample from a character set that includes every
1839 // character the state machine special-cases.
1840 let arb_string = r#"[a-z0-9 \{\}\"\\]{0,12}"#.prop_map(Value::String);
1841 let leaf = prop_oneof![
1842 Just(Value::Null),
1843 any::<bool>().prop_map(Value::Bool),
1844 any::<i32>().prop_map(|n| Value::Number(n.into())),
1845 arb_string,
1846 ];
1847 leaf.prop_recursive(3, 24, 4, |inner| {
1848 prop_oneof![
1849 prop::collection::vec(inner.clone(), 0..4).prop_map(Value::Array),
1850 prop::collection::vec((r"[a-z]{1,6}", inner), 0..4)
1851 .prop_map(|kvs| { Value::Object(kvs.into_iter().collect()) }),
1852 ]
1853 })
1854 }
1855
1856 proptest! {
1857 /// Any serialized JSON value, when fed as one continuation line
1858 /// after a multi-line header, must brace-balance and flush.
1859 #[test]
1860 fn prop_balanced_json_flushes_exactly_once(value in arb_json_value()) {
1861 // Force the top-level value to be an object so the body
1862 // opens with `{` — the property is about closed JSON
1863 // structures, not bare leaves.
1864 // `serde_json::to_string` only errors on serializers that
1865 // refuse some `Serialize` shape — `Value` always serializes
1866 // cleanly, so the `Err` branch is unreachable in practice.
1867 let body = match serde_json::to_string(&Value::Object(
1868 [("v".to_owned(), value)].into_iter().collect(),
1869 )) {
1870 Ok(s) => s,
1871 Err(e) => unreachable!("serde_json::to_string on Value failed: {e}"),
1872 };
1873 let mut buf = LineBuffer::new();
1874 let header = buf.push_line("[UnityCrossThreadLogger]1/1/2025 PropTest");
1875 prop_assert!(header.is_empty());
1876 let out = buf.push_line(&body);
1877 prop_assert_eq!(out.len(), 1, "balanced JSON must brace-flush");
1878 prop_assert!(buf.is_empty());
1879 }
1880
1881 /// An unterminated string literal — `"abc` with no closing `"`
1882 /// — must never appear balanced no matter what comes after the
1883 /// opening `{`.
1884 #[test]
1885 fn prop_unterminated_string_never_balances(
1886 prefix in r"[a-z0-9 ]{0,16}",
1887 trailing in r"[a-z0-9 \{\}]{0,16}",
1888 ) {
1889 let body = format!(r#"{{"k":"{prefix}{trailing}"#);
1890 let mut buf = LineBuffer::new();
1891 buf.push_line("[UnityCrossThreadLogger]1/1/2025 PropTest");
1892 let out = buf.push_line(&body);
1893 prop_assert_eq!(
1894 out.len(),
1895 0,
1896 "unterminated string literal must not be reported balanced",
1897 );
1898 prop_assert!(!buf.is_empty(), "entry should remain accumulating");
1899 }
1900
1901 /// `{` and `}` characters embedded in a string literal must not
1902 /// affect the brace-balance counter — a well-formed JSON object
1903 /// containing brace-noise in a string value still flushes.
1904 #[test]
1905 fn prop_braces_in_strings_dont_count(
1906 noise in r"[\{\}]{0,16}",
1907 ) {
1908 let body = format!(r#"{{"junk":"{noise}"}}"#);
1909 let mut buf = LineBuffer::new();
1910 buf.push_line("[UnityCrossThreadLogger]1/1/2025 PropTest");
1911 let out = buf.push_line(&body);
1912 prop_assert_eq!(
1913 out.len(),
1914 1,
1915 "braces inside string literals must not affect the counter",
1916 );
1917 }
1918 }
1919
1920 // -- Hand-written regression cases derived from corpus analysis ----
1921
1922 /// `{"request":"{\"foo\":\"bar\"}"}` — a JSON object whose string
1923 /// value contains a nested escaped JSON object. Corpus has 585 such
1924 /// entries; all must brace-balance correctly because the inner
1925 /// braces appear inside a string literal.
1926 #[test]
1927 fn test_regression_nested_json_in_string() {
1928 let mut buf = LineBuffer::new();
1929 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Nested");
1930 let body = r#"{"request":"{\"foo\":\"bar\"}"}"#;
1931 let out = buf.push_line(body);
1932 assert_eq!(out.len(), 1, "nested-string body must brace-balance");
1933 assert_eq!(
1934 out[0].body,
1935 format!("[UnityCrossThreadLogger]1/1/2025 Nested\n{body}")
1936 );
1937 }
1938
1939 /// Escaped quote inside a string literal: the `\"` does NOT close
1940 /// the string, so the next unescaped `"` is the real closer.
1941 #[test]
1942 fn test_regression_escaped_quote_inside_string() {
1943 let mut buf = LineBuffer::new();
1944 buf.push_line("[UnityCrossThreadLogger]1/1/2025 EscQuote");
1945 let body = r#"{"name":"a \"quoted\" name"}"#;
1946 let out = buf.push_line(body);
1947 assert_eq!(out.len(), 1);
1948 assert!(out[0].body.contains(r#""a \"quoted\" name""#));
1949 }
1950
1951 /// Escaped backslashes: `\\` is an escape pair; the next character
1952 /// is NOT escaped, so an `"` immediately after `\\` correctly
1953 /// toggles string state.
1954 #[test]
1955 fn test_regression_escaped_backslash_inside_string() {
1956 let mut buf = LineBuffer::new();
1957 buf.push_line("[UnityCrossThreadLogger]1/1/2025 EscBackslash");
1958 let body = r#"{"path":"C:\\Users\\foo"}"#;
1959 let out = buf.push_line(body);
1960 assert_eq!(out.len(), 1);
1961 assert!(out[0].body.contains(r#""C:\\Users\\foo""#));
1962 }
1963
1964 /// Bare `{` and `}` inside a string literal must not move the
1965 /// counter — the entry balances on the outer `}` alone.
1966 #[test]
1967 fn test_regression_brace_inside_string_literal() {
1968 let mut buf = LineBuffer::new();
1969 buf.push_line("[UnityCrossThreadLogger]1/1/2025 BraceInStr");
1970 let body = r#"{"emoji":"{ :) }"}"#;
1971 let out = buf.push_line(body);
1972 assert_eq!(out.len(), 1);
1973 assert!(out[0].body.contains(r#""{ :) }""#));
1974 }
1975
1976 /// Pathological unbalanced JSON — opens a `{` but never closes
1977 /// it. Depth stays > 0 forever; the entry never brace-flushes
1978 /// and must fall through to the next-header flush path. Defined
1979 /// behavior, no panic.
1980 #[test]
1981 fn test_regression_unbalanced_json_falls_through() {
1982 let mut buf = LineBuffer::new();
1983 buf.push_line("[UnityCrossThreadLogger]1/1/2025 Unbalanced");
1984 assert!(buf.push_line(r#"{"unclosed":"#).is_empty());
1985 assert!(buf.push_line(r#" "more":"data""#).is_empty());
1986
1987 // Next header flushes via the fallback path.
1988 let next = buf.push_line("[UnityCrossThreadLogger]1/1/2025 NextEvent");
1989 assert_eq!(next.len(), 1);
1990 assert_eq!(next[0].header, EntryHeader::UnityCrossThreadLogger);
1991 assert!(next[0].body.contains(r#"{"unclosed":"#));
1992 }
1993
1994 /// A JSON string value containing the `\n` escape sequence (not a
1995 /// real newline) keeps the value on one logical body line —
1996 /// `\\n` is two characters, not a line break.
1997 #[test]
1998 fn test_regression_escaped_newline_in_string() {
1999 let mut buf = LineBuffer::new();
2000 buf.push_line("[UnityCrossThreadLogger]1/1/2025 EscNewline");
2001 // `\n` in the source string is the two-character escape sequence
2002 // `\` followed by `n` — not a real newline.
2003 let body = r#"{"raw":"line1\nline2"}"#;
2004 let out = buf.push_line(body);
2005 assert_eq!(out.len(), 1);
2006 assert!(out[0].body.contains(r#""line1\nline2""#));
2007 }
2008 }
2009
2010 // -- LineBuffer: GSM truncation marker header (#200) ---------------------
2011
2012 mod truncation_marker {
2013 use super::*;
2014
2015 const MARKER: &str = "[Message summarized because one or more GameStateMessages \
2016 exceeded the 50 GameObject or 50 Annotation limit.]";
2017
2018 #[test]
2019 fn test_as_str_truncation_marker() {
2020 assert_eq!(
2021 EntryHeader::TruncationMarker.as_str(),
2022 "[Message summarized]"
2023 );
2024 }
2025
2026 #[test]
2027 fn test_display_truncation_marker() {
2028 assert_eq!(
2029 EntryHeader::TruncationMarker.to_string(),
2030 "[Message summarized]"
2031 );
2032 }
2033
2034 #[test]
2035 fn test_marker_is_detected_as_header() {
2036 let buf = LineBuffer::new();
2037 assert_eq!(
2038 buf.detect_header(MARKER),
2039 Some(EntryHeader::TruncationMarker)
2040 );
2041 }
2042
2043 #[test]
2044 fn test_marker_with_prefix_only_is_detected() {
2045 // Detection uses the `[Message summarized` prefix to stay
2046 // tolerant of minor wording variations. Any line starting with
2047 // that prefix is classified as a truncation marker.
2048 let buf = LineBuffer::new();
2049 let line = "[Message summarized for some other reason]";
2050 assert_eq!(buf.detect_header(line), Some(EntryHeader::TruncationMarker));
2051 }
2052
2053 #[test]
2054 fn test_marker_classified_as_multi_line() {
2055 assert_eq!(
2056 LineBuffer::classify_header(EntryHeader::TruncationMarker, MARKER),
2057 HeaderClass::MultiLine,
2058 );
2059 }
2060
2061 #[test]
2062 fn test_marker_as_first_line_starts_accumulation() {
2063 let mut buf = LineBuffer::new();
2064 let out = buf.push_line(MARKER);
2065 // MultiLine — entry is not flushed yet.
2066 assert!(out.is_empty());
2067 assert!(!buf.is_empty());
2068 }
2069
2070 #[test]
2071 fn test_marker_mid_stream_flushes_prior_uctl_envelope() {
2072 // The truncation marker arrives inside a `[UnityCrossThreadLogger]`
2073 // envelope and the prior (now header-only) UCTL entry must flush
2074 // when the marker triggers a new MultiLine entry.
2075 let mut buf = LineBuffer::new();
2076 buf.push_line(
2077 "[UnityCrossThreadLogger]5/13/2026 10:01:12 AM: \
2078 Match to <transaction>: GreToClientEvent",
2079 );
2080
2081 let out = buf.push_line(MARKER);
2082 assert_eq!(out.len(), 1);
2083 assert_eq!(out[0].header, EntryHeader::UnityCrossThreadLogger);
2084 assert!(out[0].body.contains("GreToClientEvent"));
2085
2086 // Truncation entry is now accumulating in the buffer.
2087 assert!(!buf.is_empty());
2088 }
2089
2090 #[test]
2091 fn test_marker_accumulates_count_lines_until_next_header() {
2092 // The marker + follow-on `::: GameStateMessage`, `:: GameObject
2093 // Count = N`, `:: Annotation Count = M`, and `::: ActionsAvailableReq`
2094 // lines are all accumulated into the truncation entry. The entry
2095 // flushes when the next real header arrives (here, the next
2096 // `[UnityCrossThreadLogger]` line).
2097 let mut buf = LineBuffer::new();
2098 assert!(buf.push_line(MARKER).is_empty());
2099 assert!(buf.push_line("::: GameStateMessage").is_empty());
2100 assert!(buf.push_line(":: GameObject Count = 63").is_empty());
2101 assert!(buf.push_line(":: Annotation Count = 4").is_empty());
2102 assert!(buf.push_line("::: ActionsAvailableReq").is_empty());
2103
2104 let out = buf.push_line("[UnityCrossThreadLogger]5/13/2026 10:01:13 AM Next");
2105 assert_eq!(out.len(), 1);
2106 assert_eq!(out[0].header, EntryHeader::TruncationMarker);
2107 assert!(out[0].body.starts_with(MARKER));
2108 assert!(out[0].body.contains(":: GameObject Count = 63"));
2109 assert!(out[0].body.contains(":: Annotation Count = 4"));
2110 assert!(out[0].body.contains("::: ActionsAvailableReq"));
2111 }
2112
2113 #[test]
2114 fn test_marker_flush_via_eof() {
2115 // EOF flush also produces the truncation entry, in case the log
2116 // ends immediately after the marker block.
2117 let mut buf = LineBuffer::new();
2118 buf.push_line(MARKER);
2119 buf.push_line("::: GameStateMessage");
2120 buf.push_line(":: GameObject Count = 7");
2121 buf.push_line(":: Annotation Count = 11");
2122 let flushed = buf.flush();
2123 assert!(flushed.is_some());
2124 let entry = flushed.unwrap_or_else(|| unreachable!());
2125 assert_eq!(entry.header, EntryHeader::TruncationMarker);
2126 assert!(entry.body.contains("GameObject Count = 7"));
2127 assert!(entry.body.contains("Annotation Count = 11"));
2128 }
2129 }
2130}