Add support for asynchronous assertions through logging

Author: Avaq

lib/doctest.js

@@ -75,12 +75,14 @@ module.exports = function(path, options) {
     console.log (source.replace (/\n$/, ''));
     return Promise.resolve ([]);
   } else if (options.silent) {
-    return Promise.resolve (evaluate (options.module, source, path));
+    return evaluate (options.module, source, path);
   } else {
     console.log ('running doctests in ' + path + '...');
-    var results = evaluate (options.module, source, path);
-    log (results);
-    return Promise.resolve (results);
+    return (evaluate (options.module, source, path))
+      .then (function(results) {
+        log (results);
+        return results;
+      });
   }
 };
 
@@ -164,6 +166,9 @@ var CLOSED = 'closed';
 var OPEN = 'open';
 var INPUT = 'input';
 var OUTPUT = 'output';
+var LOG = 'log';
+
+var MATCH_LOG = /^\[([a-zA-Z]+)\]:/;
 
 //  normalizeTest :: { output :: { value :: String } } -> Undefined
 function normalizeTest($test) {
@@ -201,16 +206,36 @@ function processLine(
       accum.tests.push ($test = {});
       $test[accum.state = INPUT] = {value: value};
       input ($test);
-    } else if (trimmedLine.charAt (0) === '.') {
+    } else if (accum.state === INPUT && trimmedLine.charAt (0) === '.') {
+      value = stripLeading (1, ' ', stripLeading (Infinity, '.', trimmedLine));
+      $test = accum.tests[accum.tests.length - 1];
+      $test[INPUT].value += '\n' + value;
+      appendToInput ($test);
+    } else if (accum.state === OUTPUT && trimmedLine.charAt (0) === '.') {
       value = stripLeading (1, ' ', stripLeading (Infinity, '.', trimmedLine));
       $test = accum.tests[accum.tests.length - 1];
-      $test[accum.state].value += '\n' + value;
-      (accum.state === INPUT ? appendToInput : appendToOutput) ($test);
-    } else if (accum.state === INPUT) {
+      $test[OUTPUT][$test[OUTPUT].length - 1].value += '\n' + value;
+      appendToOutput ($test);
+    } else if (MATCH_LOG.test (trimmedLine)) {
+      value = stripLeading (1, ' ', trimmedLine.replace (MATCH_LOG, ''));
+      $test = accum.tests[accum.tests.length - 1];
+      ($test[accum.state = OUTPUT] = $test[accum.state] || []).push ({
+        channel: MATCH_LOG.exec (trimmedLine)[1],
+        value: value
+      });
+      if ($test[OUTPUT].length === 1) {
+        output ($test);
+      }
+    } else {
       value = trimmedLine;
       $test = accum.tests[accum.tests.length - 1];
-      $test[accum.state = OUTPUT] = {value: value};
-      output ($test);
+      ($test[accum.state = OUTPUT] = $test[accum.state] || []).push ({
+        channel: null,
+        value: value
+      });
+      if ($test[OUTPUT].length === 1) {
+        output ($test);
+      }
     }
   }
 }
@@ -335,7 +360,9 @@ function wrap$js(test, sourceType) {
       '  ":": ' + test[OUTPUT].loc.start.line + ',',
       '  "!": ' + test['!'] + ',',
       '  thunk: function() {',
-      '    return ' + test[OUTPUT].value + ';',
+      '    return ' + test[OUTPUT].map (function(out) {
+        return '{channel: "' + out.channel + '", value: ' + out.value + '}';
+      }) + ';',
       '  }',
       '});'
     ]).join ('\n');
@@ -526,47 +553,59 @@ function commonjsEval(source, path) {
   return run (queue);
 }
 
-function run(queue) {
-  return queue.reduce (function(accum, io) {
-    var thunk = accum.thunk;
-    if (io.type === INPUT) {
-      if (thunk != null) thunk ();
-      accum.thunk = io.thunk;
-    } else if (io.type === OUTPUT) {
-      var either;
-      try {
-        either = {tag: 'Right', value: thunk ()};
-      } catch (err) {
-        either = {tag: 'Left', value: err};
-      }
-      accum.thunk = null;
-      var expected = io.thunk ();
-
-      var pass, repr;
-      if (either.tag === 'Left') {
-        var name = either.value.name;
-        var message = either.value.message;
-        pass = io['!'] &&
-               name === expected.name &&
-               message === expected.message.replace (/^$/, message);
-        repr = '! ' + name +
-               (expected.message && message.replace (/^(?!$)/, ': '));
-      } else {
-        pass = !io['!'] && Z.equals (either.value, expected);
-        repr = show (either.value);
-      }
+function run(queue, logMediator) {
+  return queue.reduce (function(p, io) {
+    return p.then (function(accum) {
+      var thunk = accum.thunk;
+      if (io.type === INPUT) {
+        if (thunk != null) thunk ();
+        accum.thunk = io.thunk;
+      } else if (io.type === OUTPUT) {
+        var either;
+        var expected = io.thunk ();
+
+        accum.thunk = null;
+
+        // Instead of calling the io thunk straight away, we register
+        // the appropriate listener on logMediator beforehand, to catch any
+        // synchronous log calls the thunk might make.
+        try {
+          either = {tag: 'Right', value: thunk ()};
+        } catch (err) {
+          either = {tag: 'Left', value: err};
+        }
 
-      accum.results.push ([
-        pass,
-        repr,
-        io['!'] ?
-          '! ' + expected.name + expected.message.replace (/^(?!$)/, ': ') :
-          show (expected),
-        io[':']
-      ]);
-    }
-    return accum;
-  }, {results: [], thunk: null}).results;
+        // Instead of just analyzing a single output on a single channel,
+        // we compare output on al channels, in the order indicated by the
+        // user.
+        var pass, repr;
+        if (either.tag === 'Left') {
+          var name = either.value.name;
+          var message = either.value.message;
+          pass = io['!'] &&
+                 name === expected.name &&
+                 message === expected.message.replace (/^$/, message);
+          repr = '! ' + name +
+                 (expected.message && message.replace (/^(?!$)/, ': '));
+        } else {
+          pass = !io['!'] && Z.equals (either.value, expected);
+          repr = show (either.value);
+        }
+
+        accum.results.push ([
+          pass,
+          repr,
+          io['!'] ?
+            '! ' + expected.name + expected.message.replace (/^(?!$)/, ': ') :
+            show (expected),
+          io[':']
+        ]);
+      }
+      return accum;
+    });
+  }, Promise.resolve ({results: [], thunk: null})).then (function(reduced) {
+    return reduced.results;
+  });
 }
 
 module.exports.run = run;

lib/doctest.mjs

@@ -22,7 +22,8 @@ export default async function(path, options) {
       common.sanitizeFileContents (
         await util.promisify (fs.readFile) (path, 'utf8')
       )
-    )
+    ),
+    options.logFunction
   );
 
   if (options.print) {
@@ -39,15 +40,20 @@ export default async function(path, options) {
   }
 }
 
-function wrap(source) {
+function wrap(source, logFunction) {
   return common.unlines ([
     'export const __doctest = {',
     '  queue: [],',
-    '  enqueue: function(io) { this.queue.push(io); }',
+    '  enqueue: function(io) { this.queue.push(io); },',
+    '  logMediator: {emit: function(){}}',
     '};',
-    '',
-    source
-  ]);
+    ''
+  ]) + (logFunction != null ? common.unlines ([
+    'const ' + logFunction + ' = tag => value => {',
+    '  __doctest.logMediator.emit ({tag, value});',
+    '};',
+    ''
+  ]) : []) + (source);
 }
 
 function evaluate(source, path) {
@@ -64,7 +70,10 @@ function evaluate(source, path) {
 
   return (util.promisify (fs.writeFile) (abspath, source))
     .then (function() { return import (abspath); })
-    .then (function(module) { return doctest.run (module.__doctest.queue); })
+    .then (function(module) {
+      return doctest.run (module.__doctest.queue,
+                          module.__doctest.logMediator);
+    })
     .then (cleanup (Promise.resolve.bind (Promise)),
            cleanup (Promise.reject.bind (Promise)));
 }

lib/program.js

@@ -18,6 +18,11 @@ program
          'specify line preceding doctest block (e.g. "```javascript")')
 .option ('    --closing-delimiter <delimiter>',
          'specify line following doctest block (e.g. "```")')
+.option ('    --log-function <name>',
+         'enable log output assertions')
+.option ('    --log-timeout <milliseconds>',
+         'specify an alternative log timeout time (defaults to 100)',
+         100)
 .option ('-p, --print',
          'output the rewritten source without running tests')
 .option ('-s, --silent',