diff options
| -rw-r--r-- | lib/templating/render.js | 18 | ||||
| -rw-r--r-- | lib/utils/timing.js | 11 |
2 files changed, 17 insertions, 12 deletions
diff --git a/lib/templating/render.js b/lib/templating/render.js index bf21cfe..22c0dc4 100644 --- a/lib/templating/render.js +++ b/lib/templating/render.js @@ -1,4 +1,5 @@ var Promise = require('../utils/promise'); +var timing = require('../utils/timing'); var replaceShortcuts = require('./replaceShortcuts'); @@ -17,13 +18,16 @@ function renderTemplate(engine, filePath, content, context) { content = replaceShortcuts(engine, filePath, content); - return Promise.nfcall( - env.renderString.bind(env), - content, - context, - { - path: filePath - } + return timing.measure( + 'template.render', + Promise.nfcall( + env.renderString.bind(env), + content, + context, + { + path: filePath + } + ) ); } diff --git a/lib/utils/timing.js b/lib/utils/timing.js index 9903af2..e6b0323 100644 --- a/lib/utils/timing.js +++ b/lib/utils/timing.js @@ -75,11 +75,12 @@ function dump(logger) { return timer.total; }) .forEach(function(timer) { - logger.debug.ln('Timer "' + timer.type + '" (' + timer.count + ' times) :'); - logger.debug.ln(prefix + 'Total: ' + time(timer.total)); - logger.debug.ln(prefix + 'Average: ' + time(timer.total / timer.count)); - logger.debug.ln(prefix + 'Min: ' + time(timer.min)); - logger.debug.ln(prefix + 'Max: ' + time(timer.max)); + var percent = (timer.total * 100) / totalDuration; + + + logger.debug.ln((percent.toFixed(1)) + '% of time spent in "' + timer.type + '" (' + timer.count + ' times) :'); + logger.debug.ln(prefix + 'Total: ' + time(timer.total)+ ' | Average: ' + time(timer.total / timer.count)); + logger.debug.ln(prefix + 'Min: ' + time(timer.min) + ' | Max: ' + time(timer.max)); logger.debug.ln('---------------------------'); }); |