Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Why are strings passed to winston kept in memory, leaking and ultimately crashing the node.js process?

I'm inspecting a heap snapshot created by [email protected], running on Node.js 10.16.0 in Amazon Linux with kernel 4.14.123-86.109.amzn1.x86_64. Heap snapshot is 1GB and, good news, strings visibly consume most of it, using 750MB of both shallow and retained size.

Most of these strings are bound to be logged by winston ([email protected], [email protected], [email protected]), at a log level (silly) lower than my app's minimal level (debug). So, a few dozen times per second,

  • I build a log string.
  • I pass it to winston.log with a logLevel silly.
  • No log happens (as expected, silly < debug).

Expected: strings are GCed and life goes on.

Actual: strings accumulate in memory, are not GCed, node OOMs at max-heap-size (1.4GB).


I am positive strings do leak. What I'm describing is not nominal operation between two normal GCs because, looking at the contents of the strings in the snapshot, I see a great deal of variation that, in the case of my app, can only come from hours of running.

Also, the devtools sometimes report huge sizes for these strings (23MB for a string that is actually 1KB), and the retainers tree is humongous, with >18000 levels of a next method inside objects message and chunk (see screenshot below).

So, my two questions are:

  1. Why does winston keep these strings in memory? An idea I had: maybe winston keeps the messages in a queue/buffer, doesn't log because the level is too low, and never flushes the queue?
  2. What's going on in this heapsnapshot? How can my little 1KB string have a shallow/retained size of 23MB?! What's going on in this crazy retainers tree / any idea who these next / message / chunk objects belong to?

Available to provide additional information. Thank you!

winston string in node heapsnapshot with crazy size & retainers

like image 674
Ronan Jouchet Avatar asked Jan 20 '26 03:01

Ronan Jouchet


1 Answers

This was a bug in Winston related to how it used streams. It was fixed in a pull request, you can read more about the issue and the fix here: https://github.com/winstonjs/winston/issues/1871

like image 100
Espen Avatar answered Jan 21 '26 17:01

Espen



Donate For Us

If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!