Remove trace span functions from stack traces

Fixes #229

lib/hooks/userspace/hook-express.js

@@ -83,7 +83,7 @@ function startRootSpanForRequest(req, traceHeader) {
   // we use the path part of the url as the span name and add the full
   // url as a label
   var rootContext = agent.createRootSpanData(req.originalUrl, traceId,
-    parentSpanId);
+    parentSpanId, 3);
   rootContext.addLabel(TraceLabels.HTTP_METHOD_LABEL_KEY, req.method);
   rootContext.addLabel(TraceLabels.HTTP_URL_LABEL_KEY, url);
   rootContext.addLabel(TraceLabels.HTTP_SOURCE_IP, req.connection.remoteAddress);

lib/hooks/userspace/hook-hapi.js

@@ -82,7 +82,7 @@ function startRootSpanForRequest(req, traceHeader) {
 
   // we use the path part of the url as the span name and add the full
   // url as a label
-  var rootContext = agent.createRootSpanData(req.url, traceId, parentSpanId);
+  var rootContext = agent.createRootSpanData(req.url, traceId, parentSpanId, 3);
   rootContext.addLabel(TraceLabels.HTTP_METHOD_LABEL_KEY, req.method);
   rootContext.addLabel(TraceLabels.HTTP_URL_LABEL_KEY, url);
   rootContext.addLabel(TraceLabels.HTTP_SOURCE_IP, req.connection.remoteAddress);

lib/hooks/userspace/hook-koa.js

@@ -86,7 +86,7 @@ function startRootSpanForRequest(req, traceHeader) {
   // we use the path part of the url as the span name and add the full
   // url as a label
   const rootContext = agent.createRootSpanData(req.url, traceId,
-    parentSpanId);
+    parentSpanId, 3);
   rootContext.addLabel(TraceLabels.HTTP_METHOD_LABEL_KEY, req.method);
   rootContext.addLabel(TraceLabels.HTTP_URL_LABEL_KEY, url);
   rootContext.addLabel(TraceLabels.HTTP_SOURCE_IP, req.connection.remoteAddress);

lib/hooks/userspace/hook-restify.js

@@ -81,7 +81,7 @@ function startRootSpanForRequest(req, traceHeader) {
 
   // we use the path part of the url as the span name and add the full
   // url as a label
-  var rootContext = agent.createRootSpanData(req.url, traceId, parentSpanId);
+  var rootContext = agent.createRootSpanData(req.url, traceId, parentSpanId, 3);
   rootContext.addLabel(TraceLabels.HTTP_METHOD_LABEL_KEY, req.method);
   rootContext.addLabel(TraceLabels.HTTP_URL_LABEL_KEY, url);
   rootContext.addLabel(TraceLabels.HTTP_SOURCE_IP, req.connection.remoteAddress);

lib/span-data.js

@@ -28,13 +28,13 @@ var uid = 1;
  * @param {string} name The name of the span.
  * @param {number} parentSpanId The id of the parent span, 0 for root spans.
  * @param {boolean} isRoot Whether this is a root span.
- * @param {number=} time The time when the associated TraceSpan begins.
+ * @param {number} skipFrames the number of frames to remove from the top of the stack.
  * @constructor
  */
-function SpanData(agent, trace, name, parentSpanId, isRoot, time) {
+function SpanData(agent, trace, name, parentSpanId, isRoot, skipFrames) {
   var spanId = uid++;
   this.agent = agent;
-  this.span = new TraceSpan(name, spanId, parentSpanId, time);
+  this.span = new TraceSpan(name, spanId, parentSpanId);
   this.trace = trace;
   this.isRoot = isRoot;
   trace.spans.push(this.span);
@@ -47,7 +47,7 @@ function SpanData(agent, trace, name, parentSpanId, isRoot, time) {
     // See: https://code.google.com/p/v8-wiki/wiki/JavaScriptStackTraceApi
     //
     var origLimit = Error.stackTraceLimit;
-    Error.stackTraceLimit = agent.config().stackTraceLimit;
+    Error.stackTraceLimit = agent.config().stackTraceLimit + skipFrames;
 
     var origPrepare = Error.prepareStackTrace;
     Error.prepareStackTrace = function(error, structured) {
@@ -57,7 +57,10 @@ function SpanData(agent, trace, name, parentSpanId, isRoot, time) {
     Error.captureStackTrace(e, SpanData);
 
     var stackFrames = [];
-    e.stack.forEach(function(callSite) {
+    e.stack.forEach(function(callSite, i) {
+      if (i < skipFrames) {
+        return;
+      }
       var functionName = callSite.getFunctionName();
       var methodName = callSite.getMethodName();
       var name = (methodName && functionName) ?
@@ -78,10 +81,13 @@ function SpanData(agent, trace, name, parentSpanId, isRoot, time) {
 /**
  * Creates a child span of this span.
  * @param name The name of the child span.
+ * @param {number} skipFrames The number of caller frames to eliminate from
+ *                            stack traces.
  * @returns {SpanData} The new child trace span data.
  */
-SpanData.prototype.createChildSpanData = function(name) {
-  return new SpanData(this.agent, this.trace, name, this.span.spanId, false);
+SpanData.prototype.createChildSpanData = function(name, skipFrames) {
+  return new SpanData(this.agent, this.trace, name, this.span.spanId, false,
+      skipFrames + 1);
 };
 
 SpanData.prototype.addLabel = function(key, value) {

lib/trace-agent.js

@@ -71,12 +71,15 @@ TraceAgent.prototype.config = function() {
  * @param {string} name The name of the span.
  * @param {Object<string, string}>=} labels Labels to be attached
  *   to the newly created span.
+ * @param {number=} skipFrames The number of caller frames to eliminate from
+ *                            stack traces.
  * @return {SpanData} The newly created span.
  */
-TraceAgent.prototype.startSpan = function(name, labels) {
+TraceAgent.prototype.startSpan = function(name, labels, skipFrames) {
   var rootSpan = cls.getRootContext();
+  skipFrames = skipFrames || 0;
   if (rootSpan) {
-    var newSpan = rootSpan.createChildSpanData(name);
+    var newSpan = rootSpan.createChildSpanData(name, skipFrames + 1);
     if (labels) {
       Object.keys(labels).forEach(function(key) {
         newSpan.addLabel(key, labels[key]);
@@ -120,7 +123,7 @@ TraceAgent.prototype.runInSpan = function(name, labels, fn) {
     fn = labels;
     labels = undefined;
   }
-  var span = this.startSpan(name, labels);
+  var span = this.startSpan(name, labels, 1);
   if (fn.length === 0) {
     fn();
     this.endSpan(span);
@@ -175,12 +178,19 @@ TraceAgent.prototype.shouldTrace = function(name, options) {
 
 /**
  * Call this from inside a namespace.run().
+ * @param {string} name The name of the root span.
+ * @param {string} traceId The id of the trace owning this span.
+ * @param {string} parentId The id of the parent span.
+ * @param {number=} skipFrames The number of caller frames to eliminate from
+ *                            stack traces.
  */
-TraceAgent.prototype.createRootSpanData = function(name, traceId, parentId) {
+TraceAgent.prototype.createRootSpanData = function(name, traceId, parentId,
+    skipFrames) {
   traceId = traceId || (uuid.v4().split('-').join(''));
   parentId = parentId || '0';
+  skipFrames = skipFrames || 0;
   var trace = new Trace(0, traceId); // project number added later
-  var spanData = new SpanData(this, trace, name, parentId, true);
+  var spanData = new SpanData(this, trace, name, parentId, true, skipFrames + 1);
   cls.setRootContext(spanData);
   return spanData;
 };

lib/trace-span.js

@@ -20,13 +20,13 @@
  * Creates a trace span object.
  * @constructor
  */
-function TraceSpan(name, spanId, parentSpanId, time) {
+function TraceSpan(name, spanId, parentSpanId) {
   this.name = name;
   this.parentSpanId = parentSpanId;
   this.spanId = spanId;
   this.kind = 'RPC_CLIENT';
   this.labels = {};
-  this.startTime = (time || new Date()).toISOString();
+  this.startTime = (new Date()).toISOString();
   this.endTime = '';
 }
 

test/hooks/test-trace-express.js

@@ -144,6 +144,22 @@ describe('test-trace-express', function() {
     });
   });
 
+  it('should remove trace frames from stack', function(done) {
+    var app = express();
+    app.get('/', function (req, res) {
+      res.send(common.serverRes);
+    });
+    server = app.listen(common.serverPort, function() {
+      http.get({port: common.serverPort}, function(res) {
+        var labels = common.getMatchingSpan(expressPredicate).labels;
+        var stackTrace = JSON.parse(labels[traceLabels.STACK_TRACE_DETAILS_KEY]);
+        // Ensure that our middleware is on top of the stack
+        assert.equal(stackTrace.stack_frame[0].method_name, 'middleware');
+        done();
+      });
+    });
+  });
+
   it('should handle thrown errors from get', function(done) {
     var app = express();
     app.get('/', function(req, res) {

test/hooks/test-trace-hapi.js

@@ -205,6 +205,27 @@ Object.keys(versions).forEach(function(version) {
         });
       });
     });
+
+    it('should remove trace frames from stack', function(done) {
+      server = new hapi.Server();
+      server.connection({ port: common.serverPort });
+      server.route({
+        method: 'GET',
+        path: '/',
+        handler: function(req, reply) {
+          reply(common.serverRes);
+        }
+      });
+      server.start(function() {
+        http.get({port: common.serverPort}, function(res) {
+          var labels = common.getMatchingSpan(hapiPredicate).labels;
+          var stackTrace = JSON.parse(labels[traceLabels.STACK_TRACE_DETAILS_KEY]);
+          // Ensure that our middleware is on top of the stack
+          assert.equal(stackTrace.stack_frame[0].method_name, 'middleware');
+          done();
+        });
+      });
+    });
   });
 });
 

test/hooks/test-trace-mongodb.js

@@ -21,6 +21,7 @@
 // Run a mongo image binding the mongo port
 //   ex) docker run -p 27017:27017 -d mongo
 var common = require('./common.js');
+var traceLabels = require('../../lib/trace-labels.js');
 
 var assert = require('assert');
 var mongoose = require('./fixtures/mongoose4');
@@ -126,6 +127,22 @@ describe('test-trace-mongodb', function() {
       done();
     });
   });
+
+  it('should remove trace frames from stack', function(done) {
+    common.runInTransaction(function(endTransaction) {
+      Simple.findOne({f1: 'sim'}, function(err, res) {
+        endTransaction();
+        assert(!err);
+        var trace = common.getMatchingSpan(mongoPredicate.bind(null, 'mongo-cursor'));
+        var labels = trace.labels;
+        var stackTrace = JSON.parse(labels[traceLabels.STACK_TRACE_DETAILS_KEY]);
+        // Ensure that our patch is on top of the stack
+        assert(
+          stackTrace.stack_frame[0].method_name.indexOf('next_trace') !== -1);
+        done();
+      });
+    });
+  });
 });
 
 function mongoPredicate(id, span) {

test/hooks/test-trace-mysql.js

@@ -16,6 +16,7 @@
 'use strict';
 
 var common = require('./common.js');
+var traceLabels = require('../../lib/trace-labels.js');
 require('../..').private_().config_.enhancedDatabaseReporting = true;
 var assert = require('assert');
 var mysql = require('./fixtures/mysql2');
@@ -77,6 +78,24 @@ describe('test-trace-mysql', function() {
     });
   });
 
+  it('should remove trace frames from stack', function(done) {
+    common.runInTransaction(function(endRootSpan) {
+      connection.query('SELECT * FROM t', function(err, res) {
+        endRootSpan();
+        assert(!err);
+        var spans = common.getMatchingSpans(function (span) {
+          return span.name === 'mysql-query';
+        });
+        var labels = spans[0].labels;
+        var stackTrace = JSON.parse(labels[traceLabels.STACK_TRACE_DETAILS_KEY]);
+        // Ensure that our patch is on top of the stack
+        assert(
+          stackTrace.stack_frame[0].method_name.indexOf('createQuery_trace') !== -1);
+        done();
+      });
+    });
+  });
+
   it('should work with events', function(done) {
     common.runInTransaction(function(endRootSpan) {
       var query = connection.query('SELECT * FROM t');

test/hooks/test-trace-redis.js

@@ -21,6 +21,7 @@
 // Run a redis image binding the redis port
 //   ex) docker run -p 6379:6379 -d redis
 var common = require('./common.js');
+var traceLabels = require('../../lib/trace-labels.js');
 
 var assert = require('assert');
 var versions = {
@@ -86,6 +87,22 @@ Object.keys(versions).forEach(function(version) {
         });
       });
     });
+
+    it('should remove trace frames from stack', function(done) {
+      common.runInTransaction(function(endTransaction) {
+        // Test error case as hset requires 3 parameters
+        client.hset('key', 'val', function(err) {
+          endTransaction();
+          var trace = common.getMatchingSpan(redisPredicate.bind(null, 'redis-hset'));
+          var labels = trace.labels;
+          var stackTrace = JSON.parse(labels[traceLabels.STACK_TRACE_DETAILS_KEY]);
+          // Ensure that our patch is on top of the stack
+          assert(
+            stackTrace.stack_frame[0].method_name.indexOf('send_command_trace') !== -1);
+          done();
+        });
+      });
+    });
   });
 });
 

test/hooks/test-trace-restify.js

@@ -150,6 +150,27 @@ Object.keys(versions).forEach(function(version) {
         });
       });
     });
+
+    it('should remove trace frames from stack', function(done) {
+      server = restify.createServer();
+      server.get('/', function (req, res, next) {
+        res.writeHead(200, {
+          'Content-Type': 'text/plain'
+        });
+        res.write(common.serverRes);
+        res.end();
+        return next();
+      });
+      server.listen(common.serverPort, function() {
+        http.get({port: common.serverPort}, function(res) {
+          var labels = common.getMatchingSpan(restifyPredicate).labels;
+          var stackTrace = JSON.parse(labels[traceLabels.STACK_TRACE_DETAILS_KEY]);
+          // Ensure that our middleware is on top of the stack
+          assert.equal(stackTrace.stack_frame[0].method_name, 'middleware');
+          done();
+        });
+      });
+    });
   });
 });
 

test/standalone/test-trace-koa.js

@@ -73,6 +73,26 @@ describe('test-trace-koa', function() {
       });
     });
   });
+
+  it('should remove trace frames from stack', function(done) {
+    var app = koa();
+    app.use(function* () {
+      this.body = yield function(cb) {
+        setTimeout(function() {
+          cb(null, common.serverRes);
+        }, common.serverWait);
+      };
+    });
+    server = app.listen(common.serverPort, function() {
+      http.get({port: common.serverPort}, function(res) {
+        var labels = common.getMatchingSpan(koaPredicate).labels;
+        var stackTrace = JSON.parse(labels[TraceLabels.STACK_TRACE_DETAILS_KEY]);
+        // Ensure that our middleware is on top of the stack
+        assert.equal(stackTrace.stack_frame[0].method_name, 'middleware');
+        done();
+      });
+    });
+  });
 });
 
 function koaPredicate(span) {

test/test-span-data.js

@@ -61,7 +61,7 @@ describe('SpanData', function() {
   it('captures stack traces', function() {
     agent.config().stackTraceLimit = 25;
     cls.getNamespace().run(function() {
-      var spanData = agent.createRootSpanData('name', 1, 2);
+      var spanData = agent.createRootSpanData('name', 1, 2, 1);
       assert.ok(!spanData.span.isClosed());
       spanData.close();
       var stack = spanData.span.labels[TraceLabels.STACK_TRACE_DETAILS_KEY];
@@ -70,10 +70,7 @@ describe('SpanData', function() {
       var frames = JSON.parse(stack);
       assert.ok(frames && frames.stack_frame);
       assert.ok(Array.isArray(frames.stack_frame));
-      assert.ok(frames.stack_frame.some(function(frame) {
-        return frame.method_name &&
-               frame.method_name.indexOf('createRootSpanData') !== -1;
-      }));
+      assert.equal(frames.stack_frame[0].method_name, 'Namespace.run [as run]');
     });
   });