Parse LiveQuery Excessive CPU

[wfilleman]

Issue Description

I've got a parse server in production in an IoT environment where it's processing around 100 requests a second. This all works great with CPU around 30% and 25ms response times. The parse server is clustered on AWS on two C5.Large instances.

I'm adding in LiveQuery as a separate C5.Large server. Both Parse server and LiveQuery are using Redis to communicate changes and this is working.

The problem I'm seeing is the LiveQuery server with just one client connected has CPU usage between 20-35%. Two clients connected and this jumps to around 40%. More than 3 clients connected and the server crashes within minutes.

I'm looking for some suggestions as to what to try to figure out why the excessive CPU usage and then server crash. To be clear, subscriptions all work from Parse Server to LiveQuery to the client.

More information:

• Parse Server version: 3.0.0
• Parse Client: 2.1.0
• Number of Classes monitored by Live Query: 12
• Using Role ACL
• Using Session Token in client subscriptions

Here is how Live Query server is configured:

let parseApi = new ParseServer({
    databaseURI: `mongodb://${config.get('/mongo/userName')}:${config.get('/mongo/password')}@${config.get('/mongo/uri')}`, // Connection string for your MongoDB database
    appId: config.get('/parse/appId'),
    masterKey: config.get('/parse/masterKey'), // Keep this key secret!
    serverURL: `http://127.0.0.1:${config.get('/port/webapp')}/parse`,
    logLevel: "ERROR",
    sessionLength: ONE_DAY, // in seconds. Set to 24 hours.
    schemaCacheTTL: ONE_MONTH_MS, //"The TTL for caching the schema for optimizing read/write operations. You should put a long TTL when your DB is in production. default to 5000; set 0 to disable."
    cacheTTL: ONE_DAY_MS, //"Sets the TTL for the in memory cache (in ms), defaults to 5000 (5 seconds)"
    cacheMaxSize: 1000000, //"Sets the maximum size for the in memory cache, defaults to 10000"
    enableSingleSchemaCache: true //"Use a single schema cache shared across requests. Reduces number of queries made to _SCHEMA. Defaults to false, i.e. unique schema cache per request."
});

// Serve the Parse API on the /parse URL prefix
app.use('/parse', parseApi);

let port = config.get('/port/webapp');
let server = app.listen(port);

// Initialize a LiveQuery server instance, app is the express app of your Parse Server
if (config.get('/parseAppServerIsLocal')) {
    debug(`Starting Live Query Server on port ${config.get('/port/parseLiveQuery')}`);
    let httpServer = require('http').createServer(app);
    httpServer.listen(config.get('/port/parseLiveQuery'));
    let liveQueryParams = {
        redisURL: config.get('/server/redis')
    };
    let parseLiveQueryServer = ParseServer.createLiveQueryServer(httpServer,liveQueryParams);
}

Steps to reproduce

Configure Parse server/LiveQuery per above with Redis and connect one client that subscribes to all 12 classes. Queries are not complex. Example:

const nodeStatusesQuery = new ParseObj.Query('NodeStatus').limit(10000);

Observer jump in CPU usage in high-throughput (100 requests per second to parse server).

Expected Results

I'm not sure what the CPU usage should be, but 30% for one client, 40-50% for two and crashing after that doesn't seem right.

Actual Outcome

LiveQuery server with just one client connected has CPU usage between 20-35%. Two clients connected and this jumps to around 40%. More than 3 clients connected and the server crashes within minutes.

Environment Setup

• Server

  • parse-server version (Be specific! Don't say 'latest'.) : 3.0.0
  • Operating System: Linux
  • Hardware: AWS ELB C5.Large instance
  • Localhost or remote server? (AWS, Heroku, Azure, Digital Ocean, etc): AWS

• Database

  • MongoDB version: 3.4.14
  • Storage engine: Not sure
  • Hardware: mLab hosted on AWS
  • Localhost or remote server? (AWS, mLab, ObjectRocket, Digital Ocean, etc): mLab

Logs/Trace

[flovilmart]

While this may seem excessive, this ‘kindof’ make sense. Would you be able to provide profiling info on the liveQuery server? Perhaps an obvious optimization can be made. I’m thinking JSON serialization bottlenecks

[wfilleman]

Absolutely, what would you recommend? I’ve never had to do profiling with Node before.

[flovilmart]

So that's almost easy :)

Enable inspect mode on your node process

• Get the <pid> of your live query process with ps aux | grep node
• Send the USR1 signal to this processkill -usr1 <pid> (This will not kill the node process but send the USR1 signal. node is built to enable the inspector when receiving this signal).

Forward the port

By default the debugger interface for your process should start on port 9229, if you're running the process on a remote server, then you need to ensure the port 9229 is properly open for inspection.

Chrome inspector

We use the chrome inspector to gather the profiles and process, open a new chrome tab an in the URL bar, enter: chrome://inspect

Locally this is what I see when debugging the parse-live-query-server process locally, in your case, this may be different:

Hit the inspect link and start recording the profile

[wfilleman]

Awesome, I can get the results posted tomorrow. Thanks!

[flovilmart]

Nice, also, do not profile for too long, profiles are huge :) given what you describe we should hopefully be able to see bottlenecks without too much digging

[wfilleman]

Good point. Will do.

[wfilleman]

Hi @flovilmart,

See attached for the 3 node processes running on the live query server. One process is the watchdog/master that spawns the other two node servers for each of the 2 available CPUs on a C5.Large.

Each was captured for about 60 seconds of profile data while there was one client connected and the CPU was around 30%.

Let me know what else I can capture for you. I really appreciate the help!

LiveQuery-HighCPU.zip

Wes

[wfilleman]

FYI: Your directions were nearly perfect. The one step I had to do on the remote server was to start the node app/Live Query with:

node --inspect=10.0.1.77 server.js

The --inspect=10.0.1.77 line tells the inspector to attach to it's local IP address.

[flovilmart]

Thanks @wfilleman. Are you able to record a profile when your CPU saturates? At this time the profile doesn't show any particular bottleneck on the live query server beside the fact we spend a lot of time in internals of process.nextTick() See below the time usage of runMicrotasks internal:

[wfilleman]

Hi @flovilmart,

I connected 4 clients to my LiveQuery server and was able to capture 2 of the 3 processes for about 60 seconds each before the server crashed. Hopefully, this will give you better insight as to what's happening. I'm pretty sure the one titled Process2-10-8-2018 is the LiveQuery instance. The process3 one is the watchdog.

Thanks!
Wes
LiveQuery-HighCPU-10-8-2018.zip

[flovilmart]

Awesome thanks! I’ll have a look

[wfilleman]

@flovilmart,

Managed to grab that first process after a server reboot. The server looks like it's crashing due to running out of RAM. In watching the metrics on the server this time, the LiveQuery RAM use gets to about 80% of the available RAM (on the C5.Large it's 4GB) and then the server crashes. My guess is the garbage collector can't run due to the excessive CPU.

Thanks!
Wes
Process1-10-8-2018-V2.zip

[wfilleman]

@flovilmart, One more data point: With no clients connected, the CPU is 1-2%. Stable. Whatever is happening, it's only once there are 1+ clients connected.

Wes

[flovilmart]

@wfilleman are you able to test against a particuarl branch like: schemaController-performance? I've identified one way things can improve #5107

[flovilmart]

@wfilleman the more I look at your trace in Process3, it seems to spend most of it's time on the internal connect calls. Are you sure the client connections are steady and stable? If you have your 3 clients connected and no activity on the server, what is your CPU usage like? It looks like all your clients keep connecting and disconnecting all the time. Do you have a reverse proxy in front?