elastic / elastic/apm-agent-nodejs

Transactions not ended on prematurely closed socket in Hapi <= v17

Open
#2,018 0 comments 3 reactions 0 assignees View on GitHub
agent-nodejs
Dominant language
JavaScript
Stars
594
Forks
244
Avg merge
1d 8h
Merged PRs (30d)
16

Description

**Describe the bug**

When a socket is prematurely closed against Hapi versions <= v17 the transaction is not ended. This results in the transaction not being tracked in Elastic APM, and the transaction remaining in memory.

The agent has handling for ending a transaction when the response has been finalised by calling `response.end()` (https://github.com/elastic/apm-agent-nodejs/pull/1439). However Hapi versions prior to v17 did not call this if the request had been aborted https://github.com/hapijs/hapi/commit/657be02213f2961ac13b7853db5d9219ed75a520#diff-2871801a54601791d9e1004f04b2df5d7adc881560285ff3fa6bee7bf9697857R327.

**To Reproduce**

```js
/**
* Setup npm i hapi@v17.0.0 elastic-apm-node
*/

const apm = require('elastic-apm-node');
const hapi = require('hapi');

apm.start({
serviceName: 'abc',
logLevel: 'debug'
});

async function start() {
const server = new hapi.Server({
port: 8080
});

await server.route({
method: "get",
path: "/takes/awhile",
async handler() {
console.log('-------------- Incoming Request ---------------');
await new Promise((resolve) => setTimeout(resolve, 5000));
console.log('-------------- Done ---------------');

return 'ok';
}
});

console.log(server.info.uri);

await server.start();
}

start();
```

Using the code above
1. Call `curl http://localhost:8080/takes/awhile`
2. Cancel the request before it completes.
3. The transaction is not finalised

```
start trace {
trans: '73b50a32d1251d9c',
parent: undefined,
trace: '7480847c9100dc2ae51bcaa77bd8c6fa',
name: 'unnamed',
type: null,
subtype: null,
action: null
}
-------------- Incoming Request ---------------
-------------- Done ---------------
$
```

**Expected behavior**

The transaction should be ended and the trace details should be sent to Elastic APM once the handler is complete. This fits with the behaviour outlined in https://github.com/elastic/apm-agent-nodejs/issues/1411

Here is a fix we have applied in production for one of our application that has resolved this issue.

```js
// server.events.on in Hapi v17+
server.on('response', () => {
// Ensure the Elastic APM transaction is ended.
// Older version of Hapi do not call `res.end` if the socket is closed prematurely
const trans = elasticAPM.currentTransaction;
if (!trans || trans.ended) {
return;
}

trans.end();
});
```

This looks like it can be added to https://github.com/elastic/apm-agent-nodejs/blob/master/lib/instrumentation/modules/hapi.js#L68 with no issues. Happy to open a PR for this if you accept it as a fix.

**Environment (please complete the following information)**

- OS: any
- Node.js version: any
- APM Server version: any
- Agent version: any

**How are you starting the agent? (please tick one of the boxes)**

- [x] Calling `agent.start()` directly (e.g. `require('elastic-apm-node').start(...)`)
- [ ] Requiring `elastic-apm-node/start` from within the source code
- [ ] Starting node with `-r elastic-apm-node/start`

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.