add some time instrumentation

This commit is contained in:
Konstantin Käfer 2011-01-27 10:06:56 -05:00
parent 8f8b014dc0
commit 4c40bcc2c5
2 changed files with 49 additions and 24 deletions

View File

@ -76,6 +76,7 @@ fs.readFile(input, 'utf-8', function (e, data) {
new mess.Renderer({ new mess.Renderer({
filename: input, filename: input,
debug: options.debug,
local_data_dir: path.dirname(input), local_data_dir: path.dirname(input),
}).render(data, function(err, output) { }).render(data, function(err, output) {
if (err) { if (err) {
@ -88,7 +89,7 @@ fs.readFile(input, 'utf-8', function (e, data) {
sys.puts(output); sys.puts(output);
} else { } else {
var duration = (+new Date) - start; var duration = (+new Date) - start;
console.log('Benchmark: ' + (duration / 1000) + 'ms'); console.log('Benchmark: ' + (duration) + 'ms');
} }
} }
}); });

View File

@ -16,7 +16,8 @@ require.paths.unshift(path.join(__dirname, '..', 'lib'));
*/ */
mess.Renderer = function Renderer(env) { mess.Renderer = function Renderer(env) {
env = _.extend(env, {}); env = _.extend({}, env);
if (!env.debug) env.debug = false;
if (!env.data_dir) env.data_dir = '/tmp/'; if (!env.data_dir) env.data_dir = '/tmp/';
if (!env.local_data_dir) env.local_data_dir = ''; if (!env.local_data_dir) env.local_data_dir = '';
if (!env.validation_data) env.validation_data = false; if (!env.validation_data) env.validation_data = false;
@ -180,19 +181,21 @@ mess.Renderer = function Renderer(env) {
function compileStyles(e, results) { function compileStyles(e, results) {
var options = {}, var options = {},
group = this.group(); group = this.group();
for (var i = 0, l = results.length; i < l; i++) { results.forEach(function(result) {
var next = group(); var next = group();
var parsingTime = +new Date;
new mess.Parser(_.extend(_.extend({ new mess.Parser(_.extend(_.extend({
filename: results[i][0] filename: result[0]
}, that.env), this.env)).parse(results[i][1], }, that.env), this.env)).parse(result[1],
function(err, tree) { function(err, tree) {
if (err) { if (err) {
mess.writeError(err, options); mess.writeError(err, options);
throw err; throw err;
} else { } else {
if (env.debug) console.warn('Parsing time: ' + ((new Date - parsingTime)) + 'ms (' + result[0] + ')');
try { try {
next(err, [ next(err, [
results[i][0], result[0],
tree]); tree]);
return; return;
} catch (e) { } catch (e) {
@ -201,7 +204,7 @@ mess.Renderer = function Renderer(env) {
} }
} }
}); });
} });
}, },
function waitForCompilation(err, res) { function waitForCompilation(err, res) {
callback(err, m, res); callback(err, m, res);
@ -215,6 +218,7 @@ mess.Renderer = function Renderer(env) {
* symbolizer each * symbolizer each
*/ */
splitSymbolizers: function(definitions) { splitSymbolizers: function(definitions) {
var splitTime = +new Date;
var bySymbolizer = {}; var bySymbolizer = {};
for (var i = 0; i < definitions.length; i++) { for (var i = 0; i < definitions.length; i++) {
definitions[i].symbolizers().forEach(function(sym) { definitions[i].symbolizers().forEach(function(sym) {
@ -226,6 +230,7 @@ mess.Renderer = function Renderer(env) {
definitions[i].filterSymbolizer(sym)); definitions[i].filterSymbolizer(sym));
}); });
} }
if (env.debug) console.warn('Splitting symbolizers: ' + ((new Date - splitTime)) + 'ms');
return bySymbolizer; return bySymbolizer;
}, },
@ -235,6 +240,7 @@ mess.Renderer = function Renderer(env) {
* ancestors to them. * ancestors to them.
*/ */
processChain: function(definitions) { processChain: function(definitions) {
var processTime = +new Date();
// definitions are ordered in specificity, // definitions are ordered in specificity,
// high to low // high to low
// //
@ -267,7 +273,9 @@ mess.Renderer = function Renderer(env) {
} }
} }
return this.resolveConditions(winners); if (env.debug) console.warn('Processing time: ' + ((new Date - processTime)) + 'ms');
return winners;
}, },
removeDuplicateSelectors: function(selectors) { removeDuplicateSelectors: function(selectors) {
@ -301,26 +309,29 @@ mess.Renderer = function Renderer(env) {
}, },
resolveConditions: function(definitions) { resolveConditions: function(definitions) {
var resolvingTime = +new Date;
var mergeTimeTotal = 0;
var rules = []; var rules = [];
var previousSelectors = []; var previousSelectors = [];
// detect non-conflicting rulesets // detect non-conflicting rulesets
var key = null, // var key = null,
shortcut = true, // shortcut = true,
filters; // filters;
for (var i = 0; i < definitions.length; i++) { // for (var i = 0; i < definitions.length; i++) {
filters = definitions[i].selector.filters; // filters = definitions[i].selector.filters;
if (!(filters.length && // if (!(filters.length &&
shortcut && (((key == null) && (key = filters[0].key)) || // shortcut && (((key == null) && (key = filters[0].key)) ||
(key == filters[0].key)) && // (key == filters[0].key)) &&
(filters.length == 1) && // (filters.length == 1) &&
(filters[0].op.value == '='))) { // (filters[0].op.value == '='))) {
shortcut = false; // shortcut = false;
break; // break;
} // }
} // }
//
// if (shortcut) return definitions;
if (shortcut) return definitions;
for (var i = 0; i < definitions.length; i++) { for (var i = 0; i < definitions.length; i++) {
if (!definitions[i].selector.sound()) { if (!definitions[i].selector.sound()) {
@ -331,6 +342,7 @@ mess.Renderer = function Renderer(env) {
var selectors = [ definitions[i].selector.clone() ]; var selectors = [ definitions[i].selector.clone() ];
// Add the negated previous selectors. // Add the negated previous selectors.
for (var j = 0; j < previousSelectors.length; j++) { for (var j = 0; j < previousSelectors.length; j++) {
for (var k = selectors.length - 1; k >= 0; k--) { for (var k = selectors.length - 1; k >= 0; k--) {
var splitSelectors = selectors[k].mergeOrConditions(previousSelectors[j]); var splitSelectors = selectors[k].mergeOrConditions(previousSelectors[j]);
@ -346,6 +358,7 @@ mess.Renderer = function Renderer(env) {
} }
} }
} }
previousSelectors.push(definitions[i].selector.negate()); previousSelectors.push(definitions[i].selector.negate());
selectors = this.removeDuplicateSelectors(selectors); selectors = this.removeDuplicateSelectors(selectors);
@ -358,6 +371,8 @@ mess.Renderer = function Renderer(env) {
} }
} }
if (env.debug) console.warn('Resolving time: ' + ((new Date - resolvingTime)) + 'ms');
return rules; return rules;
}, },
@ -432,10 +447,14 @@ mess.Renderer = function Renderer(env) {
for (var sym in bySymbolizer) { for (var sym in bySymbolizer) {
// Create styles out of chains of one-symbolizer rules, // Create styles out of chains of one-symbolizer rules,
// and assign those styles to layers // and assign those styles to layers
var definitions = that.processChain(bySymbolizer[sym]);
definitions = that.resolveConditions(definitions);
var new_style = new mess.tree.Style( var new_style = new mess.tree.Style(
l.id, l.id,
sym, sym,
that.processChain(bySymbolizer[sym])); definitions);
l.styles.push(new_style.name()); l.styles.push(new_style.name());
// env.effects can be modified by this call // env.effects can be modified by this call
output.push(new_style.toXML(env)); output.push(new_style.toXML(env));
@ -492,11 +511,16 @@ mess.Renderer = function Renderer(env) {
render: function(str, callback) { render: function(str, callback) {
var m = JSON.parse(str), var m = JSON.parse(str),
that = this; that = this;
var localizingTime = +new Date;
this.localizeExternals(m, function(err, res) { this.localizeExternals(m, function(err, res) {
that.ensureSRS(res, function(err, res) { that.ensureSRS(res, function(err, res) {
that.localizeStyle(res, function(err, res) { that.localizeStyle(res, function(err, res) {
if (env.debug) console.warn('Localizing time: ' + ((new Date - localizingTime)) + 'ms');
that.style(res, function(err, m, res) { that.style(res, function(err, m, res) {
var compilingTime = +new Date;
that.template(err, m, res, function(err, res) { that.template(err, m, res, function(err, res) {
if (env.debug) console.warn('COMPILING TIME: ' + ((new Date - compilingTime)) + 'ms');
callback(err, res); callback(err, res);
}); });
}); });