diff --git a/doc/index.md b/doc/index.md index 5d3022be..09553f68 100644 --- a/doc/index.md +++ b/doc/index.md @@ -1,4 +1,5 @@ @include documentation +@include stats @include localization @include custom_static @include api/api diff --git a/doc/stats.md b/doc/stats.md new file mode 100644 index 00000000..7da69547 --- /dev/null +++ b/doc/stats.md @@ -0,0 +1,18 @@ +# Statistics +Etherpad keeps track of the goings-on inside the edit machinery. If you'd like to have a look at this, just point your browser to `/stats`. + +We currently measure: + + - totalUsers (counter) + - connects (meter) + - disconnects (meter) + - pendingEdits (counter) + - edits (timer) + - failedChangesets (meter) + - httpRequests (timer) + - http500 (meter) + - memoryUsage (gauge) + +Under the hood, we are happy to rely on [measured](https://github.com/felixge/node-measured) for all our metrics needs. + +To modify or simply access our stats in your plugin, simply `require('ep_etherpad-lite/stats')` which is a `measured.Collection`. \ No newline at end of file diff --git a/src/node/handler/PadMessageHandler.js b/src/node/handler/PadMessageHandler.js index dbb0c195..0b583661 100644 --- a/src/node/handler/PadMessageHandler.js +++ b/src/node/handler/PadMessageHandler.js @@ -36,6 +36,7 @@ var accessLogger = log4js.getLogger("access"); var _ = require('underscore'); var hooks = require("ep_etherpad-lite/static/js/pluginfw/hooks.js"); var channels = require("channels"); +var stats = require('../stats'); /** * A associative array that saves informations about a session @@ -50,6 +51,11 @@ var channels = require("channels"); var sessioninfos = {}; exports.sessioninfos = sessioninfos; +// Measure total amount of users +stats.gauge('totalUsers', function() { + return Object.keys(socketio.sockets.sockets).length +}) + /** * A changeset queue per pad that is processed by handleUserChanges() */ @@ -74,7 +80,9 @@ exports.setSocketIO = function(socket_io) * @param client the new client */ exports.handleConnect = function(client) -{ +{ + stats.meter('connects').mark(); + //Initalize sessioninfos for this new session sessioninfos[client.id]={}; } @@ -99,12 +107,23 @@ exports.kickSessionsFromPad = function(padID) */ exports.handleDisconnect = function(client) { + stats.meter('disconnects').mark(); + //save the padname of this session var session = sessioninfos[client.id]; //if this connection was already etablished with a handshake, send a disconnect message to the others if(session && session.author) { + client.get('remoteAddress', function(er, ip) { + //Anonymize the IP address if IP logging is disabled + if(settings.disableIPlogging) { + ip = 'ANONYMOUS'; + } + + accessLogger.info('[LEAVE] Pad "'+session.padId+'": Author "'+session.author+'" on client '+client.id+' with IP "'+ip+'" left the pad') + }) + //get the author color out of the db authorManager.getAuthorColorId(session.author, function(err, color) { @@ -129,15 +148,6 @@ exports.handleDisconnect = function(client) }); } - client.get('remoteAddress', function(er, ip) { - //Anonymize the IP address if IP logging is disabled - if(settings.disableIPlogging) { - ip = 'ANONYMOUS'; - } - - accessLogger.info('[LEAVE] Pad "'+session.padId+'": Author "'+session.author+'" on client '+client.id+' with IP "'+ip+'" left the pad') - }) - //Delete the sessioninfos entrys of this session delete sessioninfos[client.id]; } @@ -189,6 +199,7 @@ exports.handleMessage = function(client, message) if (sessioninfos[client.id].readonly) { messageLogger.warn("Dropped message, COLLABROOM for readonly pad"); } else if (message.data.type == "USER_CHANGES") { + stats.counter('pendingEdits').inc() padChannels.emit(message.padId, {client: client, message: message});// add to pad queue } else if (message.data.type == "USERINFO_UPDATE") { handleUserInfoUpdate(client, message); @@ -558,6 +569,9 @@ function handleUserChanges(data, cb) var client = data.client , message = data.message + // This one's no longer pending, as we're gonna process it now + stats.counter('pendingEdits').dec() + // Make sure all required fields are present if(message.data.baseRev == null) { @@ -584,6 +598,9 @@ function handleUserChanges(data, cb) var thisSession = sessioninfos[client.id]; var r, apool, pad; + + // Measure time to process edit + var stopWatch = stats.timer('edits').start(); async.series([ //get the pad @@ -637,6 +654,7 @@ function handleUserChanges(data, cb) { // There is an error in this changeset, so just refuse it client.json.send({disconnect:"badChangeset"}); + stats.meter('failedChangesets').mark(); return callback(new Error("Can't apply USER_CHANGES, because "+e.message)); } @@ -667,6 +685,7 @@ function handleUserChanges(data, cb) changeset = Changeset.follow(c, changeset, false, apool); }catch(e){ client.json.send({disconnect:"badChangeset"}); + stats.meter('failedChangesets').mark(); return callback(new Error("Can't apply USER_CHANGES, because "+e.message)); } @@ -689,6 +708,7 @@ function handleUserChanges(data, cb) if (Changeset.oldLen(changeset) != prevText.length) { client.json.send({disconnect:"badChangeset"}); + stats.meter('failedChangesets').mark(); return callback(new Error("Can't apply USER_CHANGES "+changeset+" with oldLen " + Changeset.oldLen(changeset) + " to document of length " + prevText.length)); } @@ -712,6 +732,7 @@ function handleUserChanges(data, cb) } ], function(err) { + stopWatch.end() cb(); if(err) console.warn(err.stack || err) }); @@ -797,7 +818,7 @@ exports.updatePadClients = function(pad, callback) } /** - * Copied from the Etherpad Source Code. Don't know what this methode does excatly... + * Copied from the Etherpad Source Code. Don't know what this method does excatly... */ function _correctMarkersInPad(atext, apool) { var text = atext.text; diff --git a/src/node/hooks/express/errorhandling.js b/src/node/hooks/express/errorhandling.js index 825c5f3b..087dd50e 100644 --- a/src/node/hooks/express/errorhandling.js +++ b/src/node/hooks/express/errorhandling.js @@ -1,5 +1,6 @@ var os = require("os"); var db = require('../../db/DB'); +var stats = require('ep_etherpad-lite/node/stats') exports.onShutdown = false; @@ -40,6 +41,7 @@ exports.expressCreateServer = function (hook_name, args, cb) { // allowing you to respond however you like res.send(500, { error: 'Sorry, something bad happened!' }); console.error(err.stack? err.stack : err.toString()); + stats.meter('http500').mark() }) //connect graceful shutdown with sigint and uncaughtexception diff --git a/src/node/hooks/express/specialpages.js b/src/node/hooks/express/specialpages.js index 44002461..6701726e 100644 --- a/src/node/hooks/express/specialpages.js +++ b/src/node/hooks/express/specialpages.js @@ -2,6 +2,10 @@ var path = require('path'); var eejs = require('ep_etherpad-lite/node/eejs'); exports.expressCreateServer = function (hook_name, args, cb) { + // expose current stats + args.app.get('/stats', function(req, res) { + res.json(require('ep_etherpad-lite/node/stats').toJSON()) + }) //serve index.html under / args.app.get('/', function(req, res) diff --git a/src/node/hooks/express/webaccess.js b/src/node/hooks/express/webaccess.js index efced3f7..433d5094 100644 --- a/src/node/hooks/express/webaccess.js +++ b/src/node/hooks/express/webaccess.js @@ -5,6 +5,7 @@ var settings = require('../../utils/Settings'); var randomString = require('ep_etherpad-lite/static/js/pad_utils').randomString; var hooks = require('ep_etherpad-lite/static/js/pluginfw/hooks'); var ueberStore = require('../../db/SessionStore'); +var stats = require('ep_etherpad-lite/node/stats') //checks for basic http auth exports.basicAuth = function (req, res, next) { @@ -91,10 +92,21 @@ exports.basicAuth = function (req, res, next) { exports.secret = null; exports.expressConfigure = function (hook_name, args, cb) { + // Measure response time + args.app.use(function(req, res, next) { + var stopWatch = stats.timer('httpRequests').start(); + var sendFn = res.send + res.send = function() { + stopWatch.end() + sendFn.apply(res, arguments) + } + next() + }) + // If the log level specified in the config file is WARN or ERROR the application server never starts listening to requests as reported in issue #158. // Not installing the log4js connect logger when the log level has a higher severity than INFO since it would not log at that level anyway. if (!(settings.loglevel === "WARN" || settings.loglevel == "ERROR")) - args.app.use(log4js.connectLogger(httpLogger, { level: log4js.levels.DEBUG, format: ':status, :method :url -- :response-timems'})); + args.app.use(log4js.connectLogger(httpLogger, { level: log4js.levels.DEBUG, format: ':status, :method :url'})); /* Do not let express create the session, so that we can retain a * reference to it for socket.io to use. Also, set the key (cookie diff --git a/src/node/server.js b/src/node/server.js index db75d7e3..605ce847 100755 --- a/src/node/server.js +++ b/src/node/server.js @@ -23,10 +23,15 @@ var log4js = require('log4js') , async = require('async') + , stats = require('./stats') ; log4js.replaceConsole(); +stats.gauge('memoryUsage', function() { + return process.memoryUsage().rss +}) + var settings , db , plugins @@ -48,7 +53,6 @@ async.waterfall([ plugins = require("ep_etherpad-lite/static/js/pluginfw/plugins"); hooks = require("ep_etherpad-lite/static/js/pluginfw/hooks"); hooks.plugins = plugins; - callback(); }, diff --git a/src/node/stats.js b/src/node/stats.js new file mode 100644 index 00000000..24efaf4a --- /dev/null +++ b/src/node/stats.js @@ -0,0 +1,3 @@ +var measured = require('measured') + +module.exports = measured.createCollection(); \ No newline at end of file diff --git a/src/package.json b/src/package.json index a5378813..931db163 100644 --- a/src/package.json +++ b/src/package.json @@ -38,7 +38,8 @@ "unorm" : "1.0.0", "languages4translatewiki" : "0.1.3", "swagger-node-express" : "1.2.3", - "channels" : "0.0.x" + "channels" : "0.0.x", + "measured" : "0.1.3" }, "bin": { "etherpad-lite": "./node/server.js" }, "devDependencies": {