Add profiler support

Closes #142
This commit is contained in:
Sandro Santilli 2014-03-19 18:34:21 +01:00
parent 62e5d2b73c
commit 2cbdc4c38c
10 changed files with 70 additions and 8 deletions

View File

@ -5,6 +5,7 @@ New features:
* Add optional support for rollbar (#137)
* Add '/version' endpoint (#138)
* Add profiler support (#142)
Enhancements:

View File

@ -27,6 +27,7 @@ var express = require('express')
, zlib = require('zlib')
, util = require('util')
, spawn = require('child_process').spawn
, Profiler = require('step-profiler')
, Meta = require('cartodb-redis')({
host: global.settings.redis_host,
port: global.settings.redis_port
@ -85,6 +86,14 @@ if ( global.log4js ) {
app.use(express.logger(loggerOpts));
}
// Use step-profiler
if ( global.settings.useProfiler ) {
app.use(function(req, res, next) {
req.profiler = new Profiler({});
next();
});
}
// Set connection timeout
if ( global.settings.hasOwnProperty('node_socket_timeout') ) {
var timeout = parseInt(global.settings.node_socket_timeout);
@ -160,6 +169,8 @@ function handleQuery(req, res) {
var tableCacheItem;
var requestProtocol = req.protocol;
if ( req.profiler ) req.profiler.start('sqlapi.query');
req.aborted = false;
req.on("close", function() {
console.log("Request closed unexpectedly (aborted?)");
@ -224,6 +235,8 @@ function handleQuery(req, res) {
var cdbuser = cdbReq.userByReq(req);
if ( req.profiler ) req.profiler.start('init');
// 1. Get database from redis via the username stored in the host header subdomain
// 2. Run the request through OAuth to get R/W user id if signed
// 3. Get the list of tables affected by the query
@ -249,6 +262,7 @@ function handleQuery(req, res) {
}
throw err;
}
if ( req.profiler ) req.profiler.done('getDatabaseName');
database = (data === "" || _.isNull(data) || _.isUndefined(data)) ? database : data;
dbopts.dbname = database;
@ -261,6 +275,7 @@ function handleQuery(req, res) {
},
function setUserGetDBHost(err, data){
if (err) throw err;
if ( req.profiler ) req.profiler.done('verifyRequest_' + ( api_key ? 'apikey' : 'oauth' ) );
user_id = data;
authenticated = ! _.isNull(user_id);
@ -275,6 +290,7 @@ function handleQuery(req, res) {
},
function setDBHostGetPassword(err, data){
if (err) throw err;
if ( req.profiler ) req.profiler.done('getUserDBHost');
dbopts.host = data || global.settings.db_host;
@ -285,6 +301,7 @@ function handleQuery(req, res) {
},
function queryExplain(err, data){
if (err) throw err;
if ( req.profiler ) req.profiler.done('getUserDBPass');
checkAborted('queryExplain');
if ( authenticated ) {
@ -310,6 +327,7 @@ function handleQuery(req, res) {
},
function setHeaders(err, result){
if (err) throw err;
if ( req.profiler ) req.profiler.done('queryExplain');
checkAborted('setHeaders');
// store explain result in local Cache
@ -386,6 +404,7 @@ function handleQuery(req, res) {
},
function generateFormat(err, result){
if (err) throw err;
if ( req.profiler ) req.profiler.done('setHeaders');
checkAborted('generateFormat');
// TODO: drop this, fix UI!
@ -399,13 +418,25 @@ function handleQuery(req, res) {
skipfields: skipfields,
sql: sql,
filename: filename,
abortChecker: checkAborted
abortChecker: checkAborted,
}
if ( req.profiler ) {
opts.profiler = req.profiler;
opts.beforeSink = function() {
req.profiler.done('sendResponse');
var report = req.profiler.toString();
res.header('X-SQLAPI-Profiler', report);
};
}
formatter.sendResponse(opts, this);
},
function errorHandle(err){
if ( err ) handleException(err, res);
if ( req.profiler ) {
req.profiler.sendStats(); // TODO: do on nextTick ?
}
}
);
} catch (err) {
@ -460,12 +491,24 @@ function handleException(err, res){
// Force inline content disposition
res.header("Content-Disposition", 'inline');
if ( res.req && res.req.profiler ) {
var req = res.req;
req.profiler.done('finish');
var report = req.profiler.toString();
res.header('X-SQLAPI-Profiler', report);
}
// if the exception defines a http status code, use that, else a 400
if (!_.isUndefined(err.http_status)){
res.send(msg, err.http_status);
} else {
res.send(msg, 400);
}
if ( res.req && res.req.profiler ) {
var req = res.req;
req.profiler.sendStats();
}
}
return app;

View File

@ -221,13 +221,14 @@ ogr.prototype.toOGR_SingleFile = function(options, fmt, callback) {
ogr.prototype.sendResponse = function(opts, callback) {
var next = callback;
var reqKey = this.getKey(opts);
var qElem = new ExportRequest(opts.sink, callback);
var qElem = new ExportRequest(opts.sink, callback, opts.beforeSink);
var baking = bakingExports[reqKey];
if ( baking ) {
baking.req.push( qElem );
} else {
baking = bakingExports[reqKey] = { req: [ qElem ] };
this.generate(opts, function(err, dumpfile) {
if ( opts.profiler ) opts.profiler.done('generate');
Step (
function sendResults() {
var nextPipe = function(finish) {
@ -266,8 +267,9 @@ ogr.prototype.sendResponse = function(opts, callback) {
// TODO: put in an ExportRequest.js ----- {
function ExportRequest(ostream, callback) {
function ExportRequest(ostream, callback, beforeSink) {
this.cb = callback;
this.beforeSink = beforeSink;
this.ostream = ostream;
this.istream = null;
this.canceled = false;
@ -289,6 +291,7 @@ ExportRequest.prototype.sendFile = function (err, filename, callback) {
//console.log("Creating readable stream out of dumpfile");
this.istream = fs.createReadStream(filename)
.on('open', function(fd) {
if ( that.beforeSink ) that.beforeSink();
that.istream.pipe(that.ostream);
callback();
})

View File

@ -45,6 +45,8 @@ pg.prototype.handleQueryEnd = function(result) {
return;
}
if ( this.opts.profiler ) this.opts.profiler.done('gotRows');
//console.log("Got query end, result is "); console.dir(result);
var end = Date.now();
@ -74,8 +76,11 @@ pg.prototype.handleQueryEnd = function(result) {
if (err) throw err;
if ( that.opts.profiler ) that.opts.profiler.done('packageResult');
// return to browser
if ( out ) {
if ( that.opts.beforeSink ) that.opts.beforeSink();
that.opts.sink.send(out);
} else {
console.error("No output from transform, doing nothing ?!");
@ -111,6 +116,7 @@ pg.prototype.sendResponse = function(opts, callback) {
callback(err);
return;
}
if ( that.opts.profiler ) that.opts.profiler.done('eventedQuery');
query.on('row', that.handleQueryRow.bind(that));
query.on('end', that.handleQueryEnd.bind(that));

View File

@ -1,5 +1,6 @@
module.exports.base_url = '/api/:version';
module.exports.log_format = '[:date] :req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type]';
module.exports.useProfiler = true;
module.exports.log_format = '[:date] :req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-SQLAPI-Profiler])';
// Regular expression pattern to extract username
// from hostname. Must have a single grabbing block.
module.exports.user_from_host = '^(.*)\\.localhost';

View File

@ -1,5 +1,6 @@
module.exports.base_url = '/api/:version';
module.exports.log_format = '[:date] :req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type]';
module.exports.useProfiler = true;
module.exports.log_format = '[:date] :req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-SQLAPI-Profiler])';
// Regular expression pattern to extract username
// from hostname. Must have a single grabbing block.
module.exports.user_from_host = '^(.*)\\.cartodb\\.com$';

View File

@ -1,5 +1,6 @@
module.exports.base_url = '/api/:version';
module.exports.log_format = '[:date] :req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type]';
module.exports.useProfiler = true;
module.exports.log_format = '[:date] :req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-SQLAPI-Profiler])';
// Regular expression pattern to extract username
// from hostname. Must have a single grabbing block.
module.exports.user_from_host = '^(.*)\\.cartodb\\.com$';

View File

@ -1,5 +1,6 @@
module.exports.base_url = '/api/:version';
module.exports.log_format = '[:date] :req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type]';
module.exports.useProfiler = true;
module.exports.log_format = '[:date] :req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-SQLAPI-Profiler])';
// Regular expression pattern to extract username
// from hostname. Must have a single grabbing block.
module.exports.user_from_host = '^([^.]*)\\.';

4
npm-shrinkwrap.json generated
View File

@ -131,6 +131,10 @@
}
}
},
"step-profiler": {
"version": "0.0.1",
"from": "git://github.com/CartoDB/node-step-profiler.git#0.0.1"
},
"redis": {
"version": "0.7.1"
},

View File

@ -27,7 +27,8 @@
"node-uuid":"1.3.3",
"lru-cache":"~2.2.2",
"log4js": "~0.6.10",
"rollbar": "~0.3.1"
"rollbar": "~0.3.1",
"step-profiler": "git://github.com/CartoDB/node-step-profiler.git#0.0.1"
},
"devDependencies": {
"redis": "0.7.1",