From 7ff50f43f4a21121a5bb059ac468f4b55cef3e84 Mon Sep 17 00:00:00 2001
From: Mark Cavage <mark.cavage@joyent.com>
Date: Sat, 18 Feb 2012 08:54:22 +0000
Subject: [PATCH] Initial switch to bunyan

---
 lib/client.js                   |  48 +++++-----
 lib/index.js                    |  25 +++++-
 lib/log_stub.js                 | 155 --------------------------------
 lib/messages/message.js         |  13 +--
 lib/messages/parser.js          |   9 +-
 lib/messages/result.js          |   2 +-
 lib/messages/search_response.js |   8 +-
 lib/messages/unbind_request.js  |   3 +-
 lib/messages/unbind_response.js |   3 +-
 lib/server.js                   |  25 +++---
 test/client.test.js             |   2 -
 11 files changed, 67 insertions(+), 226 deletions(-)
 delete mode 100644 lib/log_stub.js

diff --git a/lib/client.js b/lib/client.js
index 173c4d6..faddcd9 100644
--- a/lib/client.js
+++ b/lib/client.js
@@ -13,7 +13,6 @@ var Protocol = require('./protocol');
 var dn = require('./dn');
 var errors = require('./errors');
 var filters = require('./filters');
-var logStub = require('./log_stub');
 var messages = require('./messages');
 var url = require('./url');
 
@@ -98,8 +97,8 @@ util.inherits(ConnectionError, errors.LDAPError);
  *
  * The options object is required, and must contain either a URL (string) or
  * a socketPath (string); the socketPath is only if you want to talk to an LDAP
- * server over a Unix Domain Socket.  Additionally, you can pass in a log4js
- * option that is the result of `require('log4js')`, presumably after you've
+ * server over a Unix Domain Socket.  Additionally, you can pass in a bunyan
+ * option that is the result of `new Logger()`, presumably after you've
  * configured it.
  *
  * @param {Object} options must have either url or socketPath.
@@ -112,8 +111,8 @@ function Client(options) {
     throw new TypeError('options.url (string) required');
   if (options.socketPath && typeof (options.socketPath) !== 'string')
     throw new TypeError('options.socketPath must be a string');
-  if (options.log4js && typeof (options.log4js) !== 'object')
-    throw new TypeError('options.log4s must be an object');
+  if (typeof (options.log) !== 'object')
+    throw new TypeError('options.log must be an object');
 
   if (!xor(options.url, options.socketPath))
     throw new TypeError('options.url ^ options.socketPath required');
@@ -134,19 +133,12 @@ function Client(options) {
     host: self.url ? self.url.hostname : undefined,
     socketPath: options.socketPath || undefined
   };
-  this.log4js = options.log4js || logStub;
+  this.log = options.log;
   this.reconnect = (typeof (options.reconnect) === 'number' ?
                     options.reconnect : 1000);
   this.shutdown = false;
   this.timeout = options.timeout || false;
 
-  this.__defineGetter__('log', function () {
-    if (!self._log)
-      self._log = self.log4js.getLogger('Client');
-
-    return self._log;
-  });
-
   return this.connect(function () {});
 }
 util.inherits(Client, EventEmitter);
@@ -760,8 +752,8 @@ Client.prototype._send = function (message, expect, callback, connection) {
       if (timer)
         clearTimeout(timer);
 
-      if (self.log.isDebugEnabled())
-        self.log.debug('%s: response received: %j', conn.ldap.id, res.json);
+      if (self.log.debug())
+        self.log.debug({res: res.json}, '%s: response received', conn.ldap.id);
 
       var err = null;
 
@@ -836,8 +828,8 @@ Client.prototype._send = function (message, expect, callback, connection) {
     }
 
     // Finally send some data
-    if (this.log.isDebugEnabled())
-      this.log.debug('%s: sending request: %j', conn.ldap.id, message.json);
+    if (this.log.debug())
+      this.log.debug({msg: message.json}, '%s: sending request', conn.ldap.id);
     return conn.write(message.toBer(), _writeCb);
   } catch (e) {
     return closeConn(e);
@@ -853,7 +845,7 @@ Client.prototype._newConnection = function () {
 
   if (this.secure) {
     c = tls.connect(connectOpts.port, connectOpts.host, function () {
-      if (log.isTraceEnabled())
+      if (log.trace())
         log.trace('%s connect event', c.ldap.id);
 
       c.ldap.connected = true;
@@ -869,7 +861,7 @@ Client.prototype._newConnection = function () {
   assert.ok(c);
 
   c.parser = new Parser({
-    log4js: self.log4js
+    log: self.log
   });
 
   // Wrap the events
@@ -886,7 +878,7 @@ Client.prototype._newConnection = function () {
   });
 
   c.on('connect', function () {
-    if (log.isTraceEnabled())
+    if (log.trace())
       log.trace('%s connect event', c.ldap.id);
 
     c.ldap.connected = true;
@@ -895,14 +887,14 @@ Client.prototype._newConnection = function () {
   });
 
   c.on('end', function () {
-    if (log.isTraceEnabled())
+    if (log.trace())
       log.trace('%s end event', c.ldap.id);
 
     c.end();
   });
 
   c.on('close', function (had_err) {
-    if (log.isTraceEnabled())
+    if (log.trace())
       log.trace('%s close event had_err=%s', c.ldap.id, had_err ? 'yes' : 'no');
 
     Object.keys(c.ldap.messages).forEach(function (msgid) {
@@ -933,8 +925,8 @@ Client.prototype._newConnection = function () {
   });
 
   c.on('error', function (err) {
-    if (log.isTraceEnabled())
-      log.trace('%s error event=%s', c.ldap.id, err ? err.stack : '?');
+    if (log.trace())
+      log.trace({err: err}, '%s error event', c.ldap.id);
 
     if (self.listeners('error').length)
       self.emit('error', err);
@@ -943,7 +935,7 @@ Client.prototype._newConnection = function () {
   });
 
   c.on('timeout', function () {
-    if (log.isTraceEnabled())
+    if (log.trace())
       log.trace('%s timeout event=%s', c.ldap.id);
 
     self.emit('timeout');
@@ -951,7 +943,7 @@ Client.prototype._newConnection = function () {
   });
 
   c.on('data', function (data) {
-    if (log.isTraceEnabled())
+    if (log.trace())
       log.trace('%s data event: %s', c.ldap.id, util.inspect(data));
 
     c.parser.write(data);
@@ -971,8 +963,8 @@ Client.prototype._newConnection = function () {
   });
 
   c.parser.on('error', function (err) {
-    if (log.isTraceEnabled())
-      log.trace('%s error event=%s', c.ldap.id, err ? err.stack : '?');
+    if (log.trace())
+      log.trace({err: err}, '%s error event', c.ldap.id);
 
     if (self.listeners('error').length)
       self.emit('error', err);
diff --git a/lib/index.js b/lib/index.js
index d460259..fd5f597 100644
--- a/lib/index.js
+++ b/lib/index.js
@@ -1,5 +1,7 @@
 // Copyright 2011 Mark Cavage, Inc.  All rights reserved.
 
+var Logger = require('bunyan');
+
 var Client = require('./client');
 var Attribute = require('./attribute');
 var Change = require('./change');
@@ -11,7 +13,6 @@ var controls = require('./controls');
 var dn = require('./dn');
 var errors = require('./errors');
 var filters = require('./filters');
-var logStub = require('./log_stub');
 var messages = require('./messages');
 var url = require('./url');
 
@@ -45,11 +46,32 @@ module.exports = {
     if (typeof (options) !== 'object')
       throw new TypeError('options (object) required');
 
+    if (!options.log) {
+      options.log = new Logger({
+        name: 'ldapjs',
+        component: 'client',
+        stream: process.stderr
+      });
+    }
     return new Client(options);
   },
 
   Server: Server,
   createServer: function (options) {
+    if (options === undefined)
+      options = {};
+
+    if (typeof (options) !== 'object')
+      throw new TypeError('options (object) required');
+
+    if (!options.log) {
+      options.log = new Logger({
+        name: 'ldapjs',
+        component: 'client',
+        stream: process.stderr
+      });
+    }
+
     return new Server(options);
   },
 
@@ -64,7 +86,6 @@ module.exports = {
   filters: filters,
   parseFilter: filters.parseString,
 
-  log4js: logStub,
   parseURL: url.parse,
   url: url
 };
diff --git a/lib/log_stub.js b/lib/log_stub.js
deleted file mode 100644
index 43d5d22..0000000
--- a/lib/log_stub.js
+++ /dev/null
@@ -1,155 +0,0 @@
-// Copyright 2011 Mark Cavage, Inc.  All rights reserved.
-
-
-
-///--- Globals
-
-var FMT_STR = '%d-%s-%s %s:%s:%sZ %s - %s: ';
-
-var _i = 0;
-var LEVELS = {
-  Trace: _i++,
-  Debug: _i++,
-  Info: _i++,
-  Warn: _i++,
-  Error: _i++,
-  Fatal: _i++
-};
-
-var level = 'Info';
-
-
-
-// --- Helpers
-
-function pad(val) {
-  if (parseInt(val, 10) < 10) {
-    val = '0' + val;
-  }
-  return val;
-}
-
-
-function format(level, name, args) {
-  var d = new Date();
-  var fmtStr = args.shift();
-  var fmtArgs = [
-    d.getUTCFullYear(),
-    pad(d.getUTCMonth() + 1),
-    pad(d.getUTCDate()),
-    pad(d.getUTCHours()),
-    pad(d.getUTCMinutes()),
-    pad(d.getUTCSeconds()),
-    level,
-    name
-  ];
-
-  args = fmtArgs.concat(args);
-
-  var output = (FMT_STR + fmtStr).replace(/%[sdj]/g, function (match) {
-    switch (match) {
-    case '%s': return new String(args.shift());
-    case '%d': return new Number(args.shift());
-    case '%j': return JSON.stringify(args.shift());
-    default:
-      return match;
-    }
-  });
-
-  return output;
-}
-
-
-
-///--- API
-
-function Log(name) {
-  this.name = name;
-}
-
-Log.prototype._write = function (level, args) {
-  var data = format(level, this.name, args);
-  console.error(data);
-};
-
-Log.prototype.isTraceEnabled = function () {
-  return (LEVELS.Trace >= LEVELS[level]);
-};
-
-Log.prototype.trace = function () {
-  if (this.isTraceEnabled())
-    this._write('TRACE', Array.prototype.slice.call(arguments));
-};
-
-Log.prototype.isDebugEnabled = function () {
-  return (LEVELS.Debug >= LEVELS[level]);
-};
-
-Log.prototype.debug = function () {
-  if (this.isDebugEnabled())
-    this._write('DEBUG', Array.prototype.slice.call(arguments));
-};
-
-Log.prototype.isInfoEnabled = function () {
-  return (LEVELS.Info >= LEVELS[level]);
-};
-
-Log.prototype.info = function () {
-  if (this.isInfoEnabled())
-    this._write('INFO', Array.prototype.slice.call(arguments));
-};
-
-Log.prototype.isWarnEnabled = function () {
-  return (LEVELS.Warn >= LEVELS[level]);
-};
-
-Log.prototype.warn = function () {
-  if (this.isWarnEnabled())
-    this._write('WARN', Array.prototype.slice.call(arguments));
-};
-
-Log.prototype.isErrorEnabled = function () {
-  return (LEVELS.Error >= LEVELS[level]);
-};
-
-Log.prototype.error = function () {
-  if (this.isErrorEnabled())
-    this._write('ERROR', Array.prototype.slice.call(arguments));
-};
-
-Log.prototype.isFatalEnabled = function () {
-  return (LEVELS.Fatal >= LEVELS[level]);
-};
-
-Log.prototype.fatal = function () {
-  if (this.isFatalEnabled())
-    this._write('FATAL', Array.prototype.slice.call(arguments));
-};
-
-
-module.exports = {
-
-  setLevel: function (l) {
-    l = l.charAt(0).toUpperCase() + l.slice(1).toLowerCase();
-    if (LEVELS[l] !== undefined)
-      level = l;
-
-    return level;
-  },
-
-  getLogger: function (name) {
-    if (!name || typeof (name) !== 'string')
-      throw new TypeError('name (string) required');
-
-    return new Log(name);
-  },
-
-  setGlobalLogLevel: function (l) {
-    l = l.charAt(0).toUpperCase() + l.slice(1).toLowerCase();
-    if (LEVELS[l] !== undefined)
-      level = l;
-
-    return level;
-  }
-
-};
diff --git a/lib/messages/message.js b/lib/messages/message.js
index 2f2dda4..516f650 100644
--- a/lib/messages/message.js
+++ b/lib/messages/message.js
@@ -8,8 +8,6 @@ var asn1 = require('asn1');
 var Control = require('../controls').Control;
 var Protocol = require('../protocol');
 
-var logStub = require('../log_stub');
-
 
 
 ///--- Globals
@@ -37,7 +35,7 @@ function LDAPMessage(options) {
   this.protocolOp = options.protocolOp || undefined;
   this.controls = options.controls ? options.controls.slice(0) : [];
 
-  this.log4js = options.log4js || logStub;
+  this.log = options.log;
 
   var self = this;
   this.__defineGetter__('id', function () { return self.messageID; });
@@ -52,11 +50,6 @@ function LDAPMessage(options) {
     j.controls = self.controls;
     return j;
   });
-  this.__defineGetter__('log', function () {
-    if (!self._log)
-      self._log = self.log4js.getLogger(self.type);
-    return self._log;
-  });
 }
 module.exports = LDAPMessage;
 
@@ -69,7 +62,7 @@ LDAPMessage.prototype.toString = function () {
 LDAPMessage.prototype.parse = function (ber) {
   assert.ok(ber);
 
-  if (this.log.isTraceEnabled())
+  if (this.log.trace())
     this.log.trace('parse: data=%s', util.inspect(ber.buffer));
 
   // Delegate off to the specific type to parse
@@ -86,7 +79,7 @@ LDAPMessage.prototype.parse = function (ber) {
     }
   }
 
-  if (this.log.isTraceEnabled())
+  if (this.log.trace())
     this.log.trace('Parsing done: %j', this.json);
   return true;
 };
diff --git a/lib/messages/parser.js b/lib/messages/parser.js
index b2e5f7a..ee26168 100644
--- a/lib/messages/parser.js
+++ b/lib/messages/parser.js
@@ -50,14 +50,13 @@ var BerReader = asn1.BerReader;
 function Parser(options) {
   if (!options || typeof (options) !== 'object')
     throw new TypeError('options (object) required');
-  if (!options.log4js || typeof (options.log4js) !== 'object')
-    throw new TypeError('options.log4js (object) required');
+  if (typeof (options.log) !== 'object')
+    throw new TypeError('options.log (object) required');
 
   EventEmitter.call(this);
 
   this.buffer = null;
-  this.log4js = options.log4js;
-  this.log = this.log4js.getLogger('Parser');
+  this.log = options.log;
 }
 util.inherits(Parser, EventEmitter);
 module.exports = Parser;
@@ -219,6 +218,6 @@ Parser.prototype.getMessage = function (ber) {
 
   return new Message({
     messageID: messageID,
-    log4js: self.log4js
+    log: self.log
   });
 };
diff --git a/lib/messages/result.js b/lib/messages/result.js
index 3c437bf..0285cf9 100644
--- a/lib/messages/result.js
+++ b/lib/messages/result.js
@@ -65,7 +65,7 @@ LDAPResult.prototype.end = function (status) {
     this.status = status;
 
   var ber = this.toBer();
-  if (this.log.isDebugEnabled())
+  if (this.log.debug())
     this.log.debug('%s: sending:  %j', this.connection.ldap.id, this.json);
 
   try {
diff --git a/lib/messages/search_response.js b/lib/messages/search_response.js
index e0f3c00..4e8c276 100644
--- a/lib/messages/search_response.js
+++ b/lib/messages/search_response.js
@@ -81,13 +81,13 @@ SearchResponse.prototype.send = function (entry, nofiltering) {
     entry = new SearchEntry({
       objectName: typeof (save.dn) === 'string' ? parseDN(save.dn) : save.dn,
       messageID: self.messageID,
-      log4js: self.log4js
+      log: self.log
     });
     entry.fromObject(save);
   }
 
   try {
-    if (this.log.isDebugEnabled())
+    if (this.log.debug())
       this.log.debug('%s: sending:  %j', this.connection.ldap.id, entry.json);
 
     this.connection.write(entry.toBer());
@@ -128,7 +128,7 @@ SearchResponse.prototype.createSearchEntry = function (object) {
 
   var entry = new SearchEntry({
     messageID: self.messageID,
-    log4js: self.log4js,
+    log: self.log,
     objectName: object.objectName || object.dn
   });
   entry.fromObject((object.attributes || object));
@@ -152,7 +152,7 @@ SearchResponse.prototype.createSearchReference = function (uris) {
   var self = this;
   return new SearchReference({
     messageID: self.messageID,
-    log4js: self.log4js,
+    log: self.log,
     uris: uris
   });
 };
diff --git a/lib/messages/unbind_request.js b/lib/messages/unbind_request.js
index 224fad1..bafa060 100644
--- a/lib/messages/unbind_request.js
+++ b/lib/messages/unbind_request.js
@@ -55,8 +55,7 @@ UnbindRequest.prototype.newResult = function () {
   }
   util.inherits(UnbindResponse, LDAPMessage);
   UnbindResponse.prototype.end = function (status) {
-    if (this.log.isTraceEnabled())
-      this.log.trace('%s: unbinding!', this.connection.ldap.id);
+    this.log.trace('%s: unbinding!', this.connection.ldap.id);
     this.connection.end();
   };
   UnbindResponse.prototype._json = function (j) { return j; };
diff --git a/lib/messages/unbind_response.js b/lib/messages/unbind_response.js
index 1fb209e..c1d8d87 100644
--- a/lib/messages/unbind_response.js
+++ b/lib/messages/unbind_response.js
@@ -36,8 +36,7 @@ module.exports = UnbindResponse;
 UnbindResponse.prototype.end = function (status) {
   assert.ok(this.connection);
 
-  if (this.log.isTraceEnabled())
-    this.log.trace('%s: unbinding!', this.connection.ldap.id);
+  this.log.trace('%s: unbinding!', this.connection.ldap.id);
 
   this.connection.end();
 
diff --git a/lib/server.js b/lib/server.js
index a6f5312..8b6f4cb 100644
--- a/lib/server.js
+++ b/lib/server.js
@@ -12,7 +12,6 @@ var dn = require('./dn');
 var dtrace = require('./dtrace');
 var errors = require('./errors');
 var Protocol = require('./protocol');
-var logStub = require('./log_stub');
 
 var Parser = require('./messages').Parser;
 var AbandonResponse = require('./messages/abandon_response');
@@ -114,7 +113,7 @@ function getResponse(req) {
 
   var res = new Response({
     messageID: req.messageID,
-    log4js: req.log4js,
+    log: req.log,
     attributes: ((req instanceof SearchRequest) ? req.attributes : undefined)
   });
   res.connection = req.connection;
@@ -241,7 +240,7 @@ function fireDTraceProbe(req, res) {
  * LDAP operations however.
  *
  * The options object currently only takes a certificate/private key, and a
- * log4js handle.
+ * bunyan logger handle.
  *
  * This object exposes the following events:
  *  - 'error'
@@ -254,8 +253,8 @@ function Server(options) {
   if (options) {
     if (typeof (options) !== 'object')
       throw new TypeError('options (object) required');
-    if (options.log4js && typeof (options.log4js) !== 'object')
-      throw new TypeError('options.log4s must be an object');
+    if (typeof (options.log) !== 'object')
+      throw new TypeError('options.log must be an object');
 
     if (options.certificate || options.key) {
       if (!(options.certificate && options.key) ||
@@ -269,14 +268,11 @@ function Server(options) {
     options = {};
   }
   var self = this;
-  if (!options.log4js)
-    options.log4js = logStub;
 
   EventEmitter.call(this, options);
 
   this._chain = [];
-  this.log4js = options.log4js;
-  this.log = this.log4js.getLogger('Server');
+  this.log = options.log;
 
   var log = this.log;
 
@@ -330,22 +326,21 @@ function Server(options) {
 
   function newConnection(c) {
     setupConnection(c);
-    if (log.isTraceEnabled())
-      log.trace('new connection from %s', c.ldap.id);
+    log.trace('new connection from %s', c.ldap.id);
 
     dtrace.fire('server-connection', function () {
       return [c.remoteAddress];
     });
 
     c.parser = new Parser({
-      log4js: options.log4js
+      log: options.log
     });
     c.parser.on('message', function (req) {
       req.connection = c;
       req.logId = c.ldap.id + '::' + req.messageID;
       req.startTime = new Date().getTime();
 
-      if (log.isDebugEnabled())
+      if (log.debug())
         log.debug('%s: message received: req=%j', c.ldap.id, req.json);
 
       var res = getResponse(req);
@@ -424,7 +419,7 @@ function Server(options) {
     });
 
     c.on('data', function (data) {
-      if (log.isTraceEnabled())
+      if (log.trace())
         log.trace('data on %s: %s', c.ldap.id, util.inspect(data));
 
       try {
@@ -448,7 +443,7 @@ function Server(options) {
   } else {
     this.server = net.createServer(newConnection);
   }
-  this.server.log4js = options.log4js;
+  this.server.log = options.log;
   this.server.ldap = {
     config: options
   };
diff --git a/test/client.test.js b/test/client.test.js
index 3f7e622..95b9501 100644
--- a/test/client.test.js
+++ b/test/client.test.js
@@ -132,8 +132,6 @@ test('setup', function (t) {
       reconnect: false // turn this off for unit testing
     });
     t.ok(client);
-    // client.log4js.setLevel('Trace');
-    // server.log4js.setLevel('Trace');
     t.end();
   });