packager: minimize terminal.log() work

Reviewed By: davidaurelio

Differential Revision: D4650441

fbshipit-source-id: 2de2c8e5bea29179fd04ef8db67ac385b3f0a06b

packager/src/lib/__tests__/TransformCache-test.js

@@ -14,7 +14,8 @@ jest
   .dontMock('json-stable-stringify')
   .dontMock('../TransformCache')
   .dontMock('../toFixedHex')
-  .dontMock('left-pad');
+  .dontMock('left-pad')
+  .dontMock('lodash/throttle');
 
 const imurmurhash = require('imurmurhash');
 

packager/src/lib/__tests__/terminal-test.js

@@ -9,7 +9,7 @@
 
 'use strict';
 
-jest.dontMock('../terminal');
+jest.dontMock('../terminal').dontMock('lodash/throttle');
 
 jest.mock('readline', () => ({
   moveCursor: (stream, dx, dy) => {
@@ -64,8 +64,16 @@ describe('terminal', () => {
     terminal.log('foo %s', 'smth');
     terminal.status('status');
     terminal.log('bar');
-    expect(stream.buffer.join('').trim())
-      .toEqual('foo smth  bar');
+    jest.runAllTimers();
+    expect(stream.buffer.join('').trim()).toEqual('foo smth  bar');
+  });
+
+  it('print status', () => {
+    const {stream, terminal} = prepare(true);
+    terminal.log('foo');
+    terminal.status('status');
+    jest.runAllTimers();
+    expect(stream.buffer.join('').trim()).toEqual('foo       status');
   });
 
   it('updates status when logging, single line', () => {
@@ -74,8 +82,11 @@ describe('terminal', () => {
     terminal.status('status');
     terminal.status('status2');
     terminal.log('bar');
-    expect(stream.buffer.join('').trim())
-      .toEqual('foo       bar       status2');
+    jest.runAllTimers();
+    expect(stream.buffer.join('').trim()).toEqual('foo       bar       status2');
+    terminal.log('beep');
+    jest.runAllTimers();
+    expect(stream.buffer.join('').trim()).toEqual('foo       bar       beep      status2');
   });
 
   it('updates status when logging, multi-line', () => {
@@ -83,6 +94,7 @@ describe('terminal', () => {
     terminal.log('foo');
     terminal.status('status\nanother');
     terminal.log('bar');
+    jest.runAllTimers();
     expect(stream.buffer.join('').trim())
       .toEqual('foo       bar       status    another');
   });
@@ -93,8 +105,8 @@ describe('terminal', () => {
     terminal.status('status');
     terminal.persistStatus();
     terminal.log('bar');
-    expect(stream.buffer.join('').trim())
-      .toEqual('foo       status    bar');
+    jest.runAllTimers();
+    expect(stream.buffer.join('').trim()).toEqual('foo       status    bar');
   });
 
 });

packager/src/lib/terminal.js

@@ -12,6 +12,7 @@
 'use strict';
 
 const readline = require('readline');
+const throttle = require('lodash/throttle');
 const tty = require('tty');
 const util = require('util');
 
@@ -70,28 +71,44 @@ function chunkString(str: string, size: number): Array<string> {
  */
 class Terminal {
 
+  _logLines: Array<string>;
+  _nextStatusStr: string;
+  _scheduleUpdate: () => void;
   _statusStr: string;
   _stream: net$Socket;
 
   constructor(stream: net$Socket) {
-    this._stream = stream;
+    this._logLines = [];
+    this._nextStatusStr = '';
+    this._scheduleUpdate = throttle(this._update, 0);
     this._statusStr = '';
+    this._stream = stream;
   }
 
   /**
-   * Same as status() without the formatting capabilities. We just clear and
-   * rewrite with the new status. If the stream is non-interactive we still
-   * keep track of the string so that `persistStatus` works.
+   * Clear and write the new status, logging in bulk in-between. Doing this in a
+   * throttled way (in a different tick than the calls to `log()` and
+   * `status()`) prevents us from repeatedly rewriting the status in case
+   * `terminal.log()` is called several times.
    */
-  _setStatus(str: string): string {
+  _update(): void {
     const {_statusStr, _stream} = this;
-    if (_statusStr !== str && _stream instanceof tty.WriteStream) {
-      clearStringBackwards(_stream, _statusStr);
-      str = chunkString(str, _stream.columns).join('\n');
-      _stream.write(str);
+    if (_statusStr === this._nextStatusStr && this._logLines.length === 0) {
+      return;
     }
-    this._statusStr = str;
-    return _statusStr;
+    if (_stream instanceof tty.WriteStream) {
+      clearStringBackwards(_stream, _statusStr);
+    }
+    this._logLines.forEach(line => {
+      _stream.write(line);
+      _stream.write('\n');
+    });
+    this._logLines = [];
+    if (_stream instanceof tty.WriteStream) {
+      this._nextStatusStr = chunkString(this._nextStatusStr, _stream.columns).join('\n');
+      _stream.write(this._nextStatusStr);
+    }
+    this._statusStr = this._nextStatusStr;
   }
 
   /**
@@ -102,7 +119,10 @@ class Terminal {
    * file, then we don't care too much about having a progress bar.
    */
   status(format: string, ...args: Array<mixed>): string {
-    return this._setStatus(util.format(format, ...args));
+    const {_nextStatusStr} = this;
+    this._nextStatusStr = util.format(format, ...args);
+    this._scheduleUpdate();
+    return _nextStatusStr;
   }
 
   /**
@@ -111,9 +131,8 @@ class Terminal {
    * `console.log`.
    */
   log(format: string, ...args: Array<mixed>): void {
-    const oldStatus = this._setStatus('');
-    this._stream.write(util.format(format, ...args) + '\n');
-    this._setStatus(oldStatus);
+    this._logLines.push(util.format(format, ...args));
+    this._scheduleUpdate();
   }
 
   /**
@@ -121,7 +140,8 @@ class Terminal {
    * status was the last one of a series of updates.
    */
   persistStatus(): void {
-    return this.log(this.status(''));
+    this.log(this._nextStatusStr);
+    this._nextStatusStr = '';
   }
 
 }