Not getting stack trace past async boundary in node.js server


When I look at a span in APM I only see the stack trace up to the current event loop handler. I was hoping to see the stack trace go further back so I could tell the actual API call being made. e.g. the trace looks like this:

node_modules/mongodb-core/lib/cursor.js in nextFunction at line 607
node_modules/mongodb-core/lib/cursor.js in cursor.topology.selectServer at line 820
node_modules/mongodb-core/lib/topologies/replset.js in ReplSet.selectServer at line 1149
node_modules/mongodb/lib/topologies/topology_base.js in selectServer at line 362
node_modules/mongodb-core/lib/cursor.js in initializeCursor at line 779
node_modules/mongodb-core/lib/cursor.js in nextFunction at line 591
node_modules/mongodb-core/lib/cursor.js in at line 833
node_modules/mongodb/lib/cursor.js in Cursor._next at line 211
node_modules/mongodb/lib/operations/cursor_ops.js in fetchDocs at line 209
node_modules/mongodb/lib/operations/cursor_ops.js in toArray at line 239
node_modules/mongodb/lib/utils.js in <anonymous> at line 437
in Promise at line 0
node_modules/mongodb/lib/utils.js in executeOperation at line 432
node_modules/mongodb/lib/cursor.js in Cursor.toArray at line 824
src/api/users/loaders/users.js in batchFn at line 6
node_modules/dataloader/index.js in dispatchQueueBatch at line 246
node_modules/dataloader/index.js in dispatchQueue at line 233
node_modules/dataloader/index.js in global.<anonymous> at line 70
internal/process/next_tick.js in internalTickCallback at line 70

Is it possible facebook's DataLoader is doing one of those things that prevents APM from tracing back past an async boundary?

I'm guessing it has something to do with this stuff in dataloader:

// Private: Enqueue a Job to be executed after all "PromiseJobs" Jobs.
// ES6 JavaScript uses the concepts Job and JobQueue to schedule work to occur
// after the current execution context has completed:
// Node.js uses the `process.nextTick` mechanism to implement the concept of a
// Job, maintaining a global FIFO JobQueue for all Jobs, which is flushed after
// the current call stack ends.
// When calling `then` on a Promise, it enqueues a Job on a specific
// "PromiseJobs" JobQueue which is flushed in Node as a single Job on the
// global JobQueue.
// DataLoader batches all loads which occur in a single frame of execution, but
// should include in the batch all loads which occur during the flushing of the
// "PromiseJobs" JobQueue after that same execution frame.
// In order to avoid the DataLoader dispatch Job occuring before "PromiseJobs",
// A Promise Job is created with the sole purpose of enqueuing a global Job,
// ensuring that it always occurs after "PromiseJobs" ends.
// Node.js's job queue is unique. Browsers do not have an equivalent mechanism
// for enqueuing a job to be performed after promise microtasks and before the
// next macrotask. For browser environments, a macrotask is used (via
// setImmediate or setTimeout) at a potential performance penalty.
var enqueuePostPromiseJob =
  typeof process === 'object' && typeof process.nextTick === 'function' ?
    function (fn) {
      if (!resolvedPromise) {
        resolvedPromise = Promise.resolve();
      resolvedPromise.then(() => process.nextTick(fn));
    } :
    setImmediate || setTimeout;

Is there a way I can monkeypatch this myself?

That's a limitation of Node.js itself. You can try installing a long stack trace module to improve that, though they do tend to have a significant performance impact. If you are on Node.js 8+, you can try

Hmm I thought the elastic APM module had a bunch of code to work around this itself.

This topic was automatically closed 20 days after the last reply. New replies are no longer allowed.