From cfa701211a865f46a63a3a802e930fb0716d42ba Mon Sep 17 00:00:00 2001 From: Joyee Cheung Date: Fri, 3 Nov 2017 16:50:57 +0800 Subject: [PATCH] test: show lldb output when timing out --- test/common.js | 174 +++++++++++++++++++++++++++++++--------------- test/scan-test.js | 56 +++++++++++---- 2 files changed, 163 insertions(+), 67 deletions(-) diff --git a/test/common.js b/test/common.js index f420bd44..2316f017 100644 --- a/test/common.js +++ b/test/common.js @@ -11,7 +11,13 @@ exports.fixturesDir = path.join(__dirname, 'fixtures'); exports.buildDir = path.join(__dirname, '..', 'out', 'Release'); exports.core = path.join(os.tmpdir(), 'core'); -exports.ranges = exports.core + '.ranges'; + +function llnodeDebug(...args) { + console.error('[TEST]', ...args); +} + +const debug = exports.debug = + process.env.LLNODE_DEBUG ? llnodeDebug : () => { }; let pluginName; if (process.platform === 'darwin') @@ -22,13 +28,15 @@ else pluginName = path.join('lib.target', 'llnode.so'); exports.llnodePath = path.join(exports.buildDir, pluginName); +exports.saveCoreTimeout = 180 * 1000; +exports.loadCoreTimeout = 20 * 1000; -function SessionOutput(session, stream) { +function SessionOutput(session, stream, timeout) { EventEmitter.call(this); this.waiting = false; this.waitQueue = []; - let buf = ''; + this.timeout = timeout || 10000; stream.on('data', (data) => { buf += data; @@ -44,10 +52,8 @@ function SessionOutput(session, stream) { if (/process \d+ exited/i.test(line)) session.kill(); - else if (session.initialized) + else this.emit('line', line); - else if (/process \d+ launched/i.test(line)) - session.initialized = true; } }); @@ -72,20 +78,54 @@ SessionOutput.prototype._unqueueWait = function _unqueueWait() { this.waitQueue.shift()(); }; -SessionOutput.prototype.wait = function wait(regexp, callback) { - if (!this._queueWait(() => { this.wait(regexp, callback); })) +SessionOutput.prototype.timeoutAfter = function timeoutAfter(timeout) { + this.timeout = timeout; +} + +SessionOutput.prototype.wait = function wait(regexp, callback, allLines) { + if (!this._queueWait(() => { this.wait(regexp, callback, allLines); })) return; const self = this; - this.on('line', function onLine(line) { - if (!regexp.test(line)) + const lines = []; + + function onLine(line) { + lines.push(line); + debug('[LINE]', line); + + if (!regexp.test(line)) { return; + } self.removeListener('line', onLine); self._unqueueWait(); + done = true; - callback(line); - }); + callback(allLines ? lines : line); + } + + let done = false; + let timePassed = 0; + const interval = 100; + const check = setInterval(() => { + timePassed += interval; + if (done) { + clearInterval(check); + } + + if (timePassed > self.timeout) { + self.removeListener('line', onLine); + self._unqueueWait(); + const message = `Test timeout in ${this.timeout} ` + + `waiting for ${regexp}\n` + + `\n${'='.repeat(10)} lldb output ${'='.repeat(10)}\n` + + `\n${lines.join('\n')}` + + `\n${'='.repeat(30)}\n`; + throw new Error(message); + } + }, interval); + + this.on('line', onLine); }; SessionOutput.prototype.waitBreak = function waitBreak(callback) { @@ -93,59 +133,80 @@ SessionOutput.prototype.waitBreak = function waitBreak(callback) { }; SessionOutput.prototype.linesUntil = function linesUntil(regexp, callback) { - if (!this._queueWait(() => { this.linesUntil(regexp, callback); })) - return; - - const lines = []; - const self = this; - this.on('line', function onLine(line) { - lines.push(line); - - if (!regexp.test(line)) - return; - - self.removeListener('line', onLine); - self._unqueueWait(); - - callback(lines); - }); + this.wait(regexp, callback, true); }; - -function Session(scenario) { +function Session(options) { EventEmitter.call(this); + const timeout = parseInt(process.env.TEST_TIMEOUT) || 10000; + const lldbBin = process.env.TEST_LLDB_BINARY || 'lldb'; + const env = Object.assign({}, process.env); - // lldb -- node scenario.js - this.lldb = spawn(process.env.TEST_LLDB_BINARY || 'lldb', [ - '--', - process.execPath, - '--abort_on_uncaught_exception', - '--expose_externalize_string', - path.join(exports.fixturesDir, scenario) - ], { - stdio: [ 'pipe', 'pipe', 'pipe' ], - env: util._extend(util._extend({}, process.env), { - LLNODE_RANGESFILE: exports.ranges - }) - }); + if (options.ranges) { + env.LLNODE_RANGESFILE = options.ranges; + } - this.lldb.stdin.write(`plugin load "${exports.llnodePath}"\n`); - this.lldb.stdin.write('run\n'); + debug('lldb binary:', lldbBin); + if (options.scenario) { + this.needToKill = true; + // lldb -- node scenario.js + const args = [ + '--', + process.execPath, + '--abort_on_uncaught_exception', + '--expose_externalize_string', + path.join(exports.fixturesDir, options.scenario) + ]; + + debug('lldb args:', args); + this.lldb = spawn(lldbBin, args, { + stdio: ['pipe', 'pipe', 'pipe'], + env: env + }); + this.lldb.stdin.write(`plugin load "${exports.llnodePath}"\n`); + this.lldb.stdin.write('run\n'); + } else if (options.core) { + this.needToKill = false; + debug('loading core', options.core) + // lldb node -c core + this.lldb = spawn(lldbBin, [], { + stdio: ['pipe', 'pipe', 'pipe'], + env: env + }); + this.lldb.stdin.write(`plugin load "${exports.llnodePath}"\n`); + this.lldb.stdin.write(`target create "${options.executable}"` + + ` --core "${options.core}"\n`); + } + this.stdout = new SessionOutput(this, this.lldb.stdout, timeout); + this.stderr = new SessionOutput(this, this.lldb.stderr, timeout); - this.initialized = false; - this.stdout = new SessionOutput(this, this.lldb.stdout); - this.stderr = new SessionOutput(this, this.lldb.stderr); + this.stderr.on('line', (line) => { + debug('[stderr]', line); + }); // Map these methods to stdout for compatibility with legacy tests. this.wait = SessionOutput.prototype.wait.bind(this.stdout); this.waitBreak = SessionOutput.prototype.waitBreak.bind(this.stdout); this.linesUntil = SessionOutput.prototype.linesUntil.bind(this.stdout); + this.timeoutAfter = SessionOutput.prototype.timeoutAfter.bind(this.stdout); } util.inherits(Session, EventEmitter); exports.Session = Session; Session.create = function create(scenario) { - return new Session(scenario); + return new Session({ scenario: scenario }); +}; + +Session.loadCore = function loadCore(executable, core, ranges) { + return new Session({ + executable: executable, + core: core, + ranges: ranges + }); +} + +Session.prototype.waitCoreLoad = function waitCoreLoad(callback) { + this.wait(/Core file[^\n]+was loaded/, callback); }; Session.prototype.kill = function kill() { @@ -154,27 +215,30 @@ Session.prototype.kill = function kill() { }; Session.prototype.quit = function quit() { - this.send('kill'); + if (this.needToKill) { + this.send('kill'); + } this.send('quit'); }; Session.prototype.send = function send(line, callback) { + debug('[SEND]', line); this.lldb.stdin.write(line + '\n', callback); }; - -exports.generateRanges = function generateRanges(cb) { +exports.generateRanges = function generateRanges(core, dest, cb) { let script; if (process.platform === 'darwin') script = path.join(__dirname, '..', 'scripts', 'otool2segments.py'); else script = path.join(__dirname, '..', 'scripts', 'readelf2segments.py'); - const proc = spawn(script, [ exports.core ], { - stdio: [ null, 'pipe', 'inherit' ] + debug('[RANGES]', `${script}, ${core}, ${dest}`); + const proc = spawn(script, [core], { + stdio: [null, 'pipe', 'inherit'] }); - proc.stdout.pipe(fs.createWriteStream(exports.ranges)); + proc.stdout.pipe(fs.createWriteStream(dest)); proc.on('exit', (status) => { cb(status === 0 ? null : new Error('Failed to generate ranges')); diff --git a/test/scan-test.js b/test/scan-test.js index 496c3f58..36ce9606 100644 --- a/test/scan-test.js +++ b/test/scan-test.js @@ -1,5 +1,6 @@ 'use strict'; +const util = require('util'); // No `process save-core` on linuxes :( if (process.platform !== 'darwin') return; @@ -9,9 +10,24 @@ const tape = require('tape'); const common = require('./common'); tape('v8 findrefs and friends', (t) => { - t.timeoutAfter(90000); + t.timeoutAfter(common.saveCoreTimeout); + + // Use prepared core and executable to test + if (process.env.LLNODE_CORE && process.env.LLNODE_NODE_EXE) { + test(process.env.LLNODE_NODE_EXE, process.env.LLNODE_CORE, t); + } else { + if (process.platform === 'linux') { + t.skip('No `process save-core` on linux'); + t.end(); + } else { + saveCoreAndTest(t); + } + } +}); - const sess = common.Session.create('inspect-scenario.js'); +function saveCoreAndTest(t) { + // Create a core and test + const sess = common.Session.create('inspect-scenario.js'); sess.timeoutAfter(common.saveCoreTimeout); sess.waitBreak(() => { sess.send(`process save-core ${common.core}`); @@ -21,22 +37,38 @@ tape('v8 findrefs and friends', (t) => { sess.wait(/lldb\-/, () => { t.ok(true, 'Saved core'); + sess.send('target delete 0'); + sess.quit(); - sess.send(`target create -c ${common.core}`); + test(process.execPath, common.core, t); }); - - sess.wait(/Core file[^\n]+was loaded/, () => { +} + +function test(executable, core, t) { + let sess, ranges; + if (process.env.LLNODE_NO_RANGES) { + sess = common.Session.loadCore(executable, core); + } else { + ranges = core + '.ranges'; + sess = common.Session.loadCore(executable, core, ranges); + } + sess.timeoutAfter(common.loadCoreTimeout); + + sess.waitCoreLoad(() => { t.ok(true, 'Loaded core'); - common.generateRanges((err) => { - t.error(err, 'generateRanges'); + if (ranges) { + common.generateRanges(core, ranges, (err) => { + t.error(err, 'generateRanges'); + t.ok(true, 'Generated ranges'); + sess.send('version'); + }) + } else { sess.send('version'); - }); + } }); sess.wait(/lldb\-/, () => { - t.ok(true, 'Generated ranges'); - sess.send('v8 findjsobjects'); // Just a separator sess.send('version'); @@ -79,8 +111,8 @@ tape('v8 findrefs and friends', (t) => { t.ok(/Object\.holder/.test(lines.join('\n')), 'Should find reference #2'); t.ok(/\(Array\)\[1\]/.test(lines.join('\n')), 'Should find reference #3'); - sess.send('target delete 1'); + sess.send('target delete 0'); sess.quit(); t.end(); }); -}); +}