chore(test): improve log output on error

test/common.js

@@ -64,8 +64,15 @@ function startFixtureProcess(t, withInspector = false, port = '0') {
     execArgv.push('--inspect');
   }
   const child = fork('./test/fixtures/default-program.js', { execArgv, silent: true});
+  let output = '';
+  child.stdout.setEncoding('utf-8');
+  child.stdout.on('data', (data) => output += `[${ child.pid }][stdout] ${ data }`);
+  child.stderr.setEncoding('utf-8');
+  child.stderr.on('data', (data) => output += `[${ child.pid }][stderr] ${ data }`);
   const fixture = new FixtureProcess(child);
   fixture.on('timeout', t.fail);
+  t.once('result', ({ ok }) => { if (!ok) { console.log(output) } });
+  t.teardown(() => fixture.exit());
   return fixture;
 }
 
@@ -128,6 +135,7 @@ class FixtureProcess extends EventEmitter {
     super();
     this._p = p;
     this.pid = p.pid;
+    this.exited = false;
     this._backlog = {};
     p.on('message', ({ event, payload }) => {
       payload = payload || {};
@@ -152,6 +160,16 @@ class FixtureProcess extends EventEmitter {
   send(event, payload = {}) {
     this._p.send({ event, payload });
   }
+
+  exit() {
+    // I'm not sure this is the best way to handle this, but there is one test
+    // that needs to call exit(), but we want to have teardown() run it for
+    // every other test
+    if (!this.exited) {
+      this.exited = true;
+      this.send('exit');
+    }
+  }
 }
 
 function validateCpuProfile({ nodes, startTime, endTime, samples, timeDeltas }) {

test/test-cpu-profile.js

@@ -21,7 +21,6 @@ test('take cpu profile', (t) => {
     t.notEqual(stream.data.length, 0);
     const result = JSON.parse(stream.data);
     t.ok(validateCpuProfile(result));
-    f.send('exit');
     t.end();
   });
 });
@@ -37,7 +36,6 @@ test('take cpu profile with duration', (t) => {
     const result = JSON.parse(stream.data);
     t.ok(validateCpuProfile(result));
 
-    f.send('exit');
     t.end();
   });
 });
@@ -58,7 +56,6 @@ test('take cpu profile with samplingInterval', (t) => {
     // samples will be captured.
     t.ok(samples1.length * 3 < samples2.length);
 
-    f.send('exit');
     t.end();
   });
 });

test/test-executables.js

@@ -19,7 +19,6 @@ test('observe heap-profile', async (t) => {
     t.notEqual(head, undefined);
     const { callFrame } = head;
     t.notEqual(callFrame, undefined);
-    f.send('exit');
     t.end();
   });
 });
@@ -33,7 +32,6 @@ test('observe heap-profile to file', async (t) => {
     t.notEqual(head, undefined);
     const { callFrame } = head;
     t.notEqual(callFrame, undefined);
-    f.send('exit');
     t.end();
   });
 });
@@ -49,7 +47,6 @@ test('observe heap-snapshot', async (t) => {
     t.notEqual(nodes, undefined);
     t.notEqual(edges, undefined);
     t.notEqual(strings, undefined);
-    f.send('exit');
     t.end();
   });
 });
@@ -65,7 +62,6 @@ test('observe heap-snapshot to file', async (t) => {
     t.notEqual(nodes, undefined);
     t.notEqual(edges, undefined);
     t.notEqual(strings, undefined);
-    f.send('exit');
     t.end();
   });
 });
@@ -77,7 +73,6 @@ test('observe cpu-profile', async (t) => {
     const options = { pid: f.pid, port, options: ['-d', 1]};
     const result = await runObserveExecutable('cpu-profile', options);
     t.ok(validateCpuProfile(result));
-    f.send('exit');
     t.end();
   });
 });
@@ -89,7 +84,6 @@ test('observe cpu-profile to file', async (t) => {
     const options = { pid: f.pid, port, toFile: true, options: ['-d', 1]};
     const result = await runObserveExecutable('cpu-profile', options);
     t.ok(validateCpuProfile(result));
-    f.send('exit');
     t.end();
   });
 });
@@ -103,7 +97,6 @@ test('observe --close', async (t) => {
     setTimeout(async () => {
       t.notOk(await isPortInUse(port));
       t.ok(validateCpuProfile(result));
-      f.send('exit');
       t.end();
     }, 500);
   });

test/test-heap-profile.js

@@ -23,7 +23,6 @@ test('take heap profile', (t) => {
     t.notEqual(head, undefined);
     const { callFrame } = head;
     t.notEqual(callFrame, undefined);
-    f.send('exit');
     t.end();
   });
 });
@@ -41,7 +40,6 @@ test('take heap profile with duration', (t) => {
     const { callFrame } = head;
     t.notEqual(callFrame, undefined);
 
-    f.send('exit');
     t.end();
   });
 });
@@ -61,7 +59,6 @@ test('take heap profile with samplingInterval', (t) => {
     // is a grouped profile format.
     t.ok(stream1.data.length * 3 < stream2.data.length);
 
-    f.send('exit');
     t.end();
   });
 });

test/test-heap-snapshot.js

@@ -17,7 +17,6 @@ test('take heap snapshot', (t) => {
     t.notEqual(nodes, undefined);
     t.notEqual(edges, undefined);
     t.notEqual(strings, undefined);
-    f.send('exit');
     t.end();
   });
 });

test/test-inspector-client.js

@@ -14,7 +14,6 @@ test('attach to existing process', (t) => {
     try {
       await client.connect();
       await client.disconnect();
-      f.send('exit');
       t.end();
     } catch (e) {
       t.fail(e.toString())
@@ -33,7 +32,6 @@ test('send message', (t) => {
       t.deepEqual(await client.post('Profiler.enable'), {});
       t.deepEqual(await client.post('Profiler.disable', {}), {});
       await client.disconnect();
-      f.send('exit');
       t.end();
     } catch (e) {
       t.fail(e.toString())
@@ -56,7 +54,6 @@ test('receive message', (t) => {
       });
       client.on('Debugger.resumed', async () => {
         await client.disconnect();
-        f.send('exit');
         t.end();
       });
       t.deepEqual(await client.post('Debugger.pause', {}), {});

test/test-utils.js

@@ -13,14 +13,13 @@ test('attach to existing process', (t) => {
   }));
 
   f.on('inspectorReady', () => {
-    f.send('exit');
     t.end();
   });
 });
 
 test('attach to non-existing process', (t) => {
   const f = startFixtureProcess(t);
-  f.on('ready', () => f.send('exit'));
+  f.on('ready', () => f.exit());
 
   // TODO(mmarchini): There's probably a better way to do this.
   f._p.on('close', () => {