node-swig / swig-templates

Take a swig of the best template engine for JavaScript.
http://node-swig.github.io/swig-templates/
MIT License
209 stars 29 forks source link

Suspected memory leak in swig / swig-templates #41

Open imran-uk opened 7 years ago

imran-uk commented 7 years ago

I recently got an error like this in production:

<--- Last few GCs --->

404572803 ms: Mark-sweep 1466.5 (1434.2) -> 1466.3 (1434.2) MB, 1884.6 / 0.0 ms [allocation failure] [GC in old space requested].
404574988 ms: Mark-sweep 1466.3 (1434.2) -> 1484.4 (1403.2) MB, 2184.6 / 0.0 ms [last resort gc].
404577008 ms: Mark-sweep 1484.4 (1403.2) -> 1503.8 (1403.2) MB, 2020.2 / 0.0 ms [last resort gc].

<--- JS stacktrace --->

==== JS stack trace =========================================

Security context: 0x23e3085cfb51 <JS Object>
    2: compiled [/opt/nodeapp/node_modules/swig/lib/swig.js:~608] [pc=0x19961c86ad0e] (this=0x23e3085e6111 <JS Global Object>,locals=0x2a837d238311 <an Object with map 0x382927d71809>)
    3: /* anonymous */ [/opt/nodeapp/node_modules/swig/lib/swig.js:559] [pc=0x199625010ad4] (this=0x23e3085e6111 <JS Global Object>,err=0x23e308504201 <null>,fn=0x2ec2109581f9 <JS Function compiled (SharedFunctio...

 "FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory"

I run node 6.x LTS with the defaults, no extra memory given to V8.

The mention of swig made me suspect something in swig is not releasing memory properly. What do you think?

imran-uk commented 7 years ago

One thing I've been doing to try and trace a leak is using chrome-devtools

I ran my node/Express/swig app using "node --inspect" and then hooked up Chrome to it using the "chrome-devtools://devtools/..." URL.

I run with NODE_ENV=production

Once loaded in the devtools, I create a heap snapshot using the chrome-devtools. This is my base-line.

I then used a HTTP benchmarking tool called "wrk" to send a bunch of requests to my app:

╰─± /opt/wrk/wrk --header "User-Agent: wrk" --latency --timeout 5s -t 1 -c 1 -d 1m "http://my-app-url"
Running 1m test @ http://my-app-url
  1 threads and 1 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.31s   215.08ms   1.74s    69.77%
    Req/Sec     0.12      0.32     1.00     88.37%
  Latency Distribution
     50%    1.37s 
     75%    1.45s 
     90%    1.53s 
     99%    1.74s 
  43 requests in 1.00m, 4.33MB read
Requests/sec:      0.72
Transfer/sec:     73.84KB

I then take another heap snapshot after every wrk run and compare the results. Without going into too much detail, there is an increase of about 5Mb between the baseline and second heap sizes. This is to be expected as templates get cached. Then comparing the second to the third, fourth heap snaphosts shows an increase of about 0.2 to 0.4Mb each time. Could this be an indication of the leak?

image

I tried both swig and swig-templates and found the same behaviour.

I am not an expert in swig or node internals, this might be normal.

However my conclusion right now is that there is a memory leak in the way swig / swig-templates . Hopefully the detail above can help you replicate. To be fair, I have not managed to replicate the memory leak error in my dev system.