diff --git a/tools/nevermore-cli/src/utils/testing/parsers/batch-log-parser.test.ts b/tools/nevermore-cli/src/utils/testing/parsers/batch-log-parser.test.ts index acbf190909..6c3a340317 100644 --- a/tools/nevermore-cli/src/utils/testing/parsers/batch-log-parser.test.ts +++ b/tools/nevermore-cli/src/utils/testing/parsers/batch-log-parser.test.ts @@ -151,6 +151,241 @@ describe('parseBatchTestLogs', () => { expect(result?.testCounts?.failed).toBe(0); expect(result?.tracebackCount).toBe(1); }); + + it('fails a section containing a traceback', () => { + const logs = buildLogs( + [ + 'Tests: 155 passed, 155 total', + 'PlayerBadgeHelper: attempt to index nil', + 'Stack Begin', + "Script 'PlayerBadgeHelper', Line 365", + 'Stack End', + ].join('\n') + ); + + const result = parseBatchTestLogs(logs, SLUG_MAP).get('egghunt2026'); + + expect(result?.success).toBe(false); + expect(result?.error).toContain('Luau traceback(s)'); + }); + + it('takes the whole inner string as the slug when END has no PASS or FAIL', () => { + const logs = [ + '===BATCH_TEST_BEGIN egghunt2026===', + 'Tests: 5 passed, 5 total', + '===BATCH_TEST_END egghunt2026===', + '===BATCH_TEST_SUMMARY===', + '[{"slug":"egghunt2026","success":true}]', + ].join('\n'); + + const result = parseBatchTestLogs(logs, SLUG_MAP).get('egghunt2026'); + + expect(result?.success).toBe(true); + expect(result?.testCounts).toEqual({ passed: 5, failed: 0, total: 5 }); + }); + + it('records no duration for an END that carries none', () => { + const logs = [ + '===BATCH_TEST_BEGIN egghunt2026===', + 'Tests: 5 passed, 5 total', + '===BATCH_TEST_END egghunt2026 PASS===', + '===BATCH_TEST_SUMMARY===', + '[{"slug":"egghunt2026","success":true}]', + ].join('\n'); + + const result = parseBatchTestLogs(logs, SLUG_MAP).get('egghunt2026'); + + expect(result?.durationMs).toBeUndefined(); + }); + + it('falls back to the END marker duration when the summary entry omits one', () => { + const logs = [ + '===BATCH_TEST_BEGIN egghunt2026===', + 'Tests: 5 passed, 5 total', + '===BATCH_TEST_END egghunt2026 PASS 4242===', + '===BATCH_TEST_SUMMARY===', + '[{"slug":"egghunt2026","success":true}]', + ].join('\n'); + + const result = parseBatchTestLogs(logs, SLUG_MAP).get('egghunt2026'); + + expect(result?.durationMs).toBe(4242); + }); + + it('lets only the first BEGIN-less END claim the output above it', () => { + const twoPackages = new Map([ + ['alpha', 'alpha'], + ['beta', 'beta'], + ]); + const logs = [ + 'Tests: 10 passed, 10 total', + '===BATCH_TEST_END alpha PASS 10===', + 'Tests: 20 passed, 20 total', + '===BATCH_TEST_END beta PASS 20===', + '===BATCH_TEST_SUMMARY===', + '[{"slug":"alpha","success":true},{"slug":"beta","success":true}]', + ].join('\n'); + + const results = parseBatchTestLogs(logs, twoPackages); + + expect(results.get('alpha')?.testCounts?.total).toBe(10); + expect(results.get('beta')?.testCounts).toBeUndefined(); + expect(results.get('beta')?.logs).toBe(''); + expect(results.get('beta')?.error).toContain( + 'no output could be attributed' + ); + }); + + it('distinguishes a reported Luau error from an absent summary entry', () => { + const twoPackages = new Map([ + ['alpha', 'alpha'], + ['beta', 'beta'], + ]); + const logs = [ + '===BATCH_TEST_BEGIN alpha===', + 'Tests: 10 passed, 10 total', + '===BATCH_TEST_END alpha FAIL 10===', + '===BATCH_TEST_BEGIN beta===', + 'Tests: 20 passed, 20 total', + '===BATCH_TEST_END beta PASS 20===', + '===BATCH_TEST_SUMMARY===', + '[{"slug":"alpha","success":false,"error":"boom"}]', + ].join('\n'); + + const results = parseBatchTestLogs(logs, twoPackages); + + expect(results.get('alpha')?.success).toBe(false); + expect(results.get('alpha')?.error).toBe( + 'the batch runner reported a Luau error' + ); + expect(results.get('beta')?.success).toBe(false); + expect(results.get('beta')?.error).toBe( + 'this package is missing from the batch summary' + ); + }); + + it('reads every package as missing when the summary payload is not JSON', () => { + const twoPackages = new Map([ + ['alpha', 'alpha'], + ['beta', 'beta'], + ]); + const logs = [ + '===BATCH_TEST_BEGIN alpha===', + 'Tests: 10 passed, 10 total', + '===BATCH_TEST_END alpha PASS 10===', + '===BATCH_TEST_BEGIN beta===', + 'Tests: 20 passed, 20 total', + '===BATCH_TEST_END beta PASS 20===', + '===BATCH_TEST_SUMMARY===', + 'not json at all', + ].join('\n'); + + const results = parseBatchTestLogs(logs, twoPackages); + + expect(results.get('alpha')?.error).toBe( + 'this package is missing from the batch summary' + ); + expect(results.get('beta')?.error).toBe( + 'this package is missing from the batch summary' + ); + }); + + it('reads every package as missing when no summary arrived at all', () => { + const twoPackages = new Map([ + ['alpha', 'alpha'], + ['beta', 'beta'], + ]); + const logs = [ + '===BATCH_TEST_BEGIN alpha===', + 'Tests: 10 passed, 10 total', + '===BATCH_TEST_END alpha PASS 10===', + '===BATCH_TEST_BEGIN beta===', + 'Tests: 20 passed, 20 total', + '===BATCH_TEST_END beta PASS 20===', + ].join('\n'); + + const results = parseBatchTestLogs(logs, twoPackages); + + expect(results.get('alpha')?.error).toBe( + 'this package is missing from the batch summary' + ); + expect(results.get('beta')?.error).toBe( + 'this package is missing from the batch summary' + ); + }); + + it('joins several failure reasons with a semicolon', () => { + const logs = [ + '===BATCH_TEST_BEGIN egghunt2026===', + 'Tests: 2 failed, 8 passed, 10 total', + 'Test Suites: 1 failed, 3 total', + '===BATCH_TEST_END egghunt2026 FAIL 10===', + '===BATCH_TEST_SUMMARY===', + '[{"slug":"egghunt2026","success":false}]', + ].join('\n'); + + const result = parseBatchTestLogs(logs, SLUG_MAP).get('egghunt2026'); + + expect(result?.error).toBe( + 'the batch runner reported a Luau error; ' + + '1 test suite(s) failed; 2 test(s) failed' + ); + }); + + it('treats a marker missing its trailing delimiter as ordinary content', () => { + const logs = [ + '===BATCH_TEST_BEGIN egghunt2026===', + '===BATCH_TEST_BEGIN egghunt2026', + 'Tests: 5 passed, 5 total', + '===BATCH_TEST_END egghunt2026 PASS 5===', + '===BATCH_TEST_SUMMARY===', + '[{"slug":"egghunt2026","success":true}]', + ].join('\n'); + + const result = parseBatchTestLogs(logs, SLUG_MAP).get('egghunt2026'); + + expect(result?.logs).toContain('===BATCH_TEST_BEGIN egghunt2026'); + expect(result?.testCounts).toEqual({ passed: 5, failed: 0, total: 5 }); + }); + + it('hands unattributable output to the first package only', () => { + const threePackages = new Map([ + ['alpha', 'alpha'], + ['beta', 'beta'], + ['gamma', 'gamma'], + ]); + const logs = [ + 'PlayerBadgeHelper: attempt to index nil', + '===BATCH_TEST_SUMMARY===', + '[{"slug":"alpha","success":true},{"slug":"beta","success":true},' + + '{"slug":"gamma","success":true}]', + ].join('\n'); + + const results = parseBatchTestLogs(logs, threePackages); + + expect(results.get('alpha')?.logs).toContain('PlayerBadgeHelper'); + expect(results.get('beta')?.logs).toBe(''); + expect(results.get('gamma')?.logs).toBe(''); + }); + + it('fails an empty section for having no jest report, with no counts', () => { + const logs = [ + '===BATCH_TEST_BEGIN egghunt2026===', + '===BATCH_TEST_END egghunt2026 PASS 0===', + '===BATCH_TEST_SUMMARY===', + '[{"slug":"egghunt2026","success":true}]', + ].join('\n'); + + const result = parseBatchTestLogs(logs, SLUG_MAP).get('egghunt2026'); + + expect(result?.success).toBe(false); + expect(result?.logs).toBe(''); + expect(result?.error).toBe( + 'no jest report in output — nothing proves any test ran' + ); + // No counts were seen, so none are reported — an empty section is not zero. + expect(result?.testCounts).toBeUndefined(); + }); }); describe('findSummaryEntries', () => { diff --git a/tools/nevermore-cli/src/utils/testing/parsers/batch-log-parser.ts b/tools/nevermore-cli/src/utils/testing/parsers/batch-log-parser.ts index b1d0b60f97..e1e97a932e 100644 --- a/tools/nevermore-cli/src/utils/testing/parsers/batch-log-parser.ts +++ b/tools/nevermore-cli/src/utils/testing/parsers/batch-log-parser.ts @@ -26,6 +26,10 @@ export interface BatchPackageResult { const BEGIN_MARKER = '===BATCH_TEST_BEGIN '; const END_MARKER = '===BATCH_TEST_END '; const SUMMARY_MARKER = '===BATCH_TEST_SUMMARY==='; +const MARKER_SUFFIX = '==='; + +// Matches " PASS|FAIL []" — slugs have no whitespace. +const END_INNER_PATTERN = /^(\S+)\s+(?:PASS|FAIL)(?:\s+(\d+))?$/; interface SummaryEntry { slug: string; @@ -34,6 +38,54 @@ interface SummaryEntry { error?: string; } +interface BeginToken { + kind: 'begin'; + slug: string; +} + +interface EndToken { + kind: 'end'; + slug: string; + durationMs?: number; +} + +interface SummaryToken { + kind: 'summary'; + /** Where the marker sat, so the JSON payload can be looked up around it. */ + lineIndex: number; +} + +interface SummaryPayloadToken { + kind: 'summaryPayload'; +} + +interface ContentToken { + kind: 'content'; + /** The untrimmed line, since section logs are shown to a human verbatim. */ + line: string; +} + +/** One log line, classified. Every line becomes exactly one token. */ +type BatchLogToken = + | BeginToken + | EndToken + | SummaryToken + | SummaryPayloadToken + | ContentToken; + +interface FoldedSections { + /** Log text of each section that closed, by slug. */ + sections: Map; + /** Sections closed by an END whose BEGIN never arrived — start of output lost. */ + partialSections: Set; + /** Durations read off END markers, by slug. */ + markerDurations: Map; + /** Slugs of ENDs that closed nothing, so claimed no output. */ + strayEndSlugs: string[]; + /** Slugs of sections a second BEGIN reopened, discarding their output. */ + orphanedBeginSlugs: string[]; +} + /** * Parse the single batch execution's logs into per-package results. * @@ -63,94 +115,27 @@ export function parseBatchTestLogs( // ── Pass 1: Extract per-package log sections from markers ── - const logSections = new Map(); - /** Sections closed by an END whose BEGIN never arrived — start of output lost. */ - const partialSections = new Set(); - const markerDurations = new Map(); - let currentSlug: string | null = null; - let currentLines: string[] = []; - let summaryLineIndex = -1; - /** True between the summary marker and its JSON payload. */ - let summaryPayloadPending = false; - let beginMarkersSeen = 0; - let endMarkersSeen = 0; - let strayEndMarkers = 0; - /** Only one section can have lost its head: the one the log was cut inside. */ - let headSectionClaimed = false; - - // Matches " PASS|FAIL []" — slugs have no whitespace. - const endInnerPattern = /^(\S+)\s+(?:PASS|FAIL)(?:\s+(\d+))?$/; - - for (let i = 0; i < lines.length; i++) { - const trimmed = lines[i].trimEnd(); - - if (trimmed.startsWith(BEGIN_MARKER) && trimmed.endsWith('===')) { - currentSlug = trimmed.slice(BEGIN_MARKER.length, -3); - currentLines = []; - beginMarkersSeen++; - continue; - } - - if (trimmed.startsWith(END_MARKER) && trimmed.endsWith('===')) { - const inner = trimmed.slice(END_MARKER.length, -3); - endMarkersSeen++; - const match = endInnerPattern.exec(inner); - const endSlug = match ? match[1] : inner; - const durationStr = match?.[2]; - - // A section normally closes on the END matching its own BEGIN. - const closesOwnSection = endSlug === currentSlug; - - // Open Cloud keeps only the tail of a long run's log, so BEGIN — printed - // first — can be lost while END and the summary survive. Recovering that - // means letting an END with no open section claim what precedes it, but - // only where the head can actually have been dropped: before any BEGIN - // has survived, and only once. Past that point the log is well-formed, - // and a BEGIN-less END is a message delivered out of order (the API does - // not order them), which must not be allowed to claim another package's - // output. - const closesDroppedHead = - currentSlug === null && beginMarkersSeen === 0 && !headSectionClaimed; - - if (closesOwnSection || closesDroppedHead) { - logSections.set(endSlug, currentLines.join('\n')); - if (closesDroppedHead) { - partialSections.add(endSlug); - headSectionClaimed = true; - } - if (durationStr !== undefined) { - markerDurations.set(endSlug, parseInt(durationStr, 10)); - } - currentSlug = null; - currentLines = []; - } else { - // Reordered marker from another package. Ignore it without resetting - // state, so the section it interrupted still closes on its own END. - strayEndMarkers++; - } - continue; - } - - if (trimmed === SUMMARY_MARKER) { - // Keep scanning: the summary prints last but is not always delivered last, - // and a section's END can follow it. - if (summaryLineIndex < 0) { - summaryLineIndex = i; - } - summaryPayloadPending = true; - continue; - } - - // The summary's JSON payload belongs to no section. - if (summaryPayloadPending && trimmed.trimStart().startsWith('[')) { - summaryPayloadPending = false; - continue; - } - - // Accumulate unconditionally: output that precedes the first surviving - // BEGIN still belongs to whichever package's END closes it. - currentLines.push(lines[i]); - } + const tokens = tokenizeBatchLog(lines); + const { + sections: logSections, + partialSections, + markerDurations, + strayEndSlugs, + orphanedBeginSlugs, + } = foldTokensIntoSections(tokens); + + // Diagnostics are read back off the token list rather than counted alongside + // the fold, so nothing the warnings report can also steer the parse. + const beginMarkersSeen = tokensOfKind(tokens, 'begin').length; + const endMarkersSeen = tokensOfKind(tokens, 'end').length; + const summaryLineIndex = tokensOfKind(tokens, 'summary')[0]?.lineIndex ?? -1; + const unknownEndSlugs = [ + ...new Set( + tokensOfKind(tokens, 'end') + .map((token) => token.slug) + .filter((slug) => !slugToPackage.has(slug)) + ), + ]; // ── Pass 2: Parse the JSON summary for authoritative pcall results ── @@ -188,13 +173,32 @@ export function parseBatchTestLogs( // ── Warn when the batch produced no recognizable output ── - if (strayEndMarkers > 0) { + if (strayEndSlugs.length > 0) { OutputHelper.verbose( - `[batch-log-parser] Ignored ${strayEndMarkers} out-of-order END marker(s); ` + + `[batch-log-parser] Ignored ${strayEndSlugs.length} out-of-order END marker(s); ` + 'their sections closed on their own boundaries.' ); } + // Reported, not acted on: a slug the batch never asked for means the markers + // and the package list disagree, which no per-package verdict can express. + if (unknownEndSlugs.length > 0) { + OutputHelper.warn( + `[batch-log-parser] END marker(s) for slug(s) not in this batch: ` + + `${unknownEndSlugs.join(', ')}.` + ); + } + + if (orphanedBeginSlugs.length > 0) { + OutputHelper.warn( + `[batch-log-parser] ${orphanedBeginSlugs.length} section(s) reopened by a ` + + `second BEGIN before their own END arrived (${orphanedBeginSlugs.join( + ', ' + )}); ` + + 'the output collected so far was discarded.' + ); + } + const noOutputAtAll = logSections.size === 0 && summaryResults.size === 0; if (noOutputAtAll) { OutputHelper.warn( @@ -325,6 +329,177 @@ export function parseBatchTestLogs( return results; } +/** + * Classify every log line, so section splitting reads tokens instead of text. + */ +function tokenizeBatchLog(lines: string[]): BatchLogToken[] { + const tokens: BatchLogToken[] = []; + /** True between the summary marker and its JSON payload. */ + let summaryPayloadPending = false; + + for (let i = 0; i < lines.length; i++) { + const trimmed = lines[i].trimEnd(); + + if (trimmed.startsWith(BEGIN_MARKER) && trimmed.endsWith(MARKER_SUFFIX)) { + tokens.push({ + kind: 'begin', + slug: trimmed.slice(BEGIN_MARKER.length, -MARKER_SUFFIX.length), + }); + continue; + } + + if (trimmed.startsWith(END_MARKER) && trimmed.endsWith(MARKER_SUFFIX)) { + tokens.push( + parseEndToken(trimmed.slice(END_MARKER.length, -MARKER_SUFFIX.length)) + ); + continue; + } + + if (trimmed === SUMMARY_MARKER) { + // Keep scanning: the summary prints last but is not always delivered last, + // and a section's END can follow it. + tokens.push({ kind: 'summary', lineIndex: i }); + summaryPayloadPending = true; + continue; + } + + // The summary's JSON payload belongs to no section. + if (summaryPayloadPending && trimmed.trimStart().startsWith('[')) { + summaryPayloadPending = false; + tokens.push({ kind: 'summaryPayload' }); + continue; + } + + tokens.push({ kind: 'content', line: lines[i] }); + } + + return tokens; +} + +/** + * Read an END marker's inner text. + * + * The PASS|FAIL verdict and the duration are both optional, so inner text that + * does not parse is taken whole as the slug rather than dropped. + */ +function parseEndToken(inner: string): EndToken { + const match = END_INNER_PATTERN.exec(inner); + if (!match) { + return { kind: 'end', slug: inner }; + } + + const durationStr = match[2]; + return { + kind: 'end', + slug: match[1], + durationMs: + durationStr === undefined ? undefined : parseInt(durationStr, 10), + }; +} + +/** + * Fold tokens into per-package log sections. + * + * Sections close on END, not on the next BEGIN, because END is what survives: + * see the head-claiming rule below. + */ +function foldTokensIntoSections( + tokens: readonly BatchLogToken[] +): FoldedSections { + const sections = new Map(); + const partialSections = new Set(); + const markerDurations = new Map(); + const strayEndSlugs: string[] = []; + const orphanedBeginSlugs: string[] = []; + + let openSlug: string | null = null; + let openLines: string[] = []; + /** + * Whether the log can still be one whose head was dropped. + * + * Open Cloud keeps only the tail of a long run's log, so BEGIN — printed + * first — can be lost while END and the summary survive. Recovering that + * means letting an END with no open section claim what precedes it, but + * only where the head can actually have been dropped: before any BEGIN + * has survived, and only once. Past that point the log is well-formed, + * and a BEGIN-less END is a message delivered out of order (the API does + * not order them), which must not be allowed to claim another package's + * output. + */ + let headClaimable = true; + + for (const token of tokens) { + switch (token.kind) { + case 'begin': { + if (openSlug !== null) { + orphanedBeginSlugs.push(openSlug); + } + openSlug = token.slug; + openLines = []; + headClaimable = false; + break; + } + + case 'end': { + // A section normally closes on the END matching its own BEGIN. + const closesOwnSection = token.slug === openSlug; + // Mutually exclusive with the above: an unclaimed head means no BEGIN + // has arrived, so no section is open to match. + const closesDroppedHead = headClaimable; + + if (!closesOwnSection && !closesDroppedHead) { + // Reordered marker from another package. Ignore it without resetting + // state, so the section it interrupted still closes on its own END. + strayEndSlugs.push(token.slug); + break; + } + + sections.set(token.slug, openLines.join('\n')); + if (closesDroppedHead) { + partialSections.add(token.slug); + } + if (token.durationMs !== undefined) { + markerDurations.set(token.slug, token.durationMs); + } + openSlug = null; + openLines = []; + headClaimable = false; + break; + } + + case 'content': { + // Accumulate unconditionally: output that precedes the first surviving + // BEGIN still belongs to whichever package's END closes it. + openLines.push(token.line); + break; + } + + case 'summary': + case 'summaryPayload': { + break; + } + } + } + + return { + sections, + partialSections, + markerDurations, + strayEndSlugs, + orphanedBeginSlugs, + }; +} + +/** Select the tokens of one kind, for counting and reporting. */ +function tokensOfKind( + tokens: readonly BatchLogToken[], + kind: K +): Extract[] { + return tokens.filter( + (token): token is Extract => token.kind === kind + ); +} + /** * Find the summary array in the lines following the summary marker. *