0001-Added-performance-instrumentation-to-routes.js-and-m.patch

From 36310504086eac9d4575b5baedd25de298d17dde Mon Sep 17 00:00:00 2001
From: Arlo Breault <abreault@wikimedia.org>
Date: Wed, 14 Jan 2015 14:03:26 -0800
Subject: [PATCH] Added performance instrumentation to routes.js and
 mediawiki.SelectiveSerializer.js. Also added node-txstatsd wrapper to
 mediawiki.Util.js and node-txstatsd version to package.json

Change-Id: I973d8379816b8bebe7fc6794f4cde0ca117198a9
---
 api/routes.js                        | 12 +++++++-
 lib/mediawiki.SelectiveSerializer.js | 18 ++++++++++-
 lib/mediawiki.Util.js                | 58 +++++++++++++++++++++++++++++++++++-
 package.json                         |  3 +-
 4 files changed, 87 insertions(+), 4 deletions(-)

diff --git a/api/routes.js b/api/routes.js
index cd6d61f..3b5734c 100644
--- a/api/routes.js
+++ b/api/routes.js
@@ -21,11 +21,15 @@ var MWParserEnv = require( mp + 'mediawiki.parser.environment.js' ).MWParserEnvi
 	LogData = require( mp + 'LogData.js' ).LogData,
 	DU = require( mp + 'mediawiki.DOMUtils.js' ).DOMUtils,
 	ApiRequest = require( mp + 'mediawiki.ApiRequest.js' ),
-	Diff = require( mp + 'mediawiki.Diff.js' ).Diff;
+	Diff = require( mp + 'mediawiki.Diff.js' ).Diff,
+	rbUtils = require( np + './mediawiki.Util.js' ).rbUtil;
 
 var ParsoidCacheRequest = ApiRequest.ParsoidCacheRequest,
 	TemplateRequest = ApiRequest.TemplateRequest;
 
+// Initialize statsd with Hostname and Port Number
+var stats = new rbUtils.StatsD("statsd.eqiad.wmnet", 8125);
+
 module.exports = function( parsoidConfig ) {
 
 var routes = {};
@@ -663,7 +667,10 @@ routes.post_rtForm = function( req, res ) {
 
 routes.get_article = function( req, res ) {
 	// Regular article parsing
+	stats.startTimer("wt2html_time");
 	wt2html( req, res );
+	stats.stopTimer("wt2html_time");
+	stats.count("wt2htmlreq"); 
 };
 
 routes.post_article = function( req, res ) {
@@ -673,7 +680,10 @@ routes.post_article = function( req, res ) {
 		wt2html( req, res, body.wt );
 	} else {
 		// Regular and form-based article serialization
+		stats.startTimer("html2wt_time");
 		html2wt( req, res, body.html || body.content || '' );
+		stats.startTimer("html2wt_time");
+		stats.count("html2wtreq");
 	}
 };
 
diff --git a/lib/mediawiki.SelectiveSerializer.js b/lib/mediawiki.SelectiveSerializer.js
index 7128d63..550509e 100644
--- a/lib/mediawiki.SelectiveSerializer.js
+++ b/lib/mediawiki.SelectiveSerializer.js
@@ -13,7 +13,10 @@ var WikitextSerializer = require( './mediawiki.WikitextSerializer.js' ).Wikitext
 	ParserPipelineFactory = require('./mediawiki.parser.js').ParserPipelineFactory,
 	DOMDiff = require('./mediawiki.DOMDiff.js').DOMDiff,
 	ParsoidCacheRequest = require('./mediawiki.ApiRequest.js').ParsoidCacheRequest,
-	async = require('async');
+	async = require('async'),
+	rbUtils = require('./mediawiki.Util.js').rbUtil;
+
+var stats = new rbUtils.StatsD("statsd.eqiad.wmnet", 8125);
 
 /**
  * @class
@@ -56,10 +59,17 @@ var SSP = SelectiveSerializer.prototype;
  */
 SSP.doSerializeDOM = function( err, doc, cb, finalcb ) {
 	var self = this;
+	// Instantize Timers to measure Time to DOM Diff 
+	stats.startTimer("time2FullSerialization");
+	stats.startTimer("time2PartSerialization");
+	stats.startTimer("time2NoSerialization");
 
 	if ( err || (!this.env.page.dom && !this.env.page.domdiff) || !this.env.page.src) {
 		// If there's no old source, fall back to non-selective serialization.
 		this.wts.serializeDOM( doc, cb, false, finalcb );
+		stats.stopTimer("time2FullSerialization");
+		// Increment count of # of Full Serializations
+		stats.count("countFullSerialization");
 	} else {
 		// Use provided diff-marked DOM (used during testing)
 		// or generate one (used in production)
@@ -68,6 +78,8 @@ SSP.doSerializeDOM = function( err, doc, cb, finalcb ) {
 		if ( ! diff.isEmpty ) {
 
 			doc = diff.dom;
+			// Increment count of # of Partial Serializations
+			stats.count("countPartSerialization");
 
 			// Add the serializer info
 			// new DiffToSelserConverter(this.env, doc).convert();
@@ -81,10 +93,14 @@ SSP.doSerializeDOM = function( err, doc, cb, finalcb ) {
 
 			// Call the WikitextSerializer to do our bidding
 			this.wts.serializeDOM( doc, cb, true, finalcb );
+			stats.stopTimer("time2PartSerialization");
 		} else {
 			// Nothing was modified, just re-use the original source
 			cb( this.env.page.src );
 			finalcb();
+			// Increment # of No Serialization 
+			stats.count("countNoSerialization"); 
+			stats.stopTimer("time2NoSerialization");
 		}
 	}
 };
diff --git a/lib/mediawiki.Util.js b/lib/mediawiki.Util.js
index 3993e77..8f85ac5 100644
--- a/lib/mediawiki.Util.js
+++ b/lib/mediawiki.Util.js
@@ -10,7 +10,8 @@ var async = require('async'),
 	request = require( 'request' ),
 	entities = require( 'entities' ),
 	TemplateRequest = require( './mediawiki.ApiRequest.js' ).TemplateRequest,
-	Consts = require('./mediawiki.wikitext.constants.js').WikitextConstants;
+	Consts = require('./mediawiki.wikitext.constants.js').WikitextConstants,
+	StatsD = require('node-txstatsd');
 
 
 // This is a circular dependency.  Don't use anything from defines at module
@@ -1472,6 +1473,61 @@ Util.retryingHTTPRequest = function (retries, requestOptions, cb) {
 /* Magic words masquerading as templates. */
 Util.magicMasqs = new Set(["defaultsort", "displaytitle"]);
 
+var rbUtil = {};
+
+// Timer that can report to StatsD
+rbUtil.StatsD = function ( statsdHost, statsdPort ) {
+    var timers = {};
+    var statsd = new StatsD(
+            statsdHost,
+            statsdPort,
+            'restbase.routes.',
+            '',
+            true,  // is txstatsd
+            false, // Don't globalize, we're doing that here
+            true  // Do cache DNS queries
+    );
+
+    function makeName(name) {
+        // See https://github.com/etsy/statsd/issues/110
+        // Only [\w_.-] allowed, with '.' being the hierarchy separator.
+        return name.replace( /[^\/a-zA-Z0-9\.\-]/g, '-' )
+                   .replace(/\//g, '_');
+    }
+
+    this.startTimer = function (name) {
+        timers[name] = Date.now();
+    };
+
+    this.stopTimer = function (name, suffix) {
+        var startTime = timers[name];
+        if (!startTime) {
+            throw new Error('Tried to stop a timer that does not exist: ' + name);
+        }
+        var delta = Date.now() - startTime;
+
+        name = makeName(name);
+        if (Array.isArray(suffix)) {
+            // Send several timings at once
+            var stats = suffix.map(function(s) {
+                return name + (s ? '.' + s : '');
+            });
+            statsd.sendAll(stats, delta, 'ms');
+        } else {
+            suffix = suffix ? '.' + suffix : '';
+            statsd.timing(makeName(name) + suffix, delta);
+        }
+        return delta;
+    };
+
+    this.count = function (name, suffix) {
+        suffix = suffix ? '.' + suffix : '';
+        statsd.increment(makeName(name) + suffix);
+    };
+};
+
+
 if (typeof module === "object") {
 	module.exports.Util = Util;
+	module.exports.rbUtil = rbUtil;
 }
diff --git a/package.json b/package.json
index b21cf63..fcacf40 100644
--- a/package.json
+++ b/package.json
@@ -20,7 +20,8 @@
 		"prfun": "~1.0.2",
 		"request": "~2.40.0",
 		"simplediff": "~0.1.1",
-		"yargs": "~1.3.1"
+		"yargs": "~1.3.1",
+		"node-txstatsd": "~0.1.5"
 	},
 	"devDependencies": {
 		"chai": "~1.9.1",
-- 
2.2.2