fix: sequence console.log() calls

Author: rvagg

lib/log.js

@@ -3,6 +3,8 @@ import colors from 'ansi-colors'
 import stripAnsi from 'strip-ansi'
 
 const tty = process.stdout.isTTY && process.stderr.isTTY
+let logQueue = []
+let logSeq = -1
 
 function brand (error) {
   const brand = 'polendina ☞'
@@ -20,11 +22,40 @@ export function error (msg) {
   console.log(`  ${brand(true)}   ${tty ? colors.gray.italic(msg) : msg}`)
 }
 
-export function logRaw (type, args) {
+export function logRaw (type, seq, args) {
   if (!tty) {
     args = args.map((a) => typeof a === 'string' ? stripAnsi(a) : a)
   }
-  console[type === 'info' ? 'log' : type].apply(null, args)
+  logQueue.push({
+    type: type === 'info' ? 'log' : type,
+    args,
+    seq
+  })
+  flushLogs(false)
+}
+
+export function flushLogs (force) {
+  while (true) {
+    const lastLen = logQueue.length
+    logQueue = logQueue.filter((le) => {
+      const next = le.seq === -1 || le.seq === logSeq + 1
+      if (force || next) {
+        console[le.type].apply(null, le.args)
+        if (le.seq !== -1) {
+          logSeq++
+        }
+      } else if (le.seq < logSeq) {
+        throw new Error(`Unexpected log output sequencing (${le.seq}<${logSeq})`)
+      }
+      return !next
+    })
+    if (lastLen === logQueue.length) {
+      break
+    }
+  }
+  if (force) {
+    logSeq = -1
+  }
 }
 
 export function logWrite (args) {

lib/puppeteer.js

@@ -2,7 +2,7 @@ import puppeteer from 'puppeteer'
 // TODO
 // const pti = require('puppeteer-to-istanbul')
 // const { copyFile } = require('fs').promises
-import { log, error, logRaw, logWrite } from './log.js'
+import { log, error, logRaw, logWrite, flushLogs } from './log.js'
 
 // wrap our convoluted _run() function in a pure Promise that can handle
 // both standard throws and the callback that ends it. _run() needs to handle
@@ -42,6 +42,7 @@ async function _run (outputDir, port, timeout, mode, runner, coverage, callback)
         return
       }
       executionQueue.then(async () => {
+        flushLogs(true)
         executionQueue = null
         /* TODO
         if (coverage) {
@@ -71,7 +72,7 @@ async function _run (outputDir, port, timeout, mode, runner, coverage, callback)
     }
     const args = []
     executionQueue = executionQueue.then(async () => {
-      logRaw('info', await Promise.all(args))
+      logRaw('info', -1, await Promise.all(args))
     })
     for (const arg of msg.args()) {
       args.push(arg.evaluate(n => n))
@@ -86,7 +87,7 @@ async function _run (outputDir, port, timeout, mode, runner, coverage, callback)
     end(errors)
   })
   await page.exposeFunction('polendinaLog', (args) => {
-    logRaw(args.shift(), args)
+    logRaw(args.shift(), args.shift(), args)
     maybeEnd()
   })
   await page.exposeFunction('polendinaWrite', (args) => {

resources/common-run.js

@@ -13,6 +13,7 @@ const inWorker = !inPage && !inServiceWorker &&
   typeof WorkerGlobalScope !== 'undefined' &&
   globalThis instanceof WorkerGlobalScope
 let _executionQueue = Promise.resolve()
+let logSeq = 0
 
 export { registry }
 export function executionQueue (fn) {
@@ -22,17 +23,17 @@ export function executionQueue (fn) {
 
 export const log = {
   info: (...args) => {
-    executionQueue(() => globalThis.polendinaLog(['info'].concat(args)))
+    executionQueue(() => globalThis.polendinaLog(['info', logSeq++].concat(args)))
     return executionQueue
   },
   // TODO
   warn: (...args) => {
-    executionQueue(() => globalThis.polendinaLog(['warn'].concat(args)))
+    executionQueue(() => globalThis.polendinaLog(['warn', logSeq++].concat(args)))
     return executionQueue
   },
   // TODO
   error: (...args) => {
-    executionQueue(() => globalThis.polendinaLog(['error'].concat(args)))
+    executionQueue(() => globalThis.polendinaLog(['error', logSeq++].concat(args)))
     return executionQueue
   }
 }