Skip to content

Commit

Permalink
Merge pull request skytap#5 from jonsu/feature/browser-id-logging
Browse files Browse the repository at this point in the history 
Adding browser context id and updating logging params
  • Loading branch information
@scottbrady
scottbrady committed Jan 17, 2015
2 parents b9ad477 + d96c9ec commit a1f1e78
Show file tree
Hide file tree
Showing 7 changed files with 87 additions and 24 deletions.
10 changes: 5 additions & 5 deletions lib/controller.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -199,13 +199,13 @@ _.extend(Controller.prototype, events.EventEmitter.prototype, {
});

response.render(templateName, { layout : templateValues.layout }, function (error, result) {
Logger.debug(request, request.method + ' ' + request.url + ' DONE');
Logger.debug(request.method + ' ' + request.url + ' DONE', request);

Logger.info(
request,
'Request for ' + request.minorjs.controller.name + '#' +
request.minorjs.controller.action + ' done in ' +
(Date.now() - request.minorjs.start) + 'ms'
(Date.now() - request.minorjs.start) + 'ms',
request
);

if (error) {
Expand Down Expand Up @@ -243,7 +243,7 @@ _.extend(Controller.prototype, events.EventEmitter.prototype, {
fullError = this._getFullError(request, response, error, incidentId),
userError;

Logger.error(request, fullError);
Logger.error(fullError, request);

if (request.xhr) {
this._handleXhrError(request, response, error);
Expand Down Expand Up @@ -296,7 +296,7 @@ _.extend(Controller.prototype, events.EventEmitter.prototype, {
var incidentId = Indentifier.generate(),
fullError = this._getFullError(request, response, error, incidentId),
userError = this._getUserError(request, response, error, incidentId);
Logger.error(request, 'Could not render error page. ' + fullError);
Logger.error('Could not render error page. ' + fullError, request);
response.send(userError);
} else {
this._handleError(request, response, error);
Expand Down
4 changes: 2 additions & 2 deletions lib/filter.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -97,11 +97,11 @@ var Filter = {
var result;

try {
Logger.debug(request, "Running the " + self.filters[filter].moduleName + " filter");
Logger.debug("Running the " + self.filters[filter].moduleName + " filter", request);
result = self.filters[filter].process(request, response, next);
return Q.isPromise(result) ? result : Q(result);
} catch (e) {
Logger.debug(request, "Rejected " + self.filters[filter].moduleName + " filter");
Logger.debug("Rejected " + self.filters[filter].moduleName + " filter", request);
return Q.reject(e);
}
};
Expand Down
4 changes: 2 additions & 2 deletions lib/logger.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -57,11 +57,11 @@ var Logger = {
*
* Output a debug log of the number of milliseconds it took to complete a task.
**/
profile : function (name, start, end) {
profile : function (name, start, end, contextId) {
if (typeof end === 'undefined') {
end = Date.now();
}
this._log('debug', null, 'Performance: ' + name + ' took ' + (end - start) + 'ms');
this._log('debug', 'Performance: ' + name + ' took ' + (end - start) + 'ms', null, contextId);
},

//////////////////////////////////////////////////////////////////////////
Expand Down
6 changes: 3 additions & 3 deletions lib/minor.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -111,7 +111,7 @@ _.extend(Minor.prototype, {

Logger.profile('Load MinorJS', self.start);

Logger.info(null, "MinorJS HTTP server listening on port " + port);
Logger.info("MinorJS HTTP server listening on port " + port);
})
.fail(function (error) {
console.error('Error loading controllers and registering routes.\n\n', error.stack);
Expand Down Expand Up @@ -277,7 +277,7 @@ _.extend(Minor.prototype, {
process.on('uncaughtException', function handleException (error) {
console.log(error.stack)

Logger.error(null, error.stack);
Logger.error(error.stack);

if (Environment.isWorker()) {
cluster.worker.disconnect();
Expand All @@ -287,7 +287,7 @@ _.extend(Minor.prototype, {
});

this.app.on('error', function handleError (error) {
Logger.error(null, error.stack);
Logger.error(error.stack);
});
},

Expand Down
16 changes: 8 additions & 8 deletions lib/router.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,8 @@ var path = require('path'),
Filter = require('./filter'),
Environment = require('./environment'),
Config = require('./config'),
Indentifier = require('./identifier');
Indentifier = require('./identifier'),
uuid = require('node-uuid');

/**
* Module for loading controllers and wiring up routes.
Expand Down Expand Up @@ -285,7 +286,6 @@ var Router = {
page = this._getPage(request),
controllerParts = this._parseControllerName(request, url),
controllerName = this._getControllerName(controllerParts);

request.minorjs = {
page : page,
controller : {
Expand All @@ -294,10 +294,10 @@ var Router = {
parts : controllerParts
},
start : startTime,
requestToken : Indentifier.generate()
requestToken : Indentifier.generate(),
browserId : request.get('Browser-Context-Id') ? request.get('Browser-Context-Id') : 'browser.' + uuid.v4().replace(/-/g, '')
};

Logger.info(request, 'Request for ' + controllerName + '#' + route.handler);
Logger.info('Request for ' + controllerName + '#' + route.handler, request);

Filter.run(filters, request, response, next)
.then(function runController (success) {
Expand Down Expand Up @@ -445,11 +445,11 @@ var Router = {
controller.emit('request-started', request);

Logger.debug(
request,
request.method + ' ' + request.url + ' START. ' +
'PARAMS: ' + JSON.stringify(request.params) + ', ' +
'BODY: ' + JSON.stringify(request.body) + ', ' +
'QUERY: ' + JSON.stringify(request.query)
'QUERY: ' + JSON.stringify(request.query),
request
);

if (Environment.isDevelopment()) {
Expand All @@ -473,7 +473,7 @@ var Router = {
try {
Controller = require(controllerPath);
} catch (error) {
Logger.error(null, "Error while loading controller '" + controllerPath + "': " + error.stack);
Logger.error("Error while loading controller '" + controllerPath + "': " + error.stack);

if (Environment.isWorker()) {
process.emit('message', 'shutdown');
Expand Down
2 changes: 1 addition & 1 deletion test/unit/lib/logger_test.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -66,7 +66,7 @@ describe('lib/logger.js', function () {
start = 12345;

Module = require('../../../lib/logger');
Module._log = sinon.spy(function (level, request, message) {
Module._log = sinon.spy(function (level, message, request) {
level.should.eql('debug');
message.should.match(/Performance: some name took [0-9]*ms/);
});
Expand Down
69 changes: 66 additions & 3 deletions test/unit/lib/router_test.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -295,8 +295,10 @@ describe('lib/router.js', function () {
url : 'some url',
route : {
path : 'some path'
}
},
get : sinon.spy()
},

response = {},
next = {},
Filter = {
Expand Down Expand Up @@ -328,7 +330,6 @@ describe('lib/router.js', function () {

done();
});

Module._handleRequest(url, route, startTime, controller, request, response, next);
});

Expand All @@ -350,7 +351,8 @@ describe('lib/router.js', function () {
url : 'some url',
route : {
path : 'some path'
}
},
get : sinon.spy()
},
response = {},
next = {},
Expand Down Expand Up @@ -386,6 +388,67 @@ describe('lib/router.js', function () {

Module._handleRequest(url, route, startTime, controller, request, response, next);
});

it('should handle browser id generation', function (done) {
var url = 'some/url',
filters = [ 'some filters' ],
controller = {
getFilters : sinon.spy(function () {
return filters;
})
},
route = {
handler : 'some handler'
},
req_w_id = {
url : 'some url',
route : {
path : 'some path'
},
'Browser-Context-Id' : 'some browser id',
get : sinon.spy(function(key){
return this[key];
})
},
req_no_id = {
url : 'some url',
route : {
path : 'some path'
},
get : sinon.spy(function(key){
return this[key];
})
},

response = {},
next = {},
Filter = {
run : sinon.spy(function () {
return Q(true);
})
},
Logger = {
info : sinon.spy()
},
startTime = Date.now();

Backhoe.mock(require.resolve('../../../lib/logger'), Logger);

Module = require('../../../lib/router');

Module._runController = sinon.spy();
Module._handleError = sinon.spy();

Module._handleRequest(url, route, startTime, controller, req_w_id, response, next);
req_w_id.get.calledWith('Browser-Context-Id');
req_w_id.minorjs.browserId.should.eql('some browser id');

Module._handleRequest(url, route, startTime, controller, req_no_id, response, next);
req_no_id.get.calledWith('Browser-Context-Id');
req_no_id.minorjs.browserId.indexOf('browser').should.eql(0);

done();
});
});

describe('_handleDevelopmentRequest', function () {
Expand Down

0 comments on commit a1f1e78

Please sign in to comment.