[Bug]: When using winston v3 on node14.18.3, there seems to be a memory leak event.

[ysknkd]

🔎 Search Terms

memory leak

The problem

I found memory leaks when using winston v3.7.2.

node test-winston.js 2> /dev/null

RSS: 28.9921875 MB
heap used/total: 4.790740966796875/8.57421875 MB
...
... snip ...
...
RSS: 195.984375 MB
heap used/total: 49.476966857910156/50.82421875 MB

What version of Winston presents the issue?

3.7.2

What version of Node are you using?

v14.18.3

If this worked in a previous version of Winston, which was it?

v2.4.5

Minimum Working Example

const w = require('winston')

setInterval(() => {
    w.error('test'.repeat(100))
}, 10)

setInterval(() => {
    const MB_DIV = 1024 * 1024;
    const usage = process.memoryUsage();
    console.log(`RSS: ${usage.rss / MB_DIV} MB`);
    console.log(`heap used/total: ${usage.heapUsed / MB_DIV }/${usage.heapTotal / MB_DIV} MB`);
}, 1000);

Additional information

In v2.4.5, the increase in memory usage has not occurred as in this case.

[wbt]

Thanks for the detailed report! I had to make a few tweaks to get initial stats reported:

const w = require('winston')
const printStats = () => {
    const MB_DIV = 1024 * 1024;
    const usage = process.memoryUsage();
    console.log(`RSS: ${usage.rss / MB_DIV} MB`);
    console.log(`heap used/total: ${usage.heapUsed / MB_DIV }/${usage.heapTotal / MB_DIV} MB`);
}
setInterval(printStats, 1000);
printStats();
setInterval(() => {
    w.error('test'.repeat(100));
}, 10)

I did not notice much of an increase in memory usage, even when making that 100 into 10000, though the logging interval function only repeats 17x in either case (and I don't fully understand why). The snipped portion for me is:
[winston] Attempt to write logs with no transports {"message":"test...test","level":"error"} 17x.
My initial testing was on Node 16.10.0. I also tried 14.18.3 and there, while it seemed like the random small initial difference might've been a bit larger, it went back down even lower several seconds later.
There may be some performance tradeoff somewhere in there which only cleans up references when memory use is above a certain threshold or at lower-activity times in order to make logging faster, because that's pretty important for a logging library, so even if there is some growth in memory usage with additional logging that doesn't necessarily mean it's problematic. Are you seeing a more sustained usage or failure to close something properly?

[zizifn]

Thanks for the detailed report! I had to make a few tweaks to get initial stats reported:

const w = require('winston')
const printStats = () => {
    const MB_DIV = 1024 * 1024;
    const usage = process.memoryUsage();
    console.log(`RSS: ${usage.rss / MB_DIV} MB`);
    console.log(`heap used/total: ${usage.heapUsed / MB_DIV }/${usage.heapTotal / MB_DIV} MB`);
}
setInterval(printStats, 1000);
printStats();
setInterval(() => {
    w.error('test'.repeat(100));
}, 10)

I did not notice much of an increase in memory usage, even when making that 100 into 10000, though the logging interval function only repeats 17x in either case (and I don't fully understand why). The snipped portion for me is: [winston] Attempt to write logs with no transports {"message":"test...test","level":"error"} 17x. My initial testing was on Node 16.10.0. I also tried 14.18.3 and there, while it seemed like the random small initial difference might've been a bit larger, it went back down even lower several seconds later. There may be some performance tradeoff somewhere in there which only cleans up references when memory use is above a certain threshold or at lower-activity times in order to make logging faster, because that's pretty important for a logging library, so even if there is some growth in memory usage with additional logging that doesn't necessarily mean it's problematic. Are you seeing a more sustained usage or failure to close something properly?

I think without config transports, winston will keep all the logs into this._readableState.buffer, or this._writableState.bufferand this will eventually cause memory issue..
https://github.com/winstonjs/winston/blob/master/lib/winston/logger.js#L300

[superobin]

When there is no transport configured, in order to control the size, it should be good to truncate the buffer, making sure it always below a certain size.

[ahmedtalhakhan]

Is there any update on this?

[zizifn]

Is there any update on this?

This memory leak is about use Winston V3 without any transports.. So make sure you add transports for V3 and I enhanced the doc and warning message in Winston for this issue.

 You need add transports by yourself, and leaving the default logger without any transports may produce a high memory usage issue.

[ahmedtalhakhan]

@zizifn We are getting the issue with transport configured as below

transports: [
			new winston.transports.Console()
		],

[cjfswd]

@zizifn We are getting the issue with transport configured as below

transports: [
			new winston.transports.Console()
		],

I solved this warn message by removing an invocation of .clear() before start logging...

[Shahtaj-Khalid]

We are facing the same issue, Winston logger is causing memory leaks, transport is already configured in our case as well.
We are using Version : 3.6.0.

Do we have any update on the fix of this issue ? we are facing issues on Prod and some update on this will help - as it's urgent.

[wbt]

@Shahtaj-Khalid what version of Node are you using?
As you can see in my comment above, I wasn't able to reproduce the problem. Even if I had been able to, diving into the details of why that's happening and figuring out how to fix it is far from a trivial effort, for a problem I'm not observing in any of my own applications, and it seems nobody is willing to fund any of the maintenance efforts on this package, so it's hard to justify any sort of priority treatment.

[Shahtaj-Khalid]

@wbt I'm using node v13.8.0 and latest version of winston logger.
Also, I have opened a separate question regarding the issue we are facing and have added all the details along with how we can reproduce the issue as well: #2233, as we're able to reproduce the issue pretty much every time, Kindly check this and provide your feedback.

Also, it is high priority issue for us as it is effecting our prod environment. If it doesn't get fixed, we'll unfortunately have to consider other loggers.

Thanks.

[wbt]

@wbt I'm using node v13.8.0 and latest version of winston logger. Also, I have opened a separate question regarding the issue we are facing and have added all the details along with how we can reproduce the issue as well: #2233, as we're able to reproduce the issue pretty much every time, Kindly check this and provide your feedback.

That doesn't provide "all the details along with how we can reproduce the issue" - it isn't even logging one message, let alone enough to be overwhelming

Also, it is high priority issue for us as it is effecting our prod environment. If it doesn't get fixed, we'll unfortunately have to consider other loggers.

That is not the threat you might think it is. If you need contracted reliability you'll have to pay a service provider for that.
You can probably pay less for an engineer to start from something that mostly works but has a few bugs (and contribute those working solutions back to the community, where the benefits can be all shared and better maintained) than to start from scratch. If you think another logging library is a better starting point, please feel free to use that. If you're interested in providing some serious funding to the Winston project, please say so. It currently has none, and businesses relying on it have no right to insist that very-limited-time volunteers burn hours trying to fix issues that you and not we are encountering, especially when provided reports don't make it easy to reliably reproduce the problem.