Add option "--timing" to mesure gitbook performances

This commit is contained in:
Samy Pesse
2016-04-30 14:37:44 +02:00
parent fbe0282738
commit 30bce5f9bb
10 changed files with 231 additions and 101 deletions
+6 -1
View File
@@ -1,5 +1,6 @@
var Parse = require('../parse');
var Output = require('../output');
var timing = require('../utils/timing');
var options = require('./options');
var getBook = require('./getBook');
@@ -11,7 +12,8 @@ module.exports = {
description: 'build a book',
options: [
options.log,
options.format
options.format,
options.timing
],
exec: function(args, kwargs) {
var book = getBook(args, kwargs);
@@ -24,6 +26,9 @@ module.exports = {
return Output.generate(Generator, resultBook, {
root: outputFolder
});
})
.fin(function() {
if (kwargs.timing) timing.dump(book.getLogger());
});
}
};
+8 -1
View File
@@ -17,7 +17,14 @@ var formatOption = {
defaults: 'website'
};
var timingOption = {
name: 'timing',
description: 'Print timing debug information',
defaults: false
};
module.exports = {
log: logOptions,
format: formatOption
format: formatOption,
timing: timingOption
};
+22 -17
View File
@@ -1,4 +1,5 @@
var Promise = require('../utils/promise');
var timing = require('../utils/timing');
var Api = require('../api');
function defaultGetArgument() {
@@ -30,26 +31,30 @@ function callHook(name, getArgument, handleResult, output) {
// Create the JS context for plugins
var context = Api.encodeGlobal(output);
// Get the arguments
return Promise(getArgument(output))
return timing.measure(
'call.hook.' + name,
// Call the hooks in serie
.then(function(arg) {
return Promise.reduce(plugins, function(prev, plugin) {
var hook = plugin.getHook(name);
if (!hook) {
return prev;
}
// Get the arguments
Promise(getArgument(output))
return hook.call(context, prev);
}, arg);
})
// Call the hooks in serie
.then(function(arg) {
return Promise.reduce(plugins, function(prev, plugin) {
var hook = plugin.getHook(name);
if (!hook) {
return prev;
}
// Handle final result
.then(function(result) {
output = Api.decodeGlobal(output, context);
return handleResult(output, result);
});
return hook.call(context, prev);
}, arg);
})
// Handle final result
.then(function(result) {
output = Api.decodeGlobal(output, context);
return handleResult(output, result);
})
);
}
module.exports = callHook;
+44 -40
View File
@@ -1,5 +1,6 @@
var Promise = require('../utils/promise');
var error = require('../utils/error');
var timing = require('../utils/timing');
var Parse = require('../parse');
var Templating = require('../templating');
@@ -18,50 +19,53 @@ function generatePage(output, page) {
var book = output.getBook();
var engine = createTemplateEngine(output);
return Parse.parsePage(book, page)
.then(function(resultPage) {
var file = resultPage.getFile();
var filePath = file.getPath();
var parser = file.getParser();
var context = JSONUtils.encodeBookWithPage(book, resultPage);
return timing.measure(
'page.generate',
Parse.parsePage(book, page)
.then(function(resultPage) {
var file = resultPage.getFile();
var filePath = file.getPath();
var parser = file.getParser();
var context = JSONUtils.encodeBookWithPage(book, resultPage);
if (!parser) {
return Promise.reject(error.FileNotParsableError({
filename: filePath
}));
}
if (!parser) {
return Promise.reject(error.FileNotParsableError({
filename: filePath
}));
}
// Call hook "page:before"
return callPageHook('page:before', output, resultPage)
// Call hook "page:before"
return callPageHook('page:before', output, resultPage)
// Escape code blocks with raw tags
.then(function(currentPage) {
return parser.page.prepare(currentPage.getContent());
// Escape code blocks with raw tags
.then(function(currentPage) {
return parser.page.prepare(currentPage.getContent());
})
// Render templating syntax
.then(function(content) {
return Templating.render(engine, filePath, content, context);
})
// Render page using parser (markdown -> HTML)
.then(parser.page).get('content')
// Post processing for templating syntax
.then(function(content) {
return Templating.postRender(engine, content);
})
// Return new page
.then(function(content) {
return resultPage.set('content', content);
})
// Call final hook
.then(function(currentPage) {
return callPageHook('page', output, currentPage);
});
})
// Render templating syntax
.then(function(content) {
return Templating.render(engine, filePath, content, context);
})
// Render page using parser (markdown -> HTML)
.then(parser.page).get('content')
// Post processing for templating syntax
.then(function(content) {
return Templating.postRender(engine, content);
})
// Return new page
.then(function(content) {
return resultPage.set('content', content);
})
// Call final hook
.then(function(currentPage) {
return callPageHook('page', output, currentPage);
});
});
);
}
module.exports = generatePage;
+15 -11
View File
@@ -1,3 +1,4 @@
var timing = require('../utils/timing');
/**
List all assets in a book
@@ -16,17 +17,20 @@ function listAssets(book, pages) {
var glossary = book.getGlossary();
var glossaryFile = glossary.getFile().getPath();
return fs.listAllFiles()
.then(function(files) {
return files.filterNot(function(file) {
return (
book.isContentFileIgnored(file) ||
pages.has(file) ||
file !== summaryFile ||
file !== glossaryFile
);
});
});
return timing.measure(
'parse.listAssets',
fs.listAllFiles()
.then(function(files) {
return files.filterNot(function(file) {
return (
book.isContentFileIgnored(file) ||
pages.has(file) ||
file !== summaryFile ||
file !== glossaryFile
);
});
})
);
}
module.exports = listAssets;
+6 -2
View File
@@ -1,4 +1,5 @@
var Promise = require('../utils/promise');
var timing = require('../utils/timing');
var Book = require('../models/book');
var parseIgnore = require('./parseIgnore');
@@ -57,7 +58,9 @@ function parseMultilingualBook(book) {
@return {Promise<Book>}
*/
function parseBook(book) {
return Promise(book)
return timing.measure(
'parse.book',
Promise(book)
.then(parseIgnore)
.then(parseConfig)
.then(parseLanguages)
@@ -67,7 +70,8 @@ function parseBook(book) {
} else {
return parseBookContent(resultBook);
}
});
})
);
}
module.exports = parseBook;
+22 -18
View File
@@ -1,5 +1,6 @@
var Immutable = require('immutable');
var timing = require('../utils/timing');
var Page = require('../models/page');
var walkSummary = require('./walkSummary');
@@ -14,27 +15,30 @@ function parsePagesList(book) {
var summary = book.getSummary();
var map = Immutable.OrderedMap();
return walkSummary(summary, function(article) {
if (!article.isPage()) return;
return timing.measure(
'parse.listPages',
walkSummary(summary, function(article) {
if (!article.isPage()) return;
var filepath = article.getPath();
var filepath = article.getPath();
// Is the page ignored?
if (book.isContentFileIgnored(filepath)) return;
// Is the page ignored?
if (book.isContentFileIgnored(filepath)) return;
return fs.statFile(filepath)
.then(function(file) {
map = map.set(
filepath,
Page.createForFile(file)
);
}, function() {
// file doesn't exist
});
})
.then(function() {
return map;
});
return fs.statFile(filepath)
.then(function(file) {
map = map.set(
filepath,
Page.createForFile(file)
);
}, function() {
// file doesn't exist
});
})
.then(function() {
return map;
})
);
}
+16 -11
View File
@@ -2,6 +2,7 @@ var path = require('path');
var Immutable = require('immutable');
var Promise = require('../utils/promise');
var timing = require('../utils/timing');
var findInstalled = require('./findInstalled');
/**
@@ -11,18 +12,22 @@ var findInstalled = require('./findInstalled');
@return {Promise<OrderedMap<String:Plugin>>}
*/
function findForBook(book) {
return Promise.all([
findInstalled(path.resolve(__dirname, '../..')),
findInstalled(book.getRoot())
])
return timing.measure(
'plugins.findForBook',
// Merge all plugins
.then(function(results) {
return Immutable.List(results)
.reduce(function(out, result) {
return out.merge(result);
}, Immutable.OrderedMap());
});
Promise.all([
findInstalled(path.resolve(__dirname, '../..')),
findInstalled(book.getRoot())
])
// Merge all plugins
.then(function(results) {
return Immutable.List(results)
.reduce(function(out, result) {
return out.merge(result);
}, Immutable.OrderedMap());
})
);
}
+3
View File
@@ -4,6 +4,7 @@ var Immutable = require('immutable');
var Promise = require('../utils/promise');
var error = require('../utils/error');
var timing = require('../utils/timing');
var validatePlugin = require('./validatePlugin');
@@ -72,6 +73,8 @@ function loadPlugin(book, plugin) {
.then(validatePlugin);
p = timing.measure('plugin.load', p);
logger.info('loading plugin "' + name + '"... ');
return logger.info.promise(p);
}
+89
View File
@@ -0,0 +1,89 @@
var Immutable = require('immutable');
var is = require('is');
var timers = {};
var startDate = Date.now();
/**
Mesure an operation
@parqm {String} type
@param {Promise} p
@return {Promise}
*/
function measure(type, p) {
timers[type] = timers[type] || {
type: type,
count: 0,
total: 0,
min: undefined,
max: 0
};
var start = Date.now();
return p
.fin(function() {
var end = Date.now();
var duration = (end - start);
timers[type].count ++;
timers[type].total += duration;
if (is.undefined(timers[type].min)) {
timers[type].min = duration;
} else {
timers[type].min = Math.min(timers[type].min, duration);
}
timers[type].max = Math.max(timers[type].max, duration);
});
}
/**
Return a milliseconds number as a second string
@param {Number} ms
@return {String}
*/
function time(ms) {
if (ms < 1000) {
return (ms.toFixed(0)) + 'ms';
}
return (ms/1000).toFixed(2) + 's';
}
/**
Dump all timers to a logger
@param {Logger} logger
*/
function dump(logger) {
var prefix = ' > ';
var measured = 0;
var totalDuration = Date.now() - startDate;
Immutable.Map(timers)
.valueSeq()
.sortBy(function(timer) {
measured += timer.total;
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));
logger.debug.ln('---------------------------');
});
logger.debug.ln(time(totalDuration - measured) + ' spent in non-mesured sections');
}
module.exports = {
measure: measure,
dump: dump
};