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