Ghost: Lot more requests since 0.9 - potential memory leak

[gergelyke]

Issue Summary

Since updating to 0.9, our ghost instances are serving a lot more traffic:

Is this the expected behavior?

Technical details:

• Ghost Version: 0.9
• Node Version: 4.x
• Database: PG

[sebgie]

Hey @gergelyke, welcome to our little space on Github 👋 . This is a really interesting observation. Could you please provide more information about what traffic you are measuring?

The Response Time graph indicates to me that most of the requests got faster (median) and slow requests got slower (95th). This leads me to the question of how the throughput is calculated. If the requests got faster you are able to transmit more data per second and therefore throughput goes up?.

Is there a chance that you switched to a newer node version during the upgrade?

[gergelyke]

Hello @sebgie,

it is measured by Trace, our Node.js monitoring platform. What you see there in the green is the number of HTTP requests with 2xx status codes, black ones are 3xx. The blog served around 30rpm, now it jumped to 60+, while the user count did not grow.

Node.js was not updated, we are using the docker image: risingstack/alpine:3.3-v4.3.2-3.1.1 (with Node.js 4.3.2)

[gergelyke]

Hello @sebgie,

what's even worse, is the memory usage and eventloop lag I just saw:

All changed in a very negative way. Any idea why it could happen?

[sebgie]

Hey, yeah, this all looks very concerning. I have not yet seen a problem on Ghost(Pro) which is running on 4.4.7 though. Would you mind swinging by our Slack community (https://ghost.org/slack/) to have a discussion about how to replicate and measure what you see?

The change log from 0.8 to 0.9 is quite long (https://gist.github.com/ErisDS/9adeb395d3e8caec192622270600c8b1) so it is possible that a problem was introduced.

A 2x increase in requests seems still very strange and could hint to a problem with the theme? Are you using a custom/3rd party theme by any chance?

[gergelyke]

We are using https://github.com/RisingStack/StayPuft as the base of our theme - but nothing chaged there

[gergelyke]

@sebgie just updated to 4.4.7 - will see what happens

[gergelyke]

the same happens with 4.4.7

[kevinansfield]

The 0.8->0.9 changelog is here, the link above was the 0.7.x->0.8 changelog https://gist.github.com/kevinansfield/ac440cd1433f33df0bc358b786608812

A 2x increase in requests suggests that there may be a change that is causing a redirect, e.g. from non-trailing-slash to trailing-slash (which may also explain the drop in median, redirects should be quick!). Are you able to get any request logs from your ghost instances?

[gergelyke]

Wooow, that's a lot of change - any chance we can do releases more often?

Checking the request logs in the meantime

[wezm]

I'm also seeing continuously growing memory usage since upgrading to 0.9:

[msamoylov]

I can confirm that Ghost 0.9 has introduced memory leaks. That's frustrating.

[gergelyke]

Ok, so if it not just us, I will dive deeper tomorrow!

[kirrg001]

@gergelyke Thank you!
What i can tell you so far: I've tested if scheduling (https://github.com/TryGhost/Ghost/blob/master/core/server/scheduling/SchedulingDefault.js) could cause memory leaks, but found nothing. The memory always jumps back to around 90mb. Before we have released scheduling, i've inserted thousand of jobs and watched the memory - it always jumped back.

[marcuspoehls]

We've noticed a doubled memory usage since upgrading to 0.9. Went up from around 120 MB to 250 MB, which is kind of a jump. Updating Node.js from 4.4.2 to 4.4.7 didn't change anything.

[ErisDS]

@gergelyke, @wezm, @msamoylov, @marcuspoehls Please please please, can you provide enough information for us to reproduce or find a pattern to what's causing the issue:

• host OS & version
• node version
• npm version
• nginx or apache
• database used
• theme used
• rough idea of how many posts the blog has
• any other pertinent details (are you running other software on the same server?)

[gergelyke]

@ErisDS

• Host OS & version: Alpine linux running on AWS Beanstalk: risingstack/alpine:3.4-v4.4.7-3.6.
• Node: 4.4.7
• npm: the one shipped with 4.4.7
• AWS ELB
• PostgreSQL
• Theme: a slighly modified Staypuft: https://github.com/dlecina/StayPuft
• cc 100

[marcuspoehls]

@ErisDS

• host OS & version: Ubuntu 14.04 (14.04.5) running on Digital Ocean
• node: 4.4.7
• npm. 3.10.6
• nginx
• database: MySQL
• theme: modified Roon
• rough idea of how many posts the blog has: 228
• any other pertinent details (are you running other software on the same server?): we're running our homepage (hapi.js server), Piwik and Gogs besides Ghost on the same server

I've had a look at the current memory consumption and Ghost jumped back to "normal" usage. Didn't check the number of requests and no idea why it peaked in the last days

[msamoylov]

@ErisDS

• host OS & version: Ubuntu 16.04.1 LTS 64-bit
• node version: 4.5.0
• npm version: 2.15.9
• nginx or apache: nginx/1.10.1
• database used: PostgreSQL 9.5.4
• theme used: slightly modified Casper
• rough idea of how many posts the blog has: https://samoylov.tech has 10 posts and no significant traffic
• any other pertinent details: that's a Linode 2GB instance running this Ghost instance and two small Django projects

[wezm]

@ErisDS

• host OS & version:
  
  
  
  • Ubuntu 15.10 (I need to do an upgrade)
  
  
  • Linux 4.2.0-42-generic #49-Ubuntu SMP Tue Jun 28 21:26:26 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
  
  
• node version: v4.4.7
• npm version: 2.15.8
• nginx or apache: nginx/1.10.0
• database used: sqlite
• theme used: Silent theme
• rough idea of how many posts the blog has: Only 3, with 1 or 2 drafts and little traffic
• any other pertinent details: I'm hosting via Phusion Passenger 5.0.28. This is a 1Gb Digital Ocean instance also running a small, low traffic Rails app. Generally RAM usage is ~60%. CPU mostly idle. I have ServerDensity monitoring this server, which includes bursts of requests for the home page of the blog (http://bitcannon.net/) from a bunch of different locations every 5 mins or so.

[codybonney]

@ErisDS

Noticing this also. TTFB appears to have increased after updating from 0.8 to 0.9 as well (by ~80-100ms). I upgraded node at the same time though, so perhaps that's the culprit.

• host OS & version: CentOS release 6.8 (Final)
• node version: v4.5.0
• npm version: 2.15.9
• nginx or apache: nginx/1.10.1
• database used: sqlite
• theme used: Custom (lightweight, based off Casper)
• rough idea of how many posts the blog has: 172
• any other pertinent details: using pm2

[sebgie]

After a few attempts to reproduce I think that I have found how to track down what is going on here. An idle blog has no leak and it hovers between 80 and 120 mb of memory depending on your theme.

BUT if you add some traffic the whole situation looks quite different. Below graphs are from an internal blog that I put some load on (5 concurrent users, every 100 seconds) and it grew from around 70mb to 260mb within 24hrs. Notably the memory didn’t grow anymore when the requests stopped.

I only sent random requests to the frontend and /ghost routes of the blog (GET /...).

It should now be possible to recreate this behaviour locally with a local dev blog and a curl command in a while loop.

while true; do curl -I http://localhost; sleep 30; done

[gergelyke]

So far it does not make a lot of sense what I am seeing in the retainers - you can spot quickly, that arrays are growing, but I can only see lodash as a retainer. All input is welcomed!

[kirrg001]

Hey, we have found the reason for the memory leak.

We have updated bookshelf and knex in our last Ghost release 0.9.0. I've tested a couple of hours in the morning and with the PR i've created, the memory usage should be back to normal.

Still, we will investigate further why the update of bookshelf and knex has caused a memory leak. Sorry you had trouble!

[gergelyke]

Wow, thanks a lot @kirrg001!

So basically you downgraded or upgraded bookshelf to solve the issue?

[kirrg001]

@gergelyke yeah exactly, for now we downgraded bookshelf and knex back to the versions we have used before 0.9.0, see https://github.com/TryGhost/Ghost/issues/7291

[ErisDS]

We've shipped a temporary solution for this in 0.10.1.

[gergelyke]

I can verify that the memory leaks stopped!

[msamoylov]

Same here. Good job!