From b43621322b63f0d82fdbe3a52a42dd5d21ec3e0d Mon Sep 17 00:00:00 2001
From: Spencer Alger <spencer@spenceralger.com>
Date: Wed, 4 Dec 2013 17:02:34 -0600
Subject: [PATCH] more tests, now with 91% coverage!

---
 src/lib/loggers/file.js               | 11 ++---
 src/lib/loggers/stream.js             | 14 ++----
 src/lib/utils.js                      | 66 +++++++++++---------------
 test/integration/yaml_suite/server.js |  4 +-
 test/mocks/writable_stream.js         |  2 +-
 test/unit/generic_logger_tests.js     | 15 ++++--
 test/unit/test_file_logger.js         | 44 +++++++++++++++++-
 test/unit/test_stream_logger.js       | 44 +++++++++---------
 test/unit/test_tracer_logger.js       | 41 ++++++++++++++++
 test/unit/test_utils.js               | 67 ++++++++++++++++++++++++++-
 10 files changed, 221 insertions(+), 87 deletions(-)
 create mode 100644 test/unit/test_tracer_logger.js

diff --git a/src/lib/loggers/file.js b/src/lib/loggers/file.js
index 7f098f341..4b4357f96 100755
--- a/src/lib/loggers/file.js
+++ b/src/lib/loggers/file.js
@@ -32,13 +32,8 @@ function File(log, config) {
 _.inherits(File, StreamLogger);
 
 File.prototype.onProcessExit = _.handler(function () {
-  // flush the write buffer to disk
-  var writeBuffer = this.stream._writableState.buffer;
-  var out = '';
-  if (writeBuffer) {
-    writeBuffer.forEach(function (buffered) {
-      out += buffered.chunk.toString();
-    });
-    fs.appendFileSync(this.path, out);
+  var toWrite = _.getUnwrittenFromStream(this.stream);
+  if (toWrite) {
+    fs.appendFileSync(this.path, toWrite);
   }
 });
diff --git a/src/lib/loggers/stream.js b/src/lib/loggers/stream.js
index fac924154..235440d15 100755
--- a/src/lib/loggers/stream.js
+++ b/src/lib/loggers/stream.js
@@ -21,7 +21,7 @@ function Stream(log, config) {
   if (config.stream && config.stream.write && config.stream.end) {
     this.stream = config.stream;
   } else {
-    throw new TypeError('Invalid stream, use an instance of stream.Writeable');
+    throw new TypeError('Invalid stream, use an instance of stream.Writable');
   }
 
   process.once('exit', this.bound.onProcessExit);
@@ -36,14 +36,10 @@ Stream.prototype.cleanUpListeners = _.handler(function () {
 // flush the write buffer to stderr synchronously
 Stream.prototype.onProcessExit = _.handler(function () {
   // process is dying, lets manually flush the buffer synchronously to stderr.
-  if (this.stream._writableState && this.stream._writableState.buffer) {
-    var writeBuffer = this.stream._writableState.buffer;
-    if (writeBuffer.length) {
-      console.error('Log stream did not get to finish writing. Flushing to stderr');
-      writeBuffer.forEach(function (buffered) {
-        console.error(buffered.chunk.toString());
-      });
-    }
+  var unwritten = _.getUnwrittenFromStream(this.stream);
+  if (unwritten) {
+    console.error('Log stream did not get to finish writing. Flushing to stderr');
+    console.error(unwritten);
   }
 });
 
diff --git a/src/lib/utils.js b/src/lib/utils.js
index 2a346d266..8d0c7ac32 100644
--- a/src/lib/utils.js
+++ b/src/lib/utils.js
@@ -226,32 +226,6 @@ utils.repeat = function (what, times) {
   return (new Array(times + 1)).join(what);
 };
 
-/**
- *
- */
-
-/**
- * Remove leading/trailing spaces from a string
- *
- * @param str {String} - Any string
- * @returns {String}
- */
-utils.trim = function (str) {
-  return typeof str === 'string' ? str.replace(/^\s+|\s+$/g, '') : '';
-};
-
-utils.collectMatches = function (text, regExp) {
-  var matches = [], match;
-  while (match = regExp.exec(text)) {
-    matches.push(match);
-    if (regExp.global !== true) {
-      // would loop forever if not true
-      break;
-    }
-  }
-  return matches;
-};
-
 /**
  * Call a function, applying the arguments object to it in an optimized way, rather than always turning it into an array
  *
@@ -328,22 +302,14 @@ _.scheduled = _.handler;
  * ```
  *
  * @param {Object} obj - The object to bind the methods to
- * @param {Array} [methods] - The methods to bind, false values === bind all flagged with _provideBound
  */
-_.makeBoundMethods = function (obj, methods) {
+_.makeBoundMethods = function (obj) {
   obj.bound = {};
-  if (!methods) {
-    methods = [];
-    for (var prop in obj) {
-      // dearest maintainer, we want to look through the prototype
-      if (typeof obj[prop] === 'function' && obj[prop]._provideBound === true) {
-        obj.bound[prop] = _.bind(obj[prop], obj);
-      }
+  for (var prop in obj) {
+    // dearest maintainer, we want to look through the prototype
+    if (typeof obj[prop] === 'function' && obj[prop]._provideBound === true) {
+      obj.bound[prop] = _.bind(obj[prop], obj);
     }
-  } else {
-    _.each(methods, function (method) {
-      obj.bound[method] = _.bindKey(obj, method);
-    });
   }
 };
 
@@ -414,4 +380,26 @@ _.createArray = function (input, transform) {
   return output;
 };
 
+/**
+ * Takes a WritableStream, and returns the chunks that have not successfully written, returning them as a string.
+ *
+ * ONLY WORKS FOR TEXT STREAMS
+ *
+ * @param  {WritableStream} stream - an instance of stream.Writable
+ * @return {string} - the remaining test to be written to the stream
+ */
+_.getUnwrittenFromStream = function (stream) {
+  if (stream && stream._writableState && stream._writableState.buffer) {
+    // flush the write buffer to disk
+    var writeBuffer = stream._writableState.buffer;
+    var out = '';
+    if (writeBuffer.length) {
+      writeBuffer.forEach(function (buffered) {
+        out += buffered.chunk.toString();
+      });
+    }
+    return out;
+  }
+};
+
 module.exports = utils;
diff --git a/test/integration/yaml_suite/server.js b/test/integration/yaml_suite/server.js
index 42c029809..c8e01f6ea 100644
--- a/test/integration/yaml_suite/server.js
+++ b/test/integration/yaml_suite/server.js
@@ -33,7 +33,7 @@ exports.start = function (cb) {
   );
 
   server.stdout.on('data', function onProcessData(line) {
-    line = _.trim(line.toString());
+    line = line.toString().trim();
     var match;
     if (match = line.match(/\{inet\[\/?([^:]+):(\d+)\]\}/)) {
       server.__hostname = match[1];
@@ -49,7 +49,7 @@ exports.start = function (cb) {
   });
 
   server.stderr.on('data', function (line) {
-    console.error(_.trim(line.toString()));
+    console.error(line.toString().trim());
   });
 
   server.on('close', function (code) {
diff --git a/test/mocks/writable_stream.js b/test/mocks/writable_stream.js
index 284adc498..032e5a70f 100644
--- a/test/mocks/writable_stream.js
+++ b/test/mocks/writable_stream.js
@@ -1,5 +1,5 @@
 /**
- * Just a buffer really, but one that implements the Writeable class
+ * Just a buffer really, but one that implements the Writable class
  * @type {Constuctor}
  */
 module.exports = MockWritableStream;
diff --git a/test/unit/generic_logger_tests.js b/test/unit/generic_logger_tests.js
index 977b7d4c9..00bc916b6 100644
--- a/test/unit/generic_logger_tests.js
+++ b/test/unit/generic_logger_tests.js
@@ -1,5 +1,6 @@
 var Log = require('../../src/lib/log');
 var LoggerAbstract = require('../../src/lib/logger');
+var TracerLogger = require('../../src/lib/loggers/tracer');
 var now = new Date('2013-03-01T00:00:00Z');
 var sinon = require('sinon');
 
@@ -234,12 +235,16 @@ module.exports = function (makeLogger) {
 
     it('joins the message and curl call with a newline', function () {
       var logger = makeLogger();
-      stub(logger, 'write', function (label, msg) {
-        msg.should.eql('curlcall\nmessage');
-      });
 
-      logger.onTrace('message', 'curlcall');
-      logger.write.callCount.should.eql(1);
+      // tracer logger has custom trace logic...
+      if (!(logger instanceof TracerLogger)) {
+        stub(logger, 'write', function (label, msg) {
+          msg.should.eql('curlcall\nmessage');
+        });
+
+        logger.onTrace('message', 'curlcall');
+        logger.write.callCount.should.eql(1);
+      }
     });
   });
 };
\ No newline at end of file
diff --git a/test/unit/test_file_logger.js b/test/unit/test_file_logger.js
index 43de8721d..14fb6bb0d 100644
--- a/test/unit/test_file_logger.js
+++ b/test/unit/test_file_logger.js
@@ -1,7 +1,12 @@
 var Log = require('../../src/lib/log');
 var FileLogger = require('../../src/lib/loggers/file');
 var sinon = require('sinon');
+var once = require('events').EventEmitter.prototype.once;
+var write = require('stream').Writable.prototype.write;
+var MockWritableStream = require('../mocks/writable_stream');
+var _ = require('lodash');
 var parentLog;
+var fs = require('fs');
 
 beforeEach(function () {
   parentLog = new Log();
@@ -17,7 +22,11 @@ function makeLogger(parent, levels, path) {
     levels: Log.parseLevels(levels || 'trace'),
     path: path === void 0 ? 'elasticsearch.log' : path
   };
-  return new FileLogger(parent, config);
+  var logger = new FileLogger(parent, config);
+  logger.stream.end();
+
+  logger.stream = new MockWritableStream();
+  return logger;
 }
 
 var stub = require('./auto_release_stub').make();
@@ -26,4 +35,37 @@ describe('File Logger', function () {
 
   require('./generic_logger_tests')(makeLogger);
 
+  describe('buffer flush', function () {
+    it('writes everything in the buffer to console.error', function () {
+      var line = 'This string is writte 10 times to create buffered output.\n';
+
+      var exitHandler;
+      stub(process, 'once', function (event, handler) {
+        if (event === 'exit') {
+          exitHandler = handler;
+        }
+        once.call(process, event, handler);
+      });
+
+      var logger = makeLogger();
+
+      // write the line 10 times
+      _.times(10, function () {
+        logger.onDebug(line);
+      });
+
+      // collect everything that is written to fs.appendFileSync
+      var flushedOutput = '';
+      stub(fs, 'appendFileSync', function (path, str) {
+        flushedOutput += str;
+      });
+
+      // call the event handler
+      exitHandler.call(process);
+
+      // the first line is sent immediately to _write and there is nothing we can do about that
+      flushedOutput.match(new RegExp(line, 'g')).length.should.eql(9);
+    });
+  });
+
 });
diff --git a/test/unit/test_stream_logger.js b/test/unit/test_stream_logger.js
index 0e80a8785..d875eb43b 100644
--- a/test/unit/test_stream_logger.js
+++ b/test/unit/test_stream_logger.js
@@ -3,7 +3,6 @@ var StreamLogger = require('../../src/lib/loggers/stream');
 var MockWritableStream = require('../mocks/writable_stream');
 var MockOldWritableStream = require('../mocks/old_writable_stream');
 var once = require('events').EventEmitter.prototype.once;
-var write = require('stream').Writable.prototype.write;
 var sinon = require('sinon');
 var stream = new MockWritableStream();
 var _ = require('lodash');
@@ -14,6 +13,10 @@ var stub = require('./auto_release_stub').make();
 
 beforeEach(function () {
   parentLog = new Log();
+  if (stream._writableState.buffer.length) {
+    // empty the buffer manually
+    stream._writableState.buffer.splice(0);
+  }
   stub(stream, 'write');
   stub(stream, 'end');
 });
@@ -34,37 +37,36 @@ function makeLogger(parent, levels) {
 describe('Stream Logger', function () {
   describe('buffer flushing', function () {
     it('writes everything in the buffer to console.error', function () {
-      var onExitCallback;
-      sinon.stub(process, 'once', function (evName, cb) {
-        if (evName === 'exit') {
-          onExitCallback = cb;
-          process.once.restore();
-        } else {
-          once.call(process, evName, cb);
-        }
-      });
-
       var logger = makeLogger();
-      var line = 'This string is repeated 10 times to create buffered output.\n';
+      var line = 'This string is writte 10 times to create buffered output.\n';
 
+      // get the last handler for process's "exit" event
+      var exitHandlers = process._events.exit;
+      var exitHandler = _.isArray(exitHandlers) ? _.last(exitHandlers) : exitHandlers;
+
+      // allow the logger to acctually write to the stream
+      stream.write.restore();
+
+      // write the line 10 times
       _.times(10, function () {
-        write.call(stream, line);
+        logger.onDebug(line);
       });
 
+      // collect everything that is written to console.error
       var flushedOutput = '';
-      sinon.stub(console, 'error', function (str) {
+      stub(console, 'error', function (str) {
         flushedOutput += str;
       });
-      onExitCallback();
-      console.error.restore();
-      // empty the buffer manually
-      stream._writableState.buffer.splice(0);
 
-      // the first line is stuck "in writing" and there is nothing we can do about that
+      // call the event handler
+      exitHandler.call(process);
+
+      // restore console.error asap.
+      console.error.restore();
+
+      // the first line is sent immediately to _write and there is nothing we are not going to worry about it
       flushedOutput.match(new RegExp(line, 'g')).length.should.eql(9);
     });
-
-    it('works with older streams');
   });
 
 
diff --git a/test/unit/test_tracer_logger.js b/test/unit/test_tracer_logger.js
new file mode 100644
index 000000000..b1b02eff3
--- /dev/null
+++ b/test/unit/test_tracer_logger.js
@@ -0,0 +1,41 @@
+var Log = require('../../src/lib/log');
+var TracerLogger = require('../../src/lib/loggers/tracer');
+var sinon = require('sinon');
+var parentLog;
+
+beforeEach(function () {
+  parentLog = new Log();
+});
+
+afterEach(function () {
+  parentLog.close();
+});
+
+function makeLogger(parent, levels) {
+  parent = parent || parentLog;
+  var config = {
+    levels: Log.parseLevels(levels || 'trace')
+  };
+  return new TracerLogger(parent, config);
+}
+
+var stub = require('./auto_release_stub').make();
+
+describe('Tracer Logger', function () {
+
+  require('./generic_logger_tests')(makeLogger);
+
+  describe('#write', function () {
+    it('comments out everything accept the curlCall', function () {
+      var logger = makeLogger();
+
+      stub(logger.stream, 'write', function (string) {
+        string.replace(/(^#.*$|^curlcall$)/mg, '').trim().should.be.exactly('');
+      });
+
+      logger.onTrace('message', 'curlcall');
+
+      logger.stream.write.callCount.should.eql(1);
+    });
+  });
+});
diff --git a/test/unit/test_utils.js b/test/unit/test_utils.js
index c78d1ad68..5d1c3bd6c 100644
--- a/test/unit/test_utils.js
+++ b/test/unit/test_utils.js
@@ -1,6 +1,8 @@
 var _ = require('../../src/lib/utils');
 var should = require('should');
 
+var stub = require('./auto_release_stub').make();
+
 describe('Utils', function () {
 
   describe('Additional Type Checkers', function () {
@@ -30,7 +32,6 @@ describe('Utils', function () {
       }
     },
     function (thing, name) {
-
       describe('#isArrayOf' + name, function (test) {
         it('likes arrays of ' + name, function () {
           should(_['isArrayOf' + name + 's'](thing.is)).be.ok;
@@ -335,4 +336,68 @@ describe('Utils', function () {
       }).should.throw(/expected a function or one of main, other/i);
     });
   });
+
+  describe('#applyArgs', function () {
+    _.times(10, function (i) {
+      var method = i > 5 ? 'apply' : 'call';
+      var argCount = i + 1;
+      var slice = 1;
+
+      it('uses ' + method + ' with ' + i + ' args', function () {
+        var func = function () {};
+        stub(func, method);
+
+        var args = _.map(new Array(i), function (val, i) { return i; });
+        _.applyArgs(func, null, args);
+
+        func[method].callCount.should.eql(1);
+        if (method === 'apply') {
+          func.apply.lastCall.args[1].should.eql(args);
+        } else {
+          func.call.lastCall.args.splice(1).should.eql(args);
+        }
+      });
+
+      it('slices the arguments properly before calling ' + method + ' with ' + argCount + ' args sliced at ' + slice,
+      function () {
+        var func = function () {};
+        stub(func, method);
+
+        var args = _.map(new Array(argCount), function (val, i) { return i; });
+        var expected = args.slice(slice);
+        _.applyArgs(func, null, args, slice);
+
+        func[method].callCount.should.eql(1);
+        if (method === 'apply') {
+          func.apply.lastCall.args[1].should.eql(expected);
+        } else {
+          func.call.lastCall.args.splice(1).should.eql(expected);
+        }
+      });
+    });
+  });
+
+  describe('#getUnwrittenFromStream', function () {
+    it('ignores things that do not have writableState', function () {
+      should.not.exist(_.getUnwrittenFromStream());
+      should.not.exist(_.getUnwrittenFromStream(false));
+      should.not.exist(_.getUnwrittenFromStream([]));
+      should.not.exist(_.getUnwrittenFromStream({}));
+    });
+
+    var MockWritableStream = require('../mocks/writable_stream');
+
+    it('ignores empty stream', function () {
+      var stream = new MockWritableStream();
+      _.getUnwrittenFromStream(stream).should.be.exactly('');
+    });
+
+    it('returns only what is in the buffer', function () {
+      var stream = new MockWritableStream();
+      stream.write('hot');
+      stream.write('dog');
+      _.getUnwrittenFromStream(stream).should.be.exactly('dog');
+    });
+  });
+
 });