Can not capture transaction name on multi-middleware

[isikhi]

I will directly simplify this problem with sample code.

Once I delved into the code a bit I simplified it to this level.

I also reviewed instrumentation here. It looks inside the request object in the Express Route, but if there is a route in the form of Express.Use (which may not be the best practice, but Express performs all route operations related to it without any problems.) Then, if a response is returned in any of the middleware except the last one, APM cannot capture the transaction name there. It appears as an unnamed transaction - unknown route.

As you can see kibana logs here:

And the source code which you can reproduce. I may contribute it

app.js

const express = require('express');
const logger = require('morgan');
require('elastic-apm-node').start({
    active: true,
    breakdownMetrics: true,
    captureBody: 'all',
    captureErrorLogStackTraces: 'always',
    captureExceptions: true,
    captureSpanStackTraces: true,
    cloudProvider: 'aws',
    environment: 'test',
    errorOnAbortedRequests: true,
    frameworkName: 'Express',
    ignoreUrls: ['/', '/swagger-json', '/metrics'],
    instrument: true,
    instrumentIncomingHTTPRequests: true,
    logLevel: 'debug',
    logUncaughtExceptions: true,
    serverUrl: 'http://localhost:8200',
    serviceName: 'elastic-apm-test',
    serviceVersion: '0.0.1',
    sourceLinesErrorAppFrames: 30,
    sourceLinesErrorLibraryFrames: 0,
    sourceLinesSpanAppFrames: 30,
    sourceLinesSpanLibraryFrames: 0,
    stackTraceLimit: 50,
});

const app = express();

app.use(logger('dev'));
app.use(express.json());
app.use(express.urlencoded({extended: false}));

async function resSend(req, res, next) {
    console.log({
        path: req.path,
        baseUrl: req.baseUrl,
        originalUrl: req.originalUrl,
    })
    res.json({
        msg: 'ok',
    });
}

app.use(
    '/one/two',
    resSend,
)

module.exports = app;

www

#!/usr/bin/env node

var app = require('./app');
var debug = require('debug')('express-elastic-bug-poc:server');
var http = require('http');

var port = normalizePort(process.env.PORT || '4000');
app.set('port', port);

var server = http.createServer(app);

server.listen(port);
server.on('error', onError);
server.on('listening', onListening);
function normalizePort(val) {
  var port = parseInt(val, 10);
  if (isNaN(port)) {
    return val;
  }

  if (port >= 0) {
    return port;
  }
  return false;
}

function onError(error) {
  if (error.syscall !== 'listen') {
    throw error;
  }

  var bind = typeof port === 'string'
    ? 'Pipe ' + port
    : 'Port ' + port;

  // handle specific listen errors with friendly messages
  switch (error.code) {
    case 'EACCES':
      console.error(bind + ' requires elevated privileges');
      process.exit(1);
      break;
    case 'EADDRINUSE':
      console.error(bind + ' is already in use');
      process.exit(1);
      break;
    default:
      throw error;
  }
}

/**
 * Event listener for HTTP server "listening" event.
 */

function onListening() {
  var addr = server.address();
  var bind = typeof addr === 'string'
    ? 'pipe ' + addr
    : 'port ' + addr.port;
  console.log('Listening on', bind)
}

package.json

{
  "name": "express-elastic-bug-poc",
  "version": "0.0.1",
  "private": true,
  "scripts": {
    "start": "node www"
  },
  "dependencies": {
    "cookie-parser": "~1.4.4",
    "debug": "~2.6.9",
    "elastic-apm-node": "^4.0.0",
    "express": "~4.18.1",
    "morgan": "~1.9.1"
  }
}

[isikhi]

I tried with different version of apm (3.x , 4.x) and the results are same.

[david-luna]

Hi @isikhi

Thanks for giving implementation details for the issue, it is really helpful :)

From your example we noticed express is required before agent starts. In that specific case we cannot guarantee the correct instrumentation of the module.

I've placed the agent start at the top and run the code again

require('elastic-apm-node').start({
  // config here...
);

const express = require('express');
const logger = require('morgan');
const app = express();
// ...rest of the code

The result is what I think you're expecting. Transaction has the path in their name (as shown in the following screenshot)

Could you confirm that this fixes the issue?

Cheers