From fdad06bcbbe995e2a6f35726f2b80a0529b87378 Mon Sep 17 00:00:00 2001
From: Chad Hietala <chadhietala@gmail.com>
Date: Wed, 19 Aug 2015 13:22:24 -0700
Subject: [PATCH] Add logging around recursive discovery and hashing

---
 index.js        | 16 ++++++++++++++--
 lib/deps-for.js | 11 +++++++++--
 lib/timing.js   | 11 +++++++++++
 package.json    |  1 +
 4 files changed, 35 insertions(+), 4 deletions(-)
 create mode 100644 lib/timing.js

diff --git a/index.js b/index.js
index 3dcd602..db8d94a 100644
--- a/index.js
+++ b/index.js
@@ -2,6 +2,8 @@
 var helpers = require('broccoli-kitchen-sink-helpers');
 var crypto = require('crypto');
 var statPathsFor = require('./lib/stat-paths-for');
+var timing = require('./lib/timing');
+var debug = require('debug')('hash-for-dep:index');
 
 /* @public
  *
@@ -12,8 +14,18 @@ var statPathsFor = require('./lib/stat-paths-for');
  * @return {String} a hash representing the stats of this module and all its descendents
  */
 module.exports = function hashForDep(name, dir, _hashTreeOverride) {
+  var start = timing.start();
   var inputHashes = statPathsFor(name, dir).map(_hashTreeOverride || helpers.hashTree).join(0x00);
+  debug('inputHashes stats: %o', {
+    hashes: inputHashes.length,
+    elapsedTime: timing.end(start)
+  });
 
-  return crypto.createHash('md5').
-    update(inputHashes).digest('hex');
+  start = timing.start();
+  var hash = crypto.createHash('md5').update(inputHashes).digest('hex');
+  debug('hash stats: %o', {
+    elapsedTime: timing.end(start)
+  });
+
+  return hash;
 };
diff --git a/lib/deps-for.js b/lib/deps-for.js
index 4b939d5..5da25aa 100644
--- a/lib/deps-for.js
+++ b/lib/deps-for.js
@@ -1,8 +1,10 @@
 'use strict';
 var pkg = require('./pkg');
+var debug = require('debug')('hash-for-dep:deps-for');
+var time = require('./timing');
 
 /* @private
- * 
+ *
  * constructs a set of all dependencies recursively
  *
  * @method depsFor
@@ -13,6 +15,7 @@ var pkg = require('./pkg');
 module.exports = function depsFor(name, dir) {
   var dependencies = [];
   var visited = Object.create(null);
+  var start = time.start();
 
   (function again(name, dir) {
     var thePackage = pkg(name, dir);
@@ -28,6 +31,10 @@ module.exports = function depsFor(name, dir) {
     });
   }(name, dir));
 
+  debug('dep discovery stats: %o', {
+    dependencies: dependencies.length,
+    elapsedTime: time.end(start)
+  });
+
   return dependencies;
 };
-
diff --git a/lib/timing.js b/lib/timing.js
new file mode 100644
index 0000000..85e79c0
--- /dev/null
+++ b/lib/timing.js
@@ -0,0 +1,11 @@
+'use strict';
+
+module.exports = {
+  start: function() {
+    return process.hrtime();
+  },
+  end: function(start) {
+    var elapsed = process.hrtime(start)[1] / 1000000;
+    return process.hrtime(start)[0] + 's ' + elapsed.toFixed(3) + 'ms';
+  }
+};
diff --git a/package.json b/package.json
index 538408e..0d3c6c2 100644
--- a/package.json
+++ b/package.json
@@ -19,6 +19,7 @@
   "homepage": "https://github.com/stefanpenner/hash-for-dep#readme",
   "dependencies": {
     "broccoli-kitchen-sink-helpers": "^0.2.6",
+    "debug": "^2.2.0",
     "resolve": "^1.1.6"
   },
   "devDependencies": {