bug: transaction.setDefaultNameFromRequest relies on instrumentation being loaded

[astorm]

This issue comes from a discuss forum post.

The following program

const apm = require('elastic-apm-node').start({
    serverUrl: 'http://some-apm-server',
    active: true,
    instrument: false,
    logLevel: 'trace',
});

const Koa = require('koa');
const Router = require('koa-router');

const app = new Koa();
const router = new Router();

router.get('/', (ctx, next) => {
    ctx.body = 'hello world';
});

app
    .use(router.routes())
    .use(router.allowedMethods());

app.listen(3000);

Will produce a transaction name of GET unknown route when handling the root URL, despite that URL having a configured route.

$ curl http://localhost:3000/

We would expect a transaction name of GET /

Root Cause

This bug occurs when the following configuration value is set

    instrument: false

which disables automatic instrumentation.

There's a bug in the setDefaultNameFromRequest method of the transaction object. It uses the getPathFromRequest from the ./express-utils module to fetch a request path if no route property is found. If it can't fetch a request path, it assumes an unknown route.

The getPathFromRequest method relies on our express instrumentation being loaded. Specifically, the agent grabs a path value using the symbols.expressMountStack symbol that our instrumentation sets on the request object.

Additionally, the agent does not reach the setDefaultNameFromRequest code path when the instrumentation configuration value is set to true, as the KOA instrumentation will have already called setDefaultTransactionName.

The setDefaultNameFromRequest (probably?) should not rely on this symbol being set as setDefaultNameFromRequest is part of our generic HTTP instrumentation.

Additional Info: PR where instrument configuration's current behavior landed: #1114

[astorm]

Some possibly non-obvious things about the instrument configuration that it's worth writing down.

This configuration value only controls the runtime/monkey-patching of the original modules. It does not control the loading and execution of the of the instrumentation module/function.

For example -- with instrument:false set, this means that the http instrumentation function here will still execute, but that the module returned by require('http') will will be Node's module and not our monkey patched version. This means top level methods like request and get will not be wrapped. However -- the depper objects that we wrap on on this module (like emit) will be wrapped. They'll remain wrapped because whether it's our version of the module or Node's version of the module, the depper objects reference the same object.

The main takeaway here is that instrument:false does not disable everything the agent does. It may be necessary to use additional configuration (like instrumentIncomingHTTPRequests) to fully turn off agent features.

[astorm]

Disabling Instrumentation Configuration

There are three configuration variables that control instrumentation in the agent.

instrumentation

The agent uses the instrumentation configuration value to set the enabled boolean for an instrumentation module. It does not control the patching of Node.js modules or the loading of instrumentations based on those modules. It is up to each individual instrumentation module to obey the enabled boolean.

Agent Reference Points:

• https://github.com/elastic/apm-agent-nodejs/blob/master/lib/instrumentation/index.js#L186

disableInstrumentation

The disableInstrumentation configuration value serves a similar function to the instrumentation configuration. It's used to create a list of specific modules that a user wants to disable, and the agent uses this information to control the enabled/disable configuration send to individual instrumentation modules. It does not control the patching of Node.js modules ot the loading of instrumentation based on those modules. It is up to each individual instrumentation module to obey the enabled boolean.

Agent Reference Points:

• https://github.com/elastic/apm-agent-nodejs/blob/master/lib/instrumentation/index.js#L181-L186

instrumentIncomingHTTPRequests

The instrumentIncomingHTTPRequests configuration controls whether the http, https, and http2 modules will be wrapped in order to start transactions (and parse trace context headers) for individual HTTP requests.

This configuration is checked in individual instrumentation modules before the enabled boolean is checked.

Agent Reference Points

• apm-agent-nodejs/lib/instrumentation/modules/http.js

  Line 11 in 666092c

  if (agent._conf.instrumentIncomingHTTPRequests) {

• apm-agent-nodejs/lib/instrumentation/modules/https.js

  Line 9 in 666092c

  if (agent._conf.instrumentIncomingHTTPRequests) {

• https://github.com/elastic/apm-agent-nodejs/blob/master/lib/instrumentation/modules/http2.js#L18

Removing instrumentIncomingHTTPRequests

Question: Will removing the instrumentIncomingHTTPRequests configuration and combing it with instrumentation and disableInstrumentation effect Node.js async context tracking?

Answer: Slightly. If users start transactions via agent.startTransaction, the currentTransaction value will still be set. However, if they don't, this value will never be set. Without a current transaction spans won't be created and most of the data an agent collects won't be sent to APM Server. Additionally, trancecontext headers won't be parsed and the server will not show up as part of a distributed trace.

Question: Is removing the instrumentIncomingHTTPRequests configuration a breaking change?

Answer: Soft yes on this. For users who have never set any of the above three configuration variables, there will be no changed agent behavior. However, if they have set any of the above there may be subtle, unexpected changes to agent behavior based on the presense or non presense of a transaction.

I'm softly opposed to changing this behavior without a major version bump.

[trentm]

instrumentIncomingHTTPRequests was added (#434, pull #1298) in v3.0.0 as a breaking change, with this justification:

It's not possible to switch off the automatic creation of HTTP request transactions when an incoming HTTP request is detected without also switching off tracing of outgoing HTTP requests.
It would be very useful - both to users, but especially also during debugging - if it was possible to control the two features separately.

---

I re-read the discuss thread and:

1. It sounds like adding a comment to the Node.js agent's docs on instrument saying that instrumentIncomingHTTPRequests must also be set false to totally disable instrumentation would have been helpful for the user in that discussion thread.

2. It wasn't entirely clear to me if the user still wants the "WIP" to have the agent work harder to set a "default transaction name". The original post said:

   The problem is that even if I give a transaction name with transaction.name, APM tries to get the name from the koa-router. It's there any way to avoid this behavior?

   If they do set transaction.name (which sets the internal transaction._customName, then that value will get used over whatever value is determined for the "default" transaction name.

3. Perhaps it was confusion over requests to other endpoints -- like the point Alan made about a request from the browser for "GET /favicon.ico"? I.e. the user is getting GET unknown root transaction names on service endpoints that they happen to not be explicitly setting a custom name via transaction.name = "custom name". If so, could we suggest the user use usePathAsTransactionName and not add Alan's WIP?

   We should likely also improve the Node.js agent's docs on this config option to include the warning about possible explosion of transaction groups that the Java equivalent mentions.

4. On the "instrument:false for Node.js is inconsistent with other agents" question: I think one option is to consider it a bug that instrument:false doesn't also disable incoming http request instrumentation. When instrumentIncomingHTTPRequests was added, the intent was to have separate control from disableInstrumentations=http,.... I don't think the intent was to have separate control from instrument:false. I think it was just missed: where if (agent._conf.instrumentIncomingHTTPRequests) { is checked the enabled boolean has already been calculated from conf.disableInstrumentations and conf.instrument

apm-agent-nodejs/lib/instrumentation/modules/http.js

Lines 10 to 19 in 666092c

	module.exports = function (http, agent, { enabled }) {
	if (agent._conf.instrumentIncomingHTTPRequests) {
	agent.logger.debug('shimming http.Server.prototype.emit function')
	shimmer.wrap(http && http.Server && http.Server.prototype, 'emit', httpShared.instrumentRequest(agent, 'http'))
	agent.logger.debug('shimming http.ServerResponse.prototype.writeHead function')
	shimmer.wrap(http && http.ServerResponse && http.ServerResponse.prototype, 'writeHead', wrapWriteHead)
	}
	if (!enabled) return http

Changing those guards to if (agent._conf.instrumentIncomingHTTPRequests && agent._conf.instrument) { would do it.

[astorm]

Consider the following small program

const apm = require('elastic-apm-node').start({
  serverUrl: 'http://some-apm-server',
  active: true,
  instrument: false,
  logLevel: 'trace',
});

const Koa = require('koa');
const Router = require('koa-router');

const app = new Koa();
const router = new Router();

router.get('/hello', (ctx, next) => {
  apm.setTransactionName('this is a test')
  ctx.body = 'hello world';
});

app
  .use(router.routes())
  .use(router.allowedMethods());

app.listen(3000);

When running this program we're able to rename the current transaction successfully despite the default transaction name being set to unknown.

Similarly, the following program is able to start a transaction with a default name and set a custom name.

const apm = require('elastic-apm-node').start({
  serverUrl: 'http://some-apm-server',
  active: true,
  instrument: false,
  logLevel: 'trace',
  instrumentIncomingHTTPRequests: false,
});

const Koa = require('koa');
const Router = require('koa-router');

const app = new Koa();
const router = new Router();

router.get('/hello', (ctx, next) => {
  apm.startTransaction('this is my transaction');
  // apm.setTransactionName('uncomment to set custom name')
  ctx.body = 'hello world';
  apm.endTransaction();
});

app
  .use(router.routes())
  .use(router.allowedMethods());

app.listen(3000);

This appears to cover the expected use cases from the original discuss forum post, and that the WIP PR isn't needed. We'll be closing this issue for now, but if anyone has trouble with custom transaction naming when these configuration values are in use please let us know.