diff --git a/build/commands/lib/buildDiagnostics.test.ts b/build/commands/lib/buildDiagnostics.test.ts new file mode 100644 index 00000000000..66cb8130d63 --- /dev/null +++ b/build/commands/lib/buildDiagnostics.test.ts @@ -0,0 +1,99 @@ +// Copyright (c) 2026 The Brave Authors. All rights reserved. +// This Source Code Form is subject to the terms of the Mozilla Public +// License, v. 2.0. If a copy of the MPL was not distributed with this file, +// You can obtain one at https://mozilla.org/MPL/2.0/. + +import fs from 'node:fs' +import os from 'node:os' +import path from 'node:path' +import { dumpBuildHangDiagnostics } from './buildDiagnostics.ts' +import Log from './logging.js' + +jest.mock('./logging.js', () => ({ + error: jest.fn(), +})) + +describe('dumpBuildHangDiagnostics', () => { + let tempDir: string + let consoleLogSpy: jest.SpyInstance + + beforeEach(() => { + tempDir = fs.mkdtempSync(path.join(os.tmpdir(), 'ci-diagnostics-')) + consoleLogSpy = jest.spyOn(console, 'log').mockImplementation(() => {}) + jest.clearAllMocks() + }) + + afterEach(() => { + consoleLogSpy.mockRestore() + jest.restoreAllMocks() + fs.rmSync(tempDir, { recursive: true, force: true }) + }) + + it('logs the contents of an existing diagnostics file', () => { + const diagPath = path.join(tempDir, 'siso.INFO') + fs.writeFileSync(diagPath, 'first line\nsecond line\n', 'utf8') + + dumpBuildHangDiagnostics(tempDir) + + expect(consoleLogSpy).toHaveBeenCalledWith(`--- tail of ${diagPath} ---`) + expect(consoleLogSpy).toHaveBeenCalledWith('first line\nsecond line\n') + expect(Log.error).not.toHaveBeenCalled() + }) + + it('reads a redirected diagnostics file when the local file is missing', () => { + const redirectedTarget = path.join(tempDir, 'redirect-target.INFO') + const redirectedMarker = path.join(tempDir, 'siso.exe.INFO.redirected') + fs.writeFileSync(redirectedTarget, 'redirected output\n', 'utf8') + fs.writeFileSync(redirectedMarker, `${redirectedTarget}\n`, 'utf8') + + dumpBuildHangDiagnostics(tempDir) + + expect(consoleLogSpy).toHaveBeenCalledWith( + `--- tail of ${redirectedTarget} ---`, + ) + expect(consoleLogSpy).toHaveBeenCalledWith('redirected output\n') + expect(Log.error).not.toHaveBeenCalled() + }) + + it('logs an error when a redirected target does not exist', () => { + const redirectedTarget = path.join(tempDir, 'missing.INFO') + const redirectedMarker = path.join(tempDir, 'siso_output.redirected') + fs.writeFileSync(redirectedMarker, redirectedTarget, 'utf8') + + dumpBuildHangDiagnostics(tempDir) + + expect(Log.error).toHaveBeenCalledWith( + `Redirected file ${redirectedTarget} does not exist`, + ) + expect(consoleLogSpy).not.toHaveBeenCalled() + }) + + it('logs read errors without throwing', () => { + const diagPath = path.join(tempDir, 'siso.INFO') + fs.writeFileSync(diagPath, 'content that will not be read', 'utf8') + + const realFs = jest.requireActual('node:fs') as typeof import('node:fs') + jest.spyOn(fs, 'openSync').mockImplementation((...args) => { + if (args[0] === diagPath) { + throw new Error('open failed') + } + return realFs.openSync(...args) + }) + + dumpBuildHangDiagnostics(tempDir) + + expect(consoleLogSpy).toHaveBeenCalledWith(`--- tail of ${diagPath} ---`) + expect(Log.error).toHaveBeenCalledWith('open failed') + }) + + it('prints only the final complete lines for oversized files', () => { + const diagPath = path.join(tempDir, 'siso.INFO') + const content = `${'a'.repeat(130 * 1024)}\nkept line 1\nkept line 2\n` + fs.writeFileSync(diagPath, content, 'utf8') + + dumpBuildHangDiagnostics(tempDir) + + expect(consoleLogSpy).toHaveBeenCalledWith('kept line 1\nkept line 2\n') + expect(Log.error).not.toHaveBeenCalled() + }) +}) diff --git a/build/commands/lib/buildDiagnostics.ts b/build/commands/lib/buildDiagnostics.ts new file mode 100644 index 00000000000..7989b38b3ac --- /dev/null +++ b/build/commands/lib/buildDiagnostics.ts @@ -0,0 +1,71 @@ +// Copyright (c) 2026 The Brave Authors. All rights reserved. +// This Source Code Form is subject to the terms of the Mozilla Public +// License, v. 2.0. If a copy of the MPL was not distributed with this file, +// You can obtain one at https://mozilla.org/MPL/2.0/. + +import fs from 'node:fs' +import path from 'node:path' +import Log from './logging.js' + +const kReadFileTailLimitBytes = 128 * 1024 + +/** + * Dumps the hanged build diagnostics for a build. + * @param {string} outputDir + */ +export function dumpBuildHangDiagnostics(outputDir: string) { + const relativePaths = ['siso.INFO', 'siso.exe.INFO', 'siso_output'] + for (const rel of relativePaths) { + let filePath = path.join(outputDir, rel) + if (!fs.existsSync(filePath)) { + const filePathRedirected = path.join(outputDir, rel + '.redirected') + if (fs.existsSync(filePathRedirected)) { + // read the redirected file and get the path + const redirectedContent = fs.readFileSync(filePathRedirected, 'utf8') + const redirectedPath = redirectedContent.trim() + if (fs.existsSync(redirectedPath)) { + filePath = redirectedPath + } else { + Log.error(`Redirected file ${redirectedPath} does not exist`) + continue + } + } else { + continue + } + } + console.log(`--- tail of ${filePath} ---`) + try { + console.log(readFileTailUtf8Sync(filePath, kReadFileTailLimitBytes)) + } catch (err) { + Log.error(err instanceof Error ? err.message : String(err)) + } + } +} + +/** + * Reads only the last `maxBytes` bytes from a file. + */ +function readFileTailUtf8Sync(filePath: string, maxBytes: number): string { + const fd = fs.openSync(filePath, 'r') + try { + const size = fs.fstatSync(fd).size + if (size === 0) { + return '' + } + const toRead = Math.min(maxBytes, size) + const buf = Buffer.alloc(toRead) + fs.readSync(fd, buf, 0, toRead, size - toRead) + // May start mid-sequence for UTF-8; Node replaces invalid bytes at slice + // edge. + let str = buf.toString('utf8') + if (toRead < size) { + const nl = str.indexOf('\n') + if (nl !== -1) { + str = str.slice(nl + 1) + } + } + return str + } finally { + fs.closeSync(fd) + } +} diff --git a/build/commands/lib/util.js b/build/commands/lib/util.js index 4d4b1f82a72..cb4c39fca61 100644 --- a/build/commands/lib/util.js +++ b/build/commands/lib/util.js @@ -18,6 +18,7 @@ import ActionGuard from './actionGuard.js' import { GitPatcher } from './gitPatcher.js' import { getBuildArgs } from './buildArgs.ts' import { isCI, isTeamcity } from './ciDetect.ts' +import { dumpBuildHangDiagnostics } from './buildDiagnostics.ts' // Do not limit the number of listeners to avoid warnings from EventEmitter. process.setMaxListeners(0) @@ -228,13 +229,22 @@ const util = { args = [], options = /** @type {Record} */ ({}), ) => { - let { continueOnFail, verbose, onStdErrLine, onStdOutLine, ...cmdOptions } = - options + let { + continueOnFail, + verbose, + onSpawn, + onStdErrLine, + onStdOutLine, + ...cmdOptions + } = options if (verbose !== false) { Log.command(cmdOptions.cwd, cmd, args) } return new Promise((resolve, reject) => { const prog = spawn(...normalizeCommand(cmd, args), cmdOptions) + if (onSpawn) { + onSpawn(prog) + } const signalsToForward = ['SIGINT', 'SIGTERM', 'SIGQUIT', 'SIGHUP'] const signalHandler = (s) => { prog.kill(s) @@ -708,11 +718,14 @@ const util = { // Collect build statistics into this variable to display in a separate TC // block. let buildStats = '' + // Updated on every autoninja log line when CI pipes output (idle watchdog). + let lastBuildLogTime = Date.now() // Parse output to display the build progress on Teamcity. if (isTeamcity) { let lastStatusTime = Date.now() options.onStdOutLine = (line) => { + lastBuildLogTime = Date.now() if ( buildStats || /^(RBE Stats:|metric\s+count|build finished)\s+/.test(line) @@ -732,6 +745,14 @@ const util = { } options.onStdErrLine = options.onStdOutLine options.stdio = 'pipe' + } else if (isCI) { + const onLine = (line) => { + lastBuildLogTime = Date.now() + console.log(line) + } + options.onStdOutLine = onLine + options.onStdErrLine = onLine + options.stdio = 'pipe' } // Enable to allow error post-processing after autoninja/siso failure. @@ -743,6 +764,14 @@ const util = { fs.unlinkSync(sisoOutputFile) } + let buildIdleWatchdogInterval = null + const clearBuildIdleWatchdog = () => { + if (buildIdleWatchdogInterval) { + clearInterval(buildIdleWatchdogInterval) + buildIdleWatchdogInterval = null + } + } + const buildGuard = new ActionGuard(path.join(outputDir, 'build.guard')) try { if ( @@ -755,9 +784,36 @@ const util = { await util.runAsync('gn', ['clean', outputDir], options) } buildGuard.markStarted() - await util.runAsync('autoninja', ninjaOpts, options) + + let buildProcess = null + const autoninjaOptions = { + ...options, + onSpawn: (prog) => { + buildProcess = prog + }, + } + + if (isCI) { + const idleTimeoutMs = 90 * 60 * 1000 // 90 minutes + lastBuildLogTime = Date.now() + buildIdleWatchdogInterval = setInterval(() => { + if (Date.now() - lastBuildLogTime <= idleTimeoutMs) { + return + } + clearBuildIdleWatchdog() + Log.error( + `Build aborted: no autoninja output for ${idleTimeoutMs / 1000}s `, + ) + dumpBuildHangDiagnostics(outputDir) + util.killProcessTree(buildProcess) + }, 10 * 1000) + } + + await util.runAsync('autoninja', ninjaOpts, autoninjaOptions) + clearBuildIdleWatchdog() buildGuard.markFinished() } catch (e) { + clearBuildIdleWatchdog() // Display siso_output on CI after a build failure. if (isCI && fs.existsSync(sisoOutputFile)) { const sisoOutput = fs.readFileSync(sisoOutputFile, 'utf8') @@ -1029,6 +1085,29 @@ const util = { config.defaultOptions, ) }, + + /** + * Stop a process and its descendants. On Windows, `child.kill()` often only + * affects `cmd.exe`; `taskkill /T` tears down the full tree. + * @param {import('node:child_process').ChildProcess | null} child + */ + killProcessTree: (child) => { + if (!child?.pid) { + return + } + if (process.platform === 'win32') { + spawnSync('taskkill', ['/PID', String(child.pid), '/T', '/F'], { + stdio: 'ignore', + windowsHide: true, + }) + return + } + try { + child.kill('SIGKILL') + } catch { + // Process may already have exited. + } + }, } export default util