Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Import/Export: OOM issues & crash on large files #11005

Closed
ErisDS opened this issue Aug 12, 2019 · 1 comment
Closed

Import/Export: OOM issues & crash on large files #11005

ErisDS opened this issue Aug 12, 2019 · 1 comment
Labels
import / upgrade life-cycle stuff: Importing, exporting, upgrading and migrating later [triage] Things we intend to work but are not immediate priority

Comments

@ErisDS
Copy link
Member

ErisDS commented Aug 12, 2019

Note: This issue is conflating different problems with the export and import, buuuuuut they're fundamentally the same in that Ghost's lifecycle tooling has been outgrown by the volumes of data we're now handling, and we need to revisit them.

If you try to import a very large file into Ghost, Ghost can run out of memory and crash (Full error below)

The first part of the error includes a "MaxListenersExceededWarning", which we also see in the import/export tests.

The last part of the error is "Fatal error: Cannot read property 'hardStop' of null" which appears to be a bug at first glance.

We have also seen recently that backups fail when there is a lot of very large content due to using JSON.stringify to create the export/backup.

# This is just a warning that seems to happen when doing a backup...
(node:93780) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 committed listeners added. Use emitter.setMaxListeners() to increase limit

# This is me removing all content prior to import
[2019-08-02 15:56:41] INFO "DELETE /ghost/api/v2/admin/db/" 204 182ms

# This is the actual failure, during a large import
FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory

<--- Last few GCs --->

[93780:0x103001e00]   226875 ms: Mark-sweep 1365.8 (1449.6) -> 1351.6 (1450.6) MB, 428.7 / 0.0 ms  (average mu = 0.176, current mu = 0.111) allocation failure scavenge might not succeed
[93780:0x103001e00]   227371 ms: Mark-sweep 1366.7 (1450.6) -> 1352.4 (1450.1) MB, 460.9 / 0.0 ms  (average mu = 0.125, current mu = 0.072) allocation failure scavenge might not succeed

<--- JS stacktrace --->

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

    0: ExitFrame [pc: 0x2b59b505be3d]
Security context: 0x3f5281b1e6e9 <JSObject>
    1: baseMatches [0x3f52eabbd531] [/Users/hannah/Sites/Ghost/node_modules/lodash/lodash.js:~3555] [pc=0x2b59b56a0c04](this=0x3f52f348d481 <JSGlobal Object>,source=0x3f52932212e9 <Object map = 0x3f52033f1ac1>)
    2: getIteratee [0x3f52b1264059] [/Users/hannah/Sites/Ghost/node_modules/lodash/lodash.js:~5923] [pc=0x2b59b5385c10](this=0x3f52f348d481 <JSGlobal...

 1: 0x10003cf99 node::Abort() [/Users/hannah/.nvm/versions/node/v10.16.0/bin/node]
 2: 0x10003d1a3 node::OnFatalError(char const*, char const*) [/Users/hannah/.nvm/versions/node/v10.16.0/bin/node]
 3: 0x1001b7835 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/Users/hannah/.nvm/versions/node/v10.16.0/bin/node]
 4: 0x100585682 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/Users/hannah/.nvm/versions/node/v10.16.0/bin/node]
 5: 0x100588155 v8::internal::Heap::CheckIneffectiveMarkCompact(unsigned long, double) [/Users/hannah/.nvm/versions/node/v10.16.0/bin/node]
 6: 0x100583fff v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/Users/hannah/.nvm/versions/node/v10.16.0/bin/node]
 7: 0x1005821d4 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/Users/hannah/.nvm/versions/node/v10.16.0/bin/node]
 8: 0x10058ea6c v8::internal::Heap::AllocateRawWithLigthRetry(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/Users/hannah/.nvm/versions/node/v10.16.0/bin/node]
 9: 0x10058eaef v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/Users/hannah/.nvm/versions/node/v10.16.0/bin/node]
10: 0x10055e434 v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationSpace) [/Users/hannah/.nvm/versions/node/v10.16.0/bin/node]
11: 0x1007e6714 v8::internal::Runtime_AllocateInNewSpace(int, v8::internal::Object**, v8::internal::Isolate*) [/Users/hannah/.nvm/versions/node/v10.16.0/bin/node]
12: 0x2b59b505be3d
Stopping Express server
Fatal error: Cannot read property 'hardStop' of null

To Reproduce

  1. Take a very very large JSON file - e.g. ~350MB of pure data [1]
  2. Try to import it locally on your machine

[1]: I can provide an example if needed.

Technical details:

  • Ghost Version: master
  • Node Version: 10.0
@kevinansfield
Copy link
Member

kevinansfield commented Aug 12, 2019

We have also seen recently that backups fail when there is a lot of very large content due to using JSON.stringify to create the export/backup.

This is the error we saw creating a backup during a migration:

<--- Last few GCs --->

[45:0x3f96020]    20511 ms: Mark-sweep 1347.5 (1456.0) -> 1347.5 (1440.0) MB, 72.5 / 0.0 ms  (average mu = 0.100, current mu = 0.001) last resort GC in old space requested
[45:0x3f96020]    20591 ms: Mark-sweep 1347.5 (1440.0) -> 1347.5 (1440.0) MB, 79.9 / 0.0 ms  (average mu = 0.051, current mu = 0.001) last resort GC in old space requested


<--- JS stacktrace --->

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

Security context: 0x295c4cc9e6e9 <JSObject>
    0: builtin exit frame: stringify(this=0x295c4cc91a21 <Object map = 0xf8f31f842a9>,0x1e6679e026f1 <undefined>,0x1e6679e026f1 <undefined>,0x056ad3e61f41 <Object map = 0x3897af307a59>,0x295c4cc91a21 <Object map = 0xf8f31f842a9>)

    1: arguments adaptor frame: 1->3
    2: writeExportFile [0x36823247c019] [/home/ghost/core/server/data/db/backup.js:17] [bytecode=0x1e50c64e6819 offset=99](this=0x...

and in the stderr output:

CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: 0x8f9d10 node::Abort() [node]
 2: 0x8f9d5c  [node]
 3: 0xaffd0e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node]
 4: 0xafff44 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node]
 5: 0xef4152  [node]
 6: 0xf0396f v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [node]
 7: 0xed351b v8::internal::Factory::NewRawTwoByteString(int, v8::internal::PretenureFlag) [node]
 8: 0x1203760 v8::internal::IncrementalStringBuilder::Extend() [node]
 9: 0xfc794e v8::internal::JsonStringifier::SerializeString(v8::internal::Handle<v8::internal::String>) [node]
10: 0xfc7d9b v8::internal::JsonStringifier::Result v8::internal::JsonStringifier::Serialize_<true>(v8::internal::Handle<v8::internal::Object>, bool, v8::internal::Handle<v8::internal::Object>) [node]
11: 0xfccead v8::internal::JsonStringifier::Result v8::internal::JsonStringifier::Serialize_<false>(v8::internal::Handle<v8::internal::Object>, bool, v8::internal::Handle<v8::internal::Object>) [node]
12: 0xfca3fa v8::internal::JsonStringifier::Result v8::internal::JsonStringifier::Serialize_<true>(v8::internal::Handle<v8::internal::Object>, bool, v8::internal::Handle<v8::internal::Object>) [node]
13: 0xfca995 v8::internal::JsonStringifier::SerializeJSReceiverSlow(v8::internal::Handle<v8::internal::JSReceiver>) [node]
14: 0xfc95f1 v8::internal::JsonStringifier::Result v8::internal::JsonStringifier::Serialize_<true>(v8::internal::Handle<v8::internal::Object>, bool, v8::internal::Handle<v8::internal::Object>) [node]
15: 0xfccead v8::internal::JsonStringifier::Result v8::internal::JsonStringifier::Serialize_<false>(v8::internal::Handle<v8::internal::Object>, bool, v8::internal::Handle<v8::internal::Object>) [node]
16: 0xfcdc09 v8::internal::JsonStringifier::Stringify(v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>) [node]
17: 0xbd46d1 v8::internal::Builtin_JsonStringify(int, v8::internal::Object**, v8::internal::Isolate*) [node]
18: 0x3b6a8a75bf7d 
Aborted (core dumped)

This is the code line in question. Writing the backup in this way will cause OOM errors with large datasets because we push the whole database into an in-memory JS object, then call JSON.stringify() on it which will keep grabbing memory until the string for the whole object has been created.

Note for further research: Determine how overall object size and the presence of large individual strings (ie, huge posts) affects memory usage/reaching of limits.

In this particular case the cause was narrowed down to a very large mobiledoc_revisions table that appears to have occurred due to a combination of a site containing very large posts and a Ghost-Admin bug that is triggering continual auto-saves in quick succession. By skipping the mobiledoc_revisions table when generating the in-memory export object the backup was able to complete successfully (the skip has now been added to core in #10993).

To find a little more long-term solution we had a quick look at a number of options for streaming the creation of the JSON string and piping it into a file so that memory isn't exhausted. The most realistic appeared to be json-stream-stringify and a proof of concept was put together to test it...

const JsonStreamStringify = require('json-stream-stringify');

writeExportFile = function writeExportFile(exportResult) {
    var filename = path.resolve(urlUtils.urlJoin(config.get('paths').contentPath, 'data', exportResult.filename));

    const jsonStream = new JsonStreamStringify(exportResult.data);
    const fileStream = fs.createWriteStream(filename);

    jsonStream.pipe(fileStream);

    return new Promise((resolve, reject) => {
        jsonStream.once('error', reject);
        jsonStream.on('end', () => resolve(filename));
        fileStream.once('error', reject);
    });
};

For our example failing db I recorded the following times to complete a backup:

  • ~8sec to finish, json file is 176MB, without mobiledoc_revisions using JSON.stringify
  • ~23sec to finish, json file is 176MB, without mobiledoc_revisions using json-stream-stringify
  • ~1min to finish, json file is 484MB, with mobiledoc_revisions using json-stream-stringify

This shows that json-stream-stringify does work to prevent an OOM error but it comes with a significant speed penalty.

Other things found during research:

@ErisDS ErisDS added import / upgrade life-cycle stuff: Importing, exporting, upgrading and migrating later [triage] Things we intend to work but are not immediate priority labels Aug 21, 2019
@ErisDS ErisDS closed this as completed Aug 21, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
import / upgrade life-cycle stuff: Importing, exporting, upgrading and migrating later [triage] Things we intend to work but are not immediate priority
Projects
None yet
Development

No branches or pull requests

2 participants