Repository: netlify/build
Pull request #398 (2019-10-31 13:04:51)

Fix streaming output
This fixes some issues when streaming child processes output in the BuildBot.

Related to #358.


Patch:
diff --git a/packages/build/src/core/instructions.js b/packages/build/src/core/instructions.js
index 31d55ece6..10164ae23 100644
--- a/packages/build/src/core/instructions.js
+++ b/packages/build/src/core/instructions.js
@@ -11,7 +11,7 @@ const {
   logInstructionSuccess,
 } = require('../log/main')
 const { startTimer, endTimer } = require('../log/timer')
-const { pipeOutput, unpipeOutput } = require('../log/stream')
+const { startOutput, stopOutput } = require('../log/stream')
 
 const { LIFECYCLE } = require('./lifecycle')
 
@@ -114,7 +114,8 @@ const execCommand = async function({ hook, command, baseDir }) {
   logCommandStart(command)
 
   const childProcess = execa(command, { shell: true, cwd: baseDir, preferLocal: true })
-  pipeOutput(childProcess)
+  const chunks = []
+  startOutput(childProcess, chunks)
 
   try {
     await childProcess
@@ -123,13 +124,14 @@ const execCommand = async function({ hook, command, baseDir }) {
     error.cleanStack = true
     throw error
   } finally {
-    unpipeOutput(childProcess)
+    stopOutput(childProcess, chunks)
   }
 }
 
 // Fire a plugin hook method
 const firePluginHook = async function({ id, childProcess, hook, hookName }, { config, token, baseDir, error }) {
-  pipeOutput(childProcess)
+  const chunks = []
+  startOutput(childProcess, chunks)
 
   try {
     await sendEventToChild(childProcess, 'run', { hookName, error })
@@ -139,7 +141,7 @@ const firePluginHook = async function({ id, childProcess, hook, hookName }, { co
     error.cleanStack = true
     throw error
   } finally {
-    unpipeOutput(childProcess)
+    stopOutput(childProcess, chunks)
   }
 }
 
diff --git a/packages/build/src/log/stream.js b/packages/build/src/log/stream.js
index c41811d23..6bdb6b05e 100644
--- a/packages/build/src/log/stream.js
+++ b/packages/build/src/log/stream.js
@@ -1,15 +1,57 @@
 const { stdout, stderr } = require('process')
 
+const isNetlifyCI = require('../utils/is-netlify-ci')
 // Start streaming command or plugin hook output
+// In CI, we need to buffer output instead at the moment due to the current
+// BuildBot not handling it correctly.
+// But locally we want to stream output instead for a better developer
+// experience.
+// See https://github.com/netlify/build/issues/343
+const startOutput = function(childProcess, chunks) {
+  if (shouldBuffer()) {
+    bufferOutput(childProcess, chunks)
+    return
+  }
+
+  pipeOutput(childProcess)
+}
+
+// Stop streaming/buffering command or plugin hook output
+const stopOutput = function(childProcess, chunks) {
+  if (shouldBuffer()) {
+    unbufferOutput(childProcess, chunks)
+    return
+  }
+
+  unpipeOutput(childProcess)
+}
+
 const pipeOutput = function(childProcess) {
   childProcess.stdout.pipe(stdout)
   childProcess.stderr.pipe(stderr)
 }
 
-// Stop streaming command or plugin hook output
 const unpipeOutput = function(childProcess) {
   childProcess.stdout.unpipe(stdout)
   childProcess.stderr.unpipe(stderr)
 }
 
-module.exports = { pipeOutput, unpipeOutput }
+const bufferOutput = function(childProcess, chunks) {
+  childProcess.stdout.on('data', chunk => {
+    chunks.push(chunk)
+  })
+  childProcess.stderr.on('data', chunk => {
+    chunks.push(chunk)
+  })
+}
+
+const unbufferOutput = function(chunks) {
+  const output = chunks.join('')
+  process.stdout.write(output)
+}
+
+const shouldBuffer = function() {
+  return isNetlifyCI()
+}
+
+module.exports = { startOutput, stopOutput }


Test patch:
diff --git a/packages/build/tests/fixtures/plugin_streams/netlify.yml b/packages/build/tests/fixtures/plugin_streams/netlify.yml
new file mode 100644
index 000000000..9af189f44
--- /dev/null
+++ b/packages/build/tests/fixtures/plugin_streams/netlify.yml
@@ -0,0 +1,2 @@
+plugins:
+  - type: ./plugin
diff --git a/packages/build/tests/fixtures/plugin_streams/plugin.js b/packages/build/tests/fixtures/plugin_streams/plugin.js
new file mode 100644
index 000000000..53dfc6aa0
--- /dev/null
+++ b/packages/build/tests/fixtures/plugin_streams/plugin.js
@@ -0,0 +1,14 @@
+const { promisify } = require('util')
+
+const pSetTimeout = promisify(setTimeout)
+
+module.exports = {
+  name: 'netlify-plugin-test',
+  async init() {
+    console.log('one')
+    await pSetTimeout(0)
+    console.error('two')
+    await pSetTimeout(0)
+    console.log('three')
+  },
+}
diff --git a/packages/build/tests/main.test.js b/packages/build/tests/main.test.js
index b0f47dff7..8e23b83fe 100644
--- a/packages/build/tests/main.test.js
+++ b/packages/build/tests/main.test.js
@@ -233,6 +233,14 @@ test('Can install local plugins', async t => {
   t.snapshot(normalizeOutput(all))
 })
 
+test('Plugin output can interleave stdout and stderr', async t => {
+  const { all } = await execa.command(`${BINARY_PATH} --config ${FIXTURES_DIR}/plugin_streams/netlify.yml`, {
+    all: true,
+    reject: false,
+  })
+  t.snapshot(normalizeOutput(all))
+})
+
 test('Install local plugin dependencies: with npm', async t => {
   const { all } = await execa.command(`${BINARY_PATH} --config ${FIXTURES_DIR}/plugin_deps/netlify.yml`, {
     all: true,
diff --git a/packages/build/tests/snapshots/main.test.js.md b/packages/build/tests/snapshots/main.test.js.md
index 4986a9760..5cab9cb70 100644
--- a/packages/build/tests/snapshots/main.test.js.md
+++ b/packages/build/tests/snapshots/main.test.js.md
@@ -1676,3 +1676,43 @@ Generated by [AVA](https://ava.li).
     ␊
     (ﾉ◕ヮ◕)ﾉ*:･ﾟ✧ Have a nice day!␊
     `
+
+## Plugin output can interleave stdout and stderr
+
+> Snapshot 1
+
+    `> Starting Netlify Build v1.0.0␊
+      https://github.com/netlify/build␊
+    ␊
+    Options␊
+      { config: '/file/path' }␊
+    ␊
+    > Using config file: /file/path␊
+    ␊
+    > Installing plugins dependencies␊
+    ␊
+    > Loading plugins␊
+      Loading plugin "@netlify/plugin-functions-core" from build core␊
+      Loading plugin from /file/path␊
+    ␊
+    > Running Netlify Build Lifecycle␊
+      Found 1 step. Lets do this!␊
+    ␊
+    ┌──────────────────────────────────────────────────────┐␊
+    │ 1. Running init lifecycle from netlify-plugin-test   │␊
+    └──────────────────────────────────────────────────────┘␊
+    ␊
+    one␊
+    two␊
+    three␊
+    ␊
+     √  netlify-plugin-test.init completed in 1ms␊
+    ␊
+    ┌─────────────────────────────┐␊
+    │   Netlify Build Complete!   │␊
+    └─────────────────────────────┘␊
+    ␊
+     √  Netlify Build completed in 1ms␊
+    ␊
+    (ﾉ◕ヮ◕)ﾉ*:･ﾟ✧ Have a nice day!␊
+    `