APM nodeJs Agent : how to use setUserContext, setTag, setCustomContext?


(Tommy Cabrelli) #1

Hello everyone,

I'm currently trying the nodejs apm agent. I did a basic integration of the agent in my APIs and everything worked fine pretty fast.
Now im trying to set some user context to help the developers team to debug.
Here is my code (in top of my code in server.js):

 const apm = require('elastic-apm-node').start({
    // active: process.env.NODE_ENV === 'production'
    serviceName: 'test',
    filterHttpHeaders: false,
    captureBody: 'all',
    serverUrl: 'http://mydomain:8200',
  });
  apm.addFilter((payload) => {
    if(payload.context.request.headers && payload.context.request.headers.authorization) {
      console.log(jwt.decode(payload.context.request.headers.authorization.replace('Bearer ', '')));
      payload.context.request.headers.authorization = 'REDACTED'
    }
    return payload;
  });
  apm.startTransaction('testTransaction') // i don't really know why I did that, i also tried without it
  apm.setTag('tagtest', 'valuetest');
  apm.setCustomContext({customecontext: 'heyyy', ok: 'loool'})
  apm.setUserContext({id:'test-id', email: 'email-test', username: 'username test'})

I did a filter on headers.authorization (I know filterHttpHeaders does it already but i wanted to test) and it works.
Unfortunately there are things that seems not working with my code such as :

  • Capturebody : i can't see the body of any requests
  • Tags : my test tag doesn't appear in 'Tag' tab
  • CustomContext : doesn't appear in 'Custom' tab
  • UserContext : doesn't appear in 'User' tab

What am i doing wrong ? Is there something im missing ?

Regards,


(Thomas Watson) #2

Hi Tommy

Thanks for trying out Elastic APM with Node.js :heart:

I think the issue is that your filter function has a bug. But the agent should have logged that as an error when trying to run it. Not sure if you checked that.

The issue with the filtering function is that it's called for all types of data being sent to the APM Server. And not all data have a context.request object. So when it's trying to access payload.context.request.headers it will throw an exception.

If you add payload.context.request && to the beginning of the if-statement that should fix it (at least it did when I ran your code locally).

As this is probably only something you want to do for transactions, you could also use addTransactionFilter instead of addFilter. That means that the filter function will only be called for transactions.

I hope this fixes it for you. If not, let me know and we'll try to dig deeper :smiley:

/thomas


(Tommy Cabrelli) #3

Hi Thomas !

Thanks for your answer and you are right about my if statement that was wrong.
But unfortunately, even without the 'apm.addFilter...' function call, there is still no body in my HTTP POST requests, and no user/custom context or tags in any of my requests. No errors appear in my logs.

Btw im using nodejs 8.9.4, hapijs 16.4.3 and elastic-apm-node 2.0.1

Thanks again for your help :slight_smile:
Have a good day :wink:


(Thomas Watson) #4

Are you transpiling your code in any way before running it - maybe via TypeScript or Babel?

Could I get you to enable debug mode as described in the Troubleshooting docs and post the resulting logs here (be sure not to post any sensitive info).


(Tommy Cabrelli) #5

I think I understand what is happening.

If I use setTag()/setCustomContext()/setUserContext() in my server.js before all my code, they all return false, probably because the transaction hasn't started I guess ?

If I set them in my routes handlers it works.
But what If I want to set them for all future transactions ? Am I misunderstanding something on the transactions behaviors ?

EDIT :
For now im using the hapi function "server.ext()" a middleware that is loaded before all my routes handlers to set contexts to the APM transaction and it works fine. I noticed that the captureBody still doesn't work.

Here is my server.js file :

const apm = require('elastic-apm-node').start({
  // active: process.env.NODE_ENV === 'production'
  serviceName: 'api-test',
  logLevel: 'debug',
  filterHttpHeaders: false,
  captureBody: 'all',
  serverUrl: 'http://logs.mydomain.net:8200',
});
const Hapi = require('hapi');
const Inert = require('inert');
const Vision = require('vision');
const hapiswaggerd = require('hapi-swaggered');
const hapiswaggeredui = require('hapi-swaggered-ui');
const Hapijwt = require('hapi-auth-jwt2');
const hapiI18n = require('hapi-basic-i18n');
const Path = require('path');
require('dotenv').config({ silent: true, path: Path.join(__dirname, '.env') });
const good = require('good');

const routes = require('./routes');
const jwtService = require('./jwt/jwt.service');

const server = new Hapi.Server({ debug: { request: ['error'] } });
server.connection({ port: process.env.PORT || 8080, host: '0.0.0.0', routes: { cors: true } });
server.register([
  Inert,
  Vision,
  {
    register: hapiI18n,
    options: {
      locale_path: Path.join(__dirname, './assets/i18n/'),
      default_language: 'FR',
      available_languages: ['FR'],
    },
  },
  {
    register: hapiswaggerd,
    options: {
      endpoint: '/swagger-doc',
    },
  },
  {
    register: Hapijwt,
  },
  {
    register: hapiswaggeredui,
    options: {
      title: 'Title API',
      path: '/documentation',
      authorization: { // see above
        field: 'Authorization',
        scope: 'header',
        placeholder: 'Enter your jwt token here',
      },
      swaggerOptions: {},
    },
  },
  {
    register: good,
    options: {
      ops: {
        interval: 1000,
      },
      reporters: {
        console: [{
          module: 'good-squeeze',
          name: 'Squeeze',
          args: [{
            response: '*',
            error: '*',
          }],
        },
        {
          module: 'good-console',
        }, 'stdout'],
      },
    },
  },
], (err) => {
  server.auth.strategy('jwt', 'jwt', {
    key: jwtService.getAppSecrets,
    validateFunc: (decoded, request, callback) => {
      if (!decoded) {
        return callback(null, false);
      }
      const scope = [];
      if (decoded) {
        if (decoded.role) {
          scope.push(decoded.role);
        }
        if (decoded.currentOrganisation && decoded.currentOrganisation.role) {
          scope.push(decoded.currentOrganisation.role);
        }
      }
      // Scope is an array that contains AppRole and OrganisationRole
      return callback(null, true, Object.assign(decoded, { scope }));
    },
    verifyOptions: { algorithms: ['HS256'] },
  });
  if (err) throw err;
  routes(server, apm);
  server.start((error) => {
    if (error) {
      throw error;
    }

    server.ext('onPreHandler', (request, reply) => {
      apm.setCustomContext({ jwtContent: request.auth.credentials });
      apm.setUserContext({
        id: request.auth.credentials.id,
        email: request.auth.credentials.email,
        username: `${request.auth.credentials.firstname} ${request.auth.credentials.lastname}`,
      });
      return reply.continue();
    });
  });
});
module.exports = server;

(Tommy Cabrelli) #6

and here are the logs when I perform a Post action (sorry for double post But I reached max characters limit) :

1|Test API  | intercepted request event call to http.Server.prototype.emit
1|Test API  | start trace { trans: '1ff2137b3bb60df9',
1|Test API  |   parent: undefined,
1|Test API  |   trace: '3fe0bcfdd9942f9c21deedb0f3440479',
1|Test API  |   name: null,
1|Test API  |   type: null }
1|Test API  | received hapi onPreResponse event
1|Test API  | setting default transaction name: CORS preflight { trans: '1ff2137b3bb60df9',
1|Test API  |   parent: undefined,
1|Test API  |   trace: '3fe0bcfdd9942f9c21deedb0f3440479' }
1|Test API  | setting transaction result { trans: '1ff2137b3bb60df9',
1|Test API  |   parent: undefined,
1|Test API  |   trace: '3fe0bcfdd9942f9c21deedb0f3440479',
1|Test API  |   result: 'HTTP 2xx' }
1|Test API  | sending transaction { trans: '1ff2137b3bb60df9',
1|Test API  |   trace: '3fe0bcfdd9942f9c21deedb0f3440479' }
1|Test API  | ended transaction { trans: '1ff2137b3bb60df9',
1|Test API  |   parent: undefined,
1|Test API  |   trace: '3fe0bcfdd9942f9c21deedb0f3440479',
1|Test API  |   type: 'request',
1|Test API  |   result: 'HTTP 2xx',
1|Test API  |   name: 'CORS preflight' }
1|Test API  | 181203/094708.919, [response] http://0.0.0.0:3004: options /trainings {} 200 (20ms)
1|Test API  | intercepted request event call to http.Server.prototype.emit
1|Test API  | start trace { trans: '8ece77b8c1960ec0',
1|Test API  |   parent: undefined,
1|Test API  |   trace: 'a145d3934f187b830778ff5fc47f35a9',
1|Test API  |   name: null,
1|Test API  |   type: null }
1|Test API  | received hapi onPreAuth event
1|Test API  | setting default transaction name: POST /trainings { trans: '8ece77b8c1960ec0',
1|Test API  |   parent: undefined,
1|Test API  |   trace: 'a145d3934f187b830778ff5fc47f35a9' }
1|Test API  | no active transaction found - cannot build new span
1|Test API  | intercepted call to http.request { id: null }**
1|Test API  | HANDLER ::::::::::::::::::::
1|Test API  | { cntext: true, user: true }
1|Test API  | received hapi onPreResponse event
1|Test API  | setting transaction result { trans: '8ece77b8c1960ec0',
1|Test API  |   parent: undefined,
1|Test API  |   trace: 'a145d3934f187b830778ff5fc47f35a9',
1|Test API  |   result: 'HTTP 2xx' }
1|Test API  | sending transaction { trans: '8ece77b8c1960ec0',
1|Test API  |   trace: 'a145d3934f187b830778ff5fc47f35a9' }
1|Test API  | ended transaction { trans: '8ece77b8c1960ec0',
1|Test API  |   parent: undefined,
1|Test API  |   trace: 'a145d3934f187b830778ff5fc47f35a9',
1|Test API  |   type: 'request',
1|Test API  |   result: 'HTTP 2xx',
1|Test API  |   name: 'POST /trainings' }
1|Test API  | 181203/094708.953, [response,api] http://0.0.0.0:3004: post /trainings {} 200 (280ms)   result: 'HTTP 2xx',
1|Test API  |   name: 'POST /trainings' }
1|Test API  | 181203/094708.953, [response,api] http://0.0.0.0:3004: post /trainings {} 200 (280ms)

(Thomas Watson) #7

Ah I see. Yes that's true. If you call setTag, setCustomContext or setUserContext when there's no active transaction, nothing happens because it needs something to bind to. It's currently not possible to set "global" tags etc that will automatically be applied to all transactions. Feel free to open a GitHub issue requesting support for this :slight_smile:

captureBody however is a global config option and should work. I'll have a look to see if I can reproduce the issue you described where it doesn't attach the body even though you configured it with the value all.