Adding DTrace probes, updating router

.npmignore

@@ -6,6 +6,7 @@
 .eslintrc
 .gitignore
 .travis.yml
+dtrace.sh
 Gruntfile.js
 sample.js
 sample2.js

dtrace.sh

@@ -0,0 +1,12 @@
+#!/usr/bin/env bash
+
+sudo dtrace -Z -n 'woodland*:::allows{ trace(copyinstr(arg0)); trace(copyinstr(arg1)); trace(copyinstr(arg2)); }'  \
+               -n 'woodland*:::decorate{ trace(copyinstr(arg0)); trace(copyinstr(arg1)); }'  \
+               -n 'woodland*:::error{ trace(copyinstr(arg0)); trace(copyinstr(arg1)); trace(copyinstr(arg2)); }'  \
+               -n 'woodland*:::route{ trace(copyinstr(arg0)); trace(copyinstr(arg1)); trace(copyinstr(arg2)); }'  \
+               -n 'woodland*:::routes{ trace(copyinstr(arg0)); trace(copyinstr(arg1)); trace(copyinstr(arg2)); trace(copyinstr(arg3)); }'  \
+               -n 'tenso*:::etag{ trace(copyinstr(arg0)); trace(copyinstr(arg1)); trace(copyinstr(arg2)); }'  \
+               -n 'tenso*:::headers{ trace(copyinstr(arg0)); trace(copyinstr(arg1)); trace(copyinstr(arg2)); trace(copyinstr(arg3)); }'  \
+               -n 'tenso*:::rate{ trace(copyinstr(arg0)); trace(copyinstr(arg1)); trace(copyinstr(arg2)); trace(copyinstr(arg3)); trace(copyinstr(arg4)); trace(copyinstr(arg5)); trace(copyinstr(arg6)); }'  \
+               -n 'tenso*:::render{ trace(copyinstr(arg0)); trace(copyinstr(arg1)); trace(copyinstr(arg2)); }'  \
+               -n 'tenso*:::send{ trace(copyinstr(arg0)); trace(copyinstr(arg1)); trace(copyinstr(arg2)); trace(copyinstr(arg3)); }'

lib/dtrace.js

@@ -0,0 +1,11 @@
+"use strict";
+
+const d = require("dtrace-provider");
+
+module.exports = (id, ...probes) => {
+	const dtp = d.createDTraceProvider(id);
+
+	probes.forEach(p => dtp.addProbe(...p));
+
+	return dtp;
+};

lib/tenso.js

@@ -8,10 +8,11 @@ const path = require("path"),
 	precise = require("precise"),
 	moment = require("moment"),
 	eventsource = require("tiny-eventsource"),
+	dtrace = require(path.join(__dirname, "dtrace.js")),
 	middleware = require(path.join(__dirname, "middleware.js")),
 	regex = require(path.join(__dirname, "regex.js")),
 	{canGet, canModify} = require(path.join(__dirname, "shared.js")),
-	{each, explode, hypermedia, serialize} = require(path.join(__dirname, "utility.js")),
+	{each, explode, hypermedia, ms, serialize} = require(path.join(__dirname, "utility.js")),
 	renderers = require(path.join(__dirname, "renderers.js")),
 	serializers = require(path.join(__dirname, "serializers.js")),
 	Base = require(path.join(__dirname, "base.js"));
@@ -165,12 +166,23 @@ class Tenso extends Base {
 			uid: 0
 		};
 		this.etags = null;
+		this.dtrace = this.config.dtrace;
+		this.dtp = this.dtrace ? dtrace("tenso") : null;
 		this.rates = new Map();
 		this.renderers = renderers;
 		this.router = null;
 		this.serializers = serializers;
 		this.server = null;
 		this.version = "";
+
+		if (this.dtrace) {
+			this.probes.set("etag", this.dtp.addProbe("etag", "char *", "char *", "char *"));
+			this.probes.set("headers", this.dtp.addProbe("headers", "char *", "char *", "int", "char *"));
+			this.probes.set("rate", this.dtp.addProbe("rate", "char *", "char *", "bool", "int", "int", "int", "char *"));
+			this.probes.set("render", this.dtp.addProbe("render", "char *", "char *", "char *"));
+			this.probes.set("send", this.dtp.addProbe("send", "char *", "char *", "int", "char *"));
+			this.dtp.enable();
+		}
 	}
 
 	all (route, fn) {
@@ -200,7 +212,20 @@ class Tenso extends Base {
 	}
 
 	canETag (pathname, method, header) {
-		return this.config.etags.enabled && method === "GET" && (header !== void 0 ? this.etags.valid({"cache-control": header}) : true) && this.config.etags.invalid.filter(i => i.test(pathname)).length === 0;
+		let result, timer;
+
+		if (this.dtrace) {
+			timer = precise().start();
+		}
+
+		result = this.config.etags.enabled && method === "GET" && (header !== void 0 ? this.etags.valid({"cache-control": header}) : true) && this.config.etags.invalid.filter(i => i.test(pathname)).length === 0;
+
+		if (this.dtrace) {
+			timer.stop();
+			this.probes.get("etag").fire(() => [pathname, method, ms(timer.diff())]);
+		}
+
+		return result;
 	}
 
 	clf (req, res, headers) {
@@ -263,6 +288,12 @@ class Tenso extends Base {
 	}
 
 	headers (req, res, status, body, headers) {
+		let timer;
+
+		if (this.dtrace) {
+			timer = precise().start();
+		}
+
 		if (req.protect && (headers["cache-control"] || "").includes("private") === false) {
 			headers["cache-control"] = (headers["cache-control"] || res.getHeader("cache-control") || "").replace(/(private|public)(,\s)?/g, "");
 			headers["cache-control"] = `private${(headers["cache-control"].length > 0 ? ", " : "")}${(headers["cache-control"] || "")}`;
@@ -325,6 +356,11 @@ class Tenso extends Base {
 			delete headers["content-length"];
 		}
 
+		if (this.dtrace) {
+			timer.stop();
+			this.probes.get("headers").fire(() => [req.parsed.pathname, req.method, status, ms(timer.diff())]);
+		}
+
 		this.log("Generated headers", "debug");
 	}
 
@@ -341,6 +377,12 @@ class Tenso extends Base {
 	}
 
 	rate (req, fn) {
+		let timer;
+
+		if (this.dtrace) {
+			timer = precise().start();
+		}
+
 		const config = this.config.rate,
 			id = req.sessionID || req.ip;
 		let valid = true,
@@ -375,18 +417,29 @@ class Tenso extends Base {
 			valid = false;
 		}
 
+		if (this.dtrace) {
+			timer.stop();
+			this.probes.get("rate").fire(() => [req.parsed.pathname, req.method, valid, limit, remaining, reset, ms(timer.diff())]);
+		}
+
 		return [valid, limit, remaining, reset];
 	}
 
 	render (req, res, arg, headers = {}) {
+		let timer;
+
+		if (this.dtrace) {
+			timer = precise().start();
+		}
+
 		if (arg === null) {
 			arg = "null";
 		}
 
 		let format = "",
 			accepts = explode(headers["content-type"] || req.parsed.searchParams.get("format") || req.headers.accept || format, ","),
 			decorated = res.getHeaders(),
-			renderer;
+			renderer, result;
 
 		each(accepts, i => {
 			if (format.length === 0) {
@@ -411,7 +464,14 @@ class Tenso extends Base {
 			}
 		});
 
-		return renderer(arg, req, headers, format === "text/html" ? this.config.template : void 0);
+		result = renderer(arg, req, headers, format === "text/html" ? this.config.template : void 0);
+
+		if (this.dtrace) {
+			timer.stop();
+			this.probes.get("render").fire(() => [req.parsed.pathname, req.method, ms(timer.diff())]);
+		}
+
+		return result;
 	}
 
 	renderer (mimetype, fn) {
@@ -421,7 +481,11 @@ class Tenso extends Base {
 	}
 
 	async send (req, res, body = "", status = 200, headers = {}) {
-		let result;
+		let result, timer;
+
+		if (this.dtrace) {
+			timer = precise().start();
+		}
 
 		if (res.headersSent === false) {
 			this.headers(req, res, status, body, headers);
@@ -446,6 +510,11 @@ class Tenso extends Base {
 			result = body;
 		}
 
+		if (this.dtrace) {
+			timer.stop();
+			this.probes.get("send").fire(() => [req.parsed.pathname, req.method, status, ms(timer.diff())]);
+		}
+
 		return result;
 	}
 

lib/utility.js

@@ -701,6 +701,10 @@ function serialize (req, arg, status = 200, headers = {}) {
 	return result;
 }
 
+function ms (arg) {
+	return `${Number(arg / 1e6).toFixed(2)} ms`;
+}
+
 module.exports = {
 	auth,
 	bootstrap,
@@ -709,6 +713,7 @@ module.exports = {
 	each,
 	explode,
 	hypermedia,
+	ms,
 	serialize,
 	sort
 };

package.json

@@ -45,7 +45,7 @@
     "tiny-merge": "^1.0.0",
     "tiny-uuid4": "^1.0.1",
     "tiny-xml": "^2.0.0",
-    "woodland": "^7.4.1",
+    "woodland": "^7.4.2",
     "yamljs": "^0.3.0",
     "yargs": "^12.0.5"
   },

sample.js

@@ -25,5 +25,6 @@ require("./index.js")({
 	},
 	security: {
 		csrf: false
-	}
+	},
+	dtrace: true
 });