Reusing HTTP connection lead to no destroy triggered #19859
Comments
|
@nodejs/async_hooks |
If you have a leaking resource in the application, one would observe the above counter to increment. This doesn't necessarily indicate a leak in async hooks, but more likely in the application itself.
You didn't specify how the code was different a week before. I am guessing that you didn't have async hooks enabled then. If that's the case, my main suspicion would be the hook functions you're installing. Are you storing the resource objects into a array/map/set etc.? That's an easy way to write a memory leak. Keeping a reference to the resources will prevent them from getting garbage collected, preventing the destroy hook from being called. |
|
Thanks for reply! I do use map to keep an object in side hooks:
But destroy looks not called as I expected. What do you suggest me to do? |
|
BTW, I did not touch the resource object passed in init function. You may check here: https://github.com/Tubitv/envoy-node/blob/dbc512fa1df73203a75cd0cc03b2b251fa597da8/src/envoy-context-store.ts#L55 |
|
Closed by mistake, sorry |
|
@ofrobots is there any possibility that in our application (code run under restify, not under createHook) code has memory leak issues that stop async_hooks' destroy from being called? |
|
@winguse I think that is the most likely cause. You could try running https://github.com/mafintosh/why-is-node-running to see what isn't being |
|
Thanks @AndreasMadsen , I can see it's some problem of our code. It looks like our conversion from generator code to promise has some problems. The reason why we didn't see them before may due to it's not wasting too many memory. |
|
As dig into detail, I find that it's not the generator problem -- they are destroyed a little bit late. And as I collect data from our production, over 99.9% not destroyed stacks are this one: TCPWRAP at Agent.addRequest (_http_agent.js:178:22) in the top of the stack, i see this code: if (socket._handle && typeof socket._handle.asyncReset === 'function') {
// Assign the handle a new asyncId and run any init() hooks.
socket._handle.asyncReset();
socket[async_id_symbol] = socket._handle.getAsyncId();
}I have no ideas about it, anyone can help? |
|
I find the root cause of this now, it's because we are using And request will use: updated the title and description as above. |
|
@winguse Do you still think this is an issue with node.js? If so, could you try writing up a test case? |
winguse
changed the title
|
@AndreasMadsen It looks to be a node.js issue to me, check the description above (i changed the title and the issue description). I am not sure if this can be solve inside node.js, as this can lead to multiple execution blocks sharing the same tcp connection resource. |
|
We have the same issue. I let code similar to the one in the OP for about an hour and ended up with 2.5 million more inits than destroys, even after several garbage collections. This only happens when using Here is my test own code: 'use strict'
const ah = require('async_hooks')
const http = require('http')
const fs = require('fs')
const DEBUG = false
const ITERATIONS = 5000
const CONCURRENCY = 1
const SOCKETS = 1
const KEEP_ALIVE = true
let count = 0
const log = message => fs.writeSync(1, `${message}\n`)
const debug = message => DEBUG && log(message)
const hook = ah.createHook({
init (asyncId, type) {
count++
debug(`init: ${asyncId} (${type})`)
},
before (asyncId) {
debug(`before: ${asyncId}`)
},
after (asyncId) {
debug(`after: ${asyncId}`)
},
destroy (asyncId) {
count--
debug(`destroy: ${asyncId}`)
}
})
hook.enable()
const agent = new http.Agent({
keepAlive: KEEP_ALIVE,
maxSockets: SOCKETS,
maxFreeSockets: SOCKETS
})
let finished = 0
for (let i = 0; i < CONCURRENCY; i++) {
operation(0)
}
function operation (index) {
const req = http.request({ port: 1234, agent }, res => {
res.on('data', () => {})
res.on('end', () => {
if (index < ITERATIONS) {
setImmediate(() => operation(index + 1))
} else {
finished++
if (finished === CONCURRENCY) {
log(`total: ${count}`)
}
}
})
})
req.on('error', () => {})
req.end()
}Something interesting that I've noticed is if you set @AndreasMadsen Is this the expected behavior? Other things I've tried to no avail:
|
|
Just tried to destroy the socket and it doesn't seem to have any effect so I don't think my above theory is valid after all. |
|
As pointed out by @winguse, this seems to affect specifically |
|
My last point is not an option unfortunately. From the doc:
That means that there is no way to know when to deallocate objects that were allocated in |
|
Hi folks, I did a bit of digging and I think there are at least two different leaks at play for HTTP client requests. Here are two more simple cases that reproduce this problem:
In both cases you can prove that there is exactly one call to the I added a bit of debugging code to the reproducers to be able to see where the First Case: Plain
|
|
|
Each time a new parser was created, AsyncReset was being called via the C++ Parser class constructor (super constructor AsyncWrap) and also via Parser::Reinitialize. This also adds a missing async_hooks destroy event before AsyncReset is called for the parser reuse case, otherwise the old async_id never gets destroyed. Refs: nodejs#19859
Emit a destroy before calling asyncReset because otherwise the old async_id never gets destroyed. Refs: nodejs#19859
Each time a new parser was created, AsyncReset was being called via the C++ Parser class constructor (super constructor AsyncWrap) and also via Parser::Reinitialize. This also adds a missing async_hooks destroy event before AsyncReset is called for the parser reuse case, otherwise the old async_id never gets destroyed. Refs: nodejs#19859
This adds missing async_hooks destroy calls for sockets (in _http_agent.js) and HTTP parsers. We need to emit a destroy in AsyncWrap#AsyncReset before assigning a new async_id when the instance has already been in use and is being recycled, because in that case, we have already emitted an init for the "old" async_id. This also removes a duplicated init call for HTTP parser: Each time a new parser was created, AsyncReset was being called via the C++ Parser class constructor (super constructor AsyncWrap) and also via Parser::Reinitialize. Fixes: nodejs#19859
|
The two previous PRs have been merged into a single PR which fixes both issues: #23272 |
|
Thanks everyone! |
This adds missing async_hooks destroy calls for sockets (in _http_agent.js) and HTTP parsers. We need to emit a destroy in AsyncWrap#AsyncReset before assigning a new async_id when the instance has already been in use and is being recycled, because in that case, we have already emitted an init for the "old" async_id. This also removes a duplicated init call for HTTP parser: Each time a new parser was created, AsyncReset was being called via the C++ Parser class constructor (super constructor AsyncWrap) and also via Parser::Reinitialize. PR-URL: nodejs#23272 Fixes: nodejs#19859 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: James M Snell <jasnell@gmail.com>
This adds missing async_hooks destroy calls for sockets (in _http_agent.js) and HTTP parsers. We need to emit a destroy in AsyncWrap#AsyncReset before assigning a new async_id when the instance has already been in use and is being recycled, because in that case, we have already emitted an init for the "old" async_id. This also removes a duplicated init call for HTTP parser: Each time a new parser was created, AsyncReset was being called via the C++ Parser class constructor (super constructor AsyncWrap) and also via Parser::Reinitialize. PR-URL: #23272 Fixes: #19859 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: James M Snell <jasnell@gmail.com>
This adds missing async_hooks destroy calls for sockets (in _http_agent.js) and HTTP parsers. We need to emit a destroy in AsyncWrap#AsyncReset before assigning a new async_id when the instance has already been in use and is being recycled, because in that case, we have already emitted an init for the "old" async_id. This also removes a duplicated init call for HTTP parser: Each time a new parser was created, AsyncReset was being called via the C++ Parser class constructor (super constructor AsyncWrap) and also via Parser::Reinitialize. PR-URL: nodejs#23272 Fixes: nodejs#19859 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: James M Snell <jasnell@gmail.com>
This adds missing async_hooks destroy calls for sockets (in _http_agent.js) and HTTP parsers. We need to emit a destroy in AsyncWrap#AsyncReset before assigning a new async_id when the instance has already been in use and is being recycled, because in that case, we have already emitted an init for the "old" async_id. This also removes a duplicated init call for HTTP parser: Each time a new parser was created, AsyncReset was being called via the C++ Parser class constructor (super constructor AsyncWrap) and also via Parser::Reinitialize. Backport-PR-URL: #23404 PR-URL: #23272 Fixes: #19859 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: James M Snell <jasnell@gmail.com>
This adds missing async_hooks destroy calls for sockets (in _http_agent.js) and HTTP parsers. We need to emit a destroy in AsyncWrap#AsyncReset before assigning a new async_id when the instance has already been in use and is being recycled, because in that case, we have already emitted an init for the "old" async_id. This also removes a duplicated init call for HTTP parser: Each time a new parser was created, AsyncReset was being called via the C++ Parser class constructor (super constructor AsyncWrap) and also via Parser::Reinitialize. Backport-PR-URL: #23410 PR-URL: #23272 Fixes: #19859 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: James M Snell <jasnell@gmail.com>
This adds missing async_hooks destroy calls for sockets (in _http_agent.js) and HTTP parsers. We need to emit a destroy in AsyncWrap#AsyncReset before assigning a new async_id when the instance has already been in use and is being recycled, because in that case, we have already emitted an init for the "old" async_id. This also removes a duplicated init call for HTTP parser: Each time a new parser was created, AsyncReset was being called via the C++ Parser class constructor (super constructor AsyncWrap) and also via Parser::Reinitialize. Backport-PR-URL: #23404 PR-URL: #23272 Fixes: #19859 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: James M Snell <jasnell@gmail.com>
This adds missing async_hooks destroy calls for sockets (in _http_agent.js) and HTTP parsers. We need to emit a destroy in AsyncWrap#AsyncReset before assigning a new async_id when the instance has already been in use and is being recycled, because in that case, we have already emitted an init for the "old" async_id. This also removes a duplicated init call for HTTP parser: Each time a new parser was created, AsyncReset was being called via the C++ Parser class constructor (super constructor AsyncWrap) and also via Parser::Reinitialize. Backport-PR-URL: #23404 PR-URL: #23272 Fixes: #19859 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: James M Snell <jasnell@gmail.com>
v8.9.0Linux cms-03 4.4.0-1052-aws #61-Ubuntu SMP Mon Feb 12 23:05:58 UTC 2018 x86_64 x86_64 x86_64 GNU/LinuxNaNpoc.js:run it with
why-is-node-running:if there are requests to the same endpoint, the socket never closed and those
destroys never get called.old description
Hi team,
Thanks for the awesome job!
I am using the async_hooks in our production, but I've found some memory issue that possible related to async_hooks.
For debugging, I created a counter variable:
inithook is called, increase by 1destroyhook is called, decrease by 1And I got the following chart for the past 1.5 days (2018-04-05T13:06:12.724Z to 2018-04-06T22:46:53.753Z)
As check with pm2 info, the the chart above drop down to 0 is the time pm2 when restart the application.
And here is the memory usage:
As comparing, this is what the memory looks like one week before:
Our application is a web service running on top of restify.
The memory is consumption may beyond your expectation, it's because of I am holding some resource after init is called and those resource's releasing require destroy to be called.
Any ideas?
The text was updated successfully, but these errors were encountered: