ApplicationInsights-node.js icon indicating copy to clipboard operation
ApplicationInsights-node.js copied to clipboard

Do not release application insights context and continuation-local-storage can't build e2e trace

Open emmansun opened this issue 4 years ago • 12 comments

We integrated application insights with a service (apigee microgateway) , this service used nodejs 8.3.0, applicationInsights-nodejs 1.7.0. we found that the service's memory is growing as time goes on. We dumped the heap, found that there are many application insights context in memory.

image image

And our service used cluster mode , forked threads per CPU, so there are 40M * number of CPU context data.

Per check the code, this context related code is in applicationinsights\out\AutoCollection\CorrelationContextManager.js and HttpRequest.js image

Any clue?

emmansun avatar Feb 12 '20 07:02 emmansun

For node.js 8.2+, we use async_hooks which was very new from your node.js version's perspective and so it might be buggy/unstable at that point. You might also have some dangling references to those contexts that are preventing garbage collection from happening.

I'd recommend either using a more recent node.js version and see if it resolves the issue, or force the SDK to use continuous-local-storage for context propagation instead. You can do this by settings the 2nd arg false here when configuring your SDK, e.g disable async_hooks https://github.com/microsoft/ApplicationInsights-node.js/blob/1b1fbc908eb8b9309ebe50a02ae0c0721106f41d/applicationinsights.ts#L260

markwolff avatar Feb 13 '20 04:02 markwolff

Thx @markwolff , we'll change to use continuation-local-storage instead, per check its code, there are also no internal _contexts map. In fact, we just integrate applicationInsights with auto-collection functions, so there should no dangling references to those cls_hooks namespace's internal field of _contexts map.

emmansun avatar Feb 13 '20 06:02 emmansun

Hi @markwolff , after i invoked setAutoDependencyCorrelation(true, false), it seems it can't build end to end transaction detail trace cross cloud components/services. We used applicationInsights-nodejs 1.7.2 SDK with nodejs 8.11.4/8.16.0.

emmansun avatar Feb 19 '20 05:02 emmansun

Is it related to Memory leak in _contexts #11?

emmansun avatar Feb 19 '20 08:02 emmansun

It could be if you are referring to the AI context in your own code at all. I'm unable to repro a leak with a simple express demo on node 8.3.0. Otherwise, I would expect each generated context to be remain on the heap until it has been GC'd, so you may see some contexts depending on your service's RPS when you profiled it.

Can you clarify what you mean by not building a trace (screenshot?). I've tested this on my demo as well and it seems to be working as intended.

markwolff avatar Feb 19 '20 19:02 markwolff

We have multiple applications/services which build a whole system, I mean once we changed to call setAutoDependencyCorrelation(true, false), the callee application/service can't get related trace information from http headers. For example, below called application, the inbound request become a root request, it's NOT expected.

image

emmansun avatar Feb 20 '20 02:02 emmansun

It could be if you are referring to the AI context in your own code at all. I'm unable to repro a leak with a simple express demo on node 8.3.0. Otherwise, I would expect each generated context to be remain on the heap until it has been GC'd, so you may see some contexts depending on your service's RPS when you profiled it.

Did you set process.env.DEBUG_CLS_HOOKED to check the _contexts map?

emmansun avatar Feb 20 '20 02:02 emmansun

Setting forceCls should have no effect on incoming request telemetry correlation. It reads the http header the same way, regardless of this configuration. What do you see on req.header["request-id"] in your request handler?

I did not use DEBUG_CLS_HOOKED. Does it do something other than log async id information to console?

markwolff avatar Feb 20 '20 20:02 markwolff

I did not use DEBUG_CLS_HOOKED. Does it do something other than log async id information to console?

Yes, i can see there are still old context in _contexts map after the request.

emmansun avatar Feb 21 '20 05:02 emmansun

Can you clarify what you mean by not building a trace (screenshot?). I've tested this on my demo as well and it seems to be working as intended.

I wrote a simple demo, and also can't build relationship for end to end transaction Below is using cls-hook, (did NOT call setAutoDependencyCorrelation(true, false)) image

Below is using continue-local-storage (call setAutoDependencyCorrelation(true, false)) image

Related dependent request telemetry: image

The test code is simple: ai-express-front:

const request = require('request');
const appInsights = require('applicationinsights');
const express = require('express');
const app = express()
const port = 3000

process.env.DEBUG_CLS_HOOKED=true;
appInsights.setup('xxxx'.setAutoDependencyCorrelation(true, false);
appInsights.defaultClient.context.tags[appInsights.defaultClient.context.keys.cloudRole] = 'ai_demo_front';
appInsights.defaultClient.commonProperties = {
  environment: 'local',
  serviceName: 'ai_demo_front'
};
appInsights.start();

app.get('/', (req, res) => request.get('http://localhost:3010').pipe(res))

app.listen(port, () => console.log(`Example app listening on port ${port}!`))

ai-express:

const colors = require('colors');
const appInsights = require('applicationinsights');
const express = require('express');
const app = express()
const port = 3010

appInsights.setup('xxxx').setAutoDependencyCorrelation(true, false);
appInsights.defaultClient.context.tags[appInsights.defaultClient.context.keys.cloudRole] = 'ai_demo';
appInsights.defaultClient.commonProperties = {
  environment: 'local',
  serviceName: 'ai_demo'
};
appInsights.start();

app.get('/', (req, res) => res.send('Hello World! I\'m ai_demo.'));

app.listen(port, () => console.log(`Example app listening on port ${port}!`))

Test env. nodejs: 10.16.0 express: 4.17.1 applicationInsights: 1.7.2 request: 2.88.2

emmansun avatar Feb 24 '20 03:02 emmansun

You should import and start the SDK before you import in any HTTP modules. It seems the patching required for CLS-mode requires us to not only be imported before express/requests, but also started before as well.

markwolff avatar Feb 26 '20 02:02 markwolff

Thx @markwolff , after the code change, it worked with setAutoDependencyCorrelation(true, false). btw, i can see below debug information even the request had been closed for long time when i used cls-hooks: image Is it normal?

emmansun avatar Feb 26 '20 02:02 emmansun