Unable to see transactions with APM when used with apollo-server-express

Elastic Observability APM
1

APM Agent language and version:
"elastic-apm-node": "^3.10.0",

Using with:
"apollo-server-express": "^2.18.2",
"express": "^4.17.1",

This is a first time setup for this particular type of app. As suggested by Apollo team (Integrating with Node.js middleware - Apollo Server - Apollo GraphQL Docs), we are using the express app applied as a middleware to the ApolloServer.

The problem is - APM is only shimming graphql and not the nodejs http modules, hence any other rest api calls are not getting tracked - only graphql endpoint requests are getting tracked:

Running in trace log mode I see:

  pid: 76893,
  ppid: 76892,
  arch: 'x64',
  platform: 'darwin',
  node: 'v12.18.3',
  agent: '3.10.0',
  ancestors: [
    '/Users/****/node_modules/elastic-apm-node/index.js',
    '/Users/****/src/middlewares/verifyToken.ts',
    '/Users/****/src/index.ts',
    [length]: 3
  ],
  startTrace: [
    'at Agent.start (/Users/****/node_modules/elastic-apm-node/lib/agent.js:154:11)',
    'at Object.apmSetup [as default] (/Users/****/src/apmSetup.ts:5:21)',
    'at Object.<anonymous> (/Users/****/src/index.ts:30:27)',
    'at Module._compile (internal/modules/cjs/loader.js:1137:30)',
    'at Module.m._compile (/Users/****/node_modules/ts-node/src/index.ts:1056:23)',
    'at Module._extensions..js (internal/modules/cjs/loader.js:1157:10)',
    'at Object.require.extensions.<computed> [as .ts] (/Users/****/node_modules/ts-node/src/index.ts:1059:12)',
    'at Module.load (internal/modules/cjs/loader.js:985:32)',
    'at Function.Module._load (internal/modules/cjs/loader.js:878:14)',
    'at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:71:12)',
    'at main (/Users/****/node_modules/ts-node/src/bin.ts:198:14)',
    'at Object.<anonymous> (/Users/****/node_modules/ts-node/src/bin.ts:288:3)',
    'at Module._compile (internal/modules/cjs/loader.js:1137:30)',
    'at Object.Module._extensions..js (internal/modules/cjs/loader.js:1157:10)',
    'at Module.load (internal/modules/cjs/loader.js:985:32)',
    'at Function.Module._load (internal/modules/cjs/loader.js:878:14)',
    [length]: 16
  ],
  main: undefined,
  dependencies: undefined,
  conf: {
    ignoreUrlStr: [ [length]: 0 ],
    ignoreUrlRegExp: [ [length]: 0 ],
    ignoreUserAgentStr: [ [length]: 0 ],
    ignoreUserAgentRegExp: [ [length]: 0 ],
    transactionIgnoreUrlRegExp: [ [length]: 0 ],
    sanitizeFieldNamesRegExp: [
      /^password$/i { [lastIndex]: 0 },
      /^passwd$/i { [lastIndex]: 0 },
      /^pwd$/i { [lastIndex]: 0 },
      /^secret$/i { [lastIndex]: 0 },
      /^.*key$/i { [lastIndex]: 0 },
      /^.*token.*$/i { [lastIndex]: 0 },
      /^.*session.*$/i { [lastIndex]: 0 },
      /^.*credit.*$/i { [lastIndex]: 0 },
      /^.*card.*$/i { [lastIndex]: 0 },
      /^authorization$/i { [lastIndex]: 0 },
      /^set\x2dcookie$/i { [lastIndex]: 0 },
      /^pw$/i { [lastIndex]: 0 },
      /^pass$/i { [lastIndex]: 0 },
      /^connect\.sid$/i { [lastIndex]: 0 },
      [length]: 14
    ],
    abortedErrorThreshold: 25,
    active: true,
    apiRequestSize: 786432,
    apiRequestTime: 10,
    asyncHooks: true,
    breakdownMetrics: true,
    captureBody: 'off',
    captureErrorLogStackTraces: 'messages',
    captureExceptions: true,
    captureHeaders: true,
    captureSpanStackTraces: true,
    centralConfig: true,
    disableInstrumentations: [ [length]: 0 ],
    environment: 'dev',
    errorMessageMaxLength: 2048,
    errorOnAbortedRequests: false,
    filterHttpHeaders: true,
    instrument: true,
    instrumentIncomingHTTPRequests: true,
    logLevel: 'trace',
    logUncaughtExceptions: false,
    metricsInterval: 30,
    metricsLimit: 1000,
    sanitizeFieldNames: [
      'password',   'passwd',
      'pwd',        'secret',
      '*key',       '*token*',
      '*session*',  '*credit*',
      '*card*',     'authorization',
      'set-cookie', 'pw',
      'pass',       'connect.sid',
      [length]: 14
    ],
    serverTimeout: 30,
    sourceLinesErrorAppFrames: 5,
    sourceLinesErrorLibraryFrames: 5,
    sourceLinesSpanAppFrames: 0,
    sourceLinesSpanLibraryFrames: 0,
    stackTraceLimit: 50,
    transactionIgnoreUrls: [ [length]: 0 ],
    transactionMaxSpans: 500,
    transactionSampleRate: 1,
    useElasticTraceparentHeader: true,
    usePathAsTransactionName: false,
    verifyServerCert: true,
    serviceName: '******',
    secretToken: '',
    serverUrl: '*********',
    serviceVersion: '0.0.1',
    serverHost: '********',
    serverPort: 443
  }
}
adding hook to Node.js module loader
shimming graphql@15.4.0 module

I was expecting APM to shim the following as well.

shimming http@12.18.3 module
shimming http.Server.prototype.emit function
shimming http.ServerResponse.prototype.writeHead function
shimming http.request function
shimming http.get function

Can somebody help on identifying why this could be happening and what can I do different for it to work?

Thanks,
Sim

2

Sim_Singh, thanks for dropping by.

Reading over your post -- great job at identifying the root cause -- if the modules you mention aren't shimmed that will definitely block transaction creation.

The most common reason for these modules not to be shimmed is the Node.js Agent isn't the first module loaded by your application. If something else loads http before the agent loads, the agent won't be able to shim that module. Can you talk a little bit about how you're invoking node and what your application bootstrap file looks like? With that information someone might be better able to diagnose your issue.

3

hey Alan,

Thanks for looking into this.

As mentioned in the post I am bootstrapping my app something like this:

const express = require('express');
const { ApolloServer } = require('apollo-server-express');
const { typeDefs, resolvers } = require('./schema');
import { start } from 'elastic-apm-node';

const apmObject = start({...});
const app = express();
const server = new ApolloServer({
  typeDefs,
  resolvers,
});

server.applyMiddleware({ app });

app.use((req, res) => {
  res.status(200);
  res.send('Hello!');
  res.end();
});

app.listen({ port: 4000 }, () =>
  console.log(`🚀 Server ready at http://localhost:4000${server.graphqlPath}`)
)
4

Thanks @Sim_Singh, this makes the problem clear.

The elastic-apm-node needs to be the first thing that's loaded in your application's bootstrap file. So instead of this

const express = require('express');
const { ApolloServer } = require('apollo-server-express');
const { typeDefs, resolvers } = require('./schema');
import { start } from 'elastic-apm-node';

try something like this

const apm = require('elastic-apm-node')
apm.start({...})
const express = require('express');
const { ApolloServer } = require('apollo-server-express');
const { typeDefs, resolvers } = require('./schema');

Get elastic-apm-node loaded first and you should be good to go.

1 Like
5

Ah, that solves it! Order of imports, I forgot that.

Thanks a lot!

6

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