Performance issue on version 4.x

[saulogt]

New Issue Checklist

• I am not disclosing a vulnerability.
• I am not just asking a question.
• I have searched through existing issues.
• I can reproduce the issue with the latest version of Parse Server.

Issue Description

Parse server 4.5.0 is up to four times slower than version 3.10.0. That prevents me from upgrading parse-server in a production app. Other than the performance issues, there are random errors logged in the console that does not happen with the version 3.x

Steps to reproduce

I created a repo to prove my point: https://github.com/saulogt/test-parse-server4

• Clone this repo (https://github.com/saulogt/test-parse-server4)
• $ npm i
• Run node ./tester.js create once to create the collections
• Run the test with version 3.10.0
• $ node ./tester.js
• Save metrics
• npm i [email protected]
  -Run the test again with version 4.5
• $ node ./tester.js
• Compare results

Actual Outcome

• [email protected]

Created 300 accounts in parallel through cloud function (Installation + User + Account)
accounts: 6.773s
Created 400 myObjects in parallel
objectsP: 658.257ms
Created 400 myObjects in sequence
objectsS: 1.320s

• [email protected]

Created 300 accounts in parallel through cloud function (Installation + User + Account)
accounts: 19.303s
Created 400 myObjects in parallel
objectsP: 7.482s
Created 400 myObjects in sequence
objectsS: 4.174s

The second run (4.5.0) also logs these errors in the console:

error: Uncaught internal server error. {"stack":"Error"}
error: Uncaught internal server error. {"stack":"Error"}
error: Uncaught internal server error. {"stack":"Error"}
error: Uncaught internal server error. {"stack":"Error"}
[Error]
[Error]
[Error]
[Error]
[Error]
[Error]

These errors disappear if I reduce the number of parallel accounts creation from 300 to 10 https://github.com/saulogt/test-parse-server4/blob/master/tester.js#L74

Expected Outcome

Similar performance when compared with version 3.x and no errors

Failing Test Case / Pull Request

• 🤩 I submitted a PR with a fix and a test case.
• 🧐 I submitted a PR with a failing test case.

Environment

Server

• Parse Server version: 4.5.0
• Operating system: MacOS 11.3.1
• Local or remote host (AWS, Azure, Google Cloud, Heroku, Digital Ocean, etc): Local also happens on Heroku

Database

• System (MongoDB or Postgres): mongodb
• Database version: 4.4.6
• Local or remote host (MongoDB Atlas, mLab, AWS, Azure, Google Cloud, etc): Local and MongoDB Atlas

Client

• SDK (iOS, Android, JavaScript, PHP, Unity, etc): Javascript
• SDK version: 2.19.0

Logs

[mtrezza]

Thanks for providing this investigation report.

In your repo you mention the difference between Parse Server 3.10 and 4.5. Did you only observe the difference in 4.5 or in versions prior to 4.5 too?

[saulogt]

All versions >= 4.0.0 have the performance problem.
I did the test again using all versions between 3.10 and 4.5.
This time I didn't observe the same difference as before, but the parallel operation test is still more than 2x slower than in 3.10

I noticed this time that the error message started in version 4.3.0 with a slightly different content:

...
error: Uncaught internal server error.NAPI error {"stack":"Error: NAPI error"}
error: Uncaught internal server error.NAPI error {"stack":"Error: NAPI error"}
[Error: NAPI error]
[Error: NAPI error]
...

Version	Parallel operation time spent	Error logged
3.10	598.99ms	NO
4.0.2	1.117s	NO
4.1.0	1.123s	NO
4.2.0	1.165s	NO
4.3.0	1.260s	error: Uncaught internal server error.NAPI error {"stack":"Error: NAPI error"} [Error: NAPI error]
4.4.0	1.150s	error: Uncaught internal server error. {"stack":"Error"} [Error]
4.5.0	1.177s	error: Uncaught internal server error. {"stack":"Error"} [Error]

[dplewis]

Can include the latest master branch for your performance tests? A lot of performance improvements have been added since 4.5.0

[mtrezza]

Thanks for doing more tests.

It would also be interesting to know the Node.js version you are running these tests on.

To make the tests more comparable, the influence of caches, especially on the DB side, should be addressed. I assume you did not do each test with fresh MongoDB servers, so the WT cache may skew the results. One way to address this would be to restart the MongoDB server for each test (of you are using a local DB) or force a resync or double-failover (for hosted replica sets).

A test on the master branch could yield some insight, because it contains a lot of changes (some of them breaking), and the issue may be been fixed by now, although I am not aware a specific PR that addressed the issue you are describing.

Regarding the error log, you could set a semantic breakpoint that shows where in code the error occurs and what the stack trace is. If you could post that there, it could give more insight.

[mtrezza]

Maybe related:

• Saving 3000 objects in cloud code with saveAll takes more than 10 seconds #5471

[saulogt]

I tested against master (5abbeeb), and the logged errors are gone. However, the performance issue remains with an interesting difference... The sequential save performance is slightly better. How is that possible?

The result with the unreleased version was:

Created 400 myObjects in parallel
objectsP: 1.184s
Created 400 myObjects in sequence
objectsS: 895.12ms

How can this ...

for (const o of objcts) {
    await o.save(null, { sessionToken: a.user.getSessionToken() });
}

be faster than this?

await Promise.all(objcts.map((o) => o.save(null, { sessionToken: a.user.getSessionToken() })));

[saulogt]

My guess is that the degraded performance on parallel tasks can create a compound effect in very busy servers like ours.

[mtrezza]

The sequential save performance is slightly better. How is that possible?

There has been a change in how schema changes are fetched, so that a Parse Server find/fetch - and I think also save - may be improved.

My guess is that the degraded performance on parallel tasks can create a compound effect in very busy servers like ours.

It may as well be an infrastructure limitation. I haven't tested your demo repo out myself, but would be interested to see perf metrics from other environments. We should also male sure there are no caches skewing the results between tests.

[saulogt]

Thanks for your attention @mtrezza

Speaking about infrastructure, the production env that I deployed my code with the last parse-server version (and had to rollback) is a Heroku PL dyno (Performance Large) with min autoscale count of 2 and WEB_CONCURENCY=8. We also use redis cache

The unreleased version definitely has improvements in performance. But it's still bad compared to 3.10.
I'll run the same test in a more real world environment, possibly enabling hooks and some custom configuration

Thanks again

[mtrezza]

Heroku dynos are abstracted shared black boxes, so it may be difficult to infer something from their metrics.

We should also make sure we compare with the same parse server, node, system, nginx, db, etc settings, because latency can be introduced at any point. @dplewis, can you please run these tests (as part of the PCP), I think it is significant enough to be looked at with priority.

This confirms that we would do good to pursue #7329, a CI check that compares the Parse Server performance with vs. without a PR.

[dplewis]

@saulogt It is recommended to use Parse.Object.saveAll instead of Promise.all because of internal batching but I believe there maybe a bigger issue. Can you try this WIP branch for tests https://github.com/parse-community/parse-server/tree/schema-reduction

[saulogt]

@dplewis Thanks for the headsup. I'm actually trying to be closer to the multiple clients saving at the same time. In this case, saveAll is not adequate.

@mtrezza I tried to deploy a test app with the unreleased master version, but I got many errors, maybe I missed something.
Any idea when we'll get a release with all improvements from master?

[mtrezza]

Any idea when we'll get a release with all improvements from master?

I expect later this year. Master currently contains many breaking changes (some quite fundamental) and therefore we'll try to bring this into our planned alpha/beta distribution process according to the new release cycle. So we get feedback before making it an official release.

[saulogt]

Cheers!
I tested the beta version (5-beta.4) and it's very promising. With slightly better performance than 3.10.
I'm looking forward to seeing it released. Unfortunately, we had to skip version 4.x as it's just broken

[mtrezza]

Thanks for the feedback. I would not conclude that 4.x is broken as you suggest. It's also often difficult to compare custom performance runs. There have indeed been some cache-related improvements though and some experimental features that have been activated in 5.x. Thanks for testing out 5.x beta and please let us know any feedback you may have.

[dblythy]

I have observed and identified a few additional bottlenecks in the schema/role logic here @mtrezza (not relating to the extends issue

[mtrezza]

Cool, is this still relevant for Parse Server 6?

[dblythy]

After investigating, I have found that:

• Parse Server bottlenecks many calls with the same session_token, as each call runs RestQuery on the role class, which bottlenecks again
• For each time config is called, new DatabaseController is called, resulting in the schema cache clearing
• When multiple objects are saved, the schema is re-fetched from the database (rawFind)
• This puts additional workload on the database and limits the capacity by around 40-50% for bursts of traffic

Average execution time in RestWrite, with a Promise of 1500 objects:

{
  getUserAndRoleACL: 2177,
  validateClientClassCreation: 0.0013311111356386796,
  handleInstallation: 0.003325791106058432,
  handleSession: 0.0013293451507157758,
  validateAuthData: 0.0006653348197039767,
  runBeforeSaveTrigger: 0.016632928996368694,
  ensureUniqueAuthDataId: 0.0006648933234732508,
  deleteEmailResetTokenIfNeeded: 0.0013293451507157758,
  validateSchema: 5952.8060537963165,
  setRequiredFieldsIfNeeded: 0.017276189004536372,
  transformUser: 0.0006988885332391474,
  expandFilesForExistingObjects: 0.000664451827242525,
  destroyDuplicatedSessions: 0.0019933554817275745,
  runDatabaseOperation: 659.2924497522102,
  createSessionTokenIfNeeded: 0.0013553934283286055,
  handleFollowup: 0,
  runAfterSaveTrigger: 0.005316056114170926,
  cleanUserAuthData: 0.000664451827242525
}

The total promise chain takes 12s to resolve, with 2s being getUserAndRoleACL, 6s being validateSchema, and only 0.5s being the actual databaseOp.

@mtrezza let me know how you think we should address this

[mtrezza]

Great investigation, sure, please feel free to go ahead and let me know if you need anything

[dblythy]

Upon further review, most of the bottleneck seems to happen due to multiple object class creation and schema updates at the same time.

This doesn’t seem like it would affect production servers, as schemas are normally fixed, and new classes are not allowed to be created.

there are some minor improvements that we can generally make but I’m not convinced the 50% slowdown as previously mentioned would occur on a server that has schemas, classes, etc set up.