gatsby: V8 serialize error on build with huge number of pages(100k+)

Thank you very much 👍

The fix was published in gatsby@2.19.22

Please report if there are still problems and provide a repro if that’s the case.

(And hey, if your issue is now fixed, let me know too 😃 )

Ok, I am looking into it now. Consider this a research post while I’m trying to dig in.

I think https://github.com/nodejs/help/issues/1059 is interesting because that implies that there shouldn’t be a concrete difference between the v8.serialize and json.stringify, apart from a more aggressive gc schedule. This could very well be the reason. Additionally we might consider that the performance improvement of using v8.serialize over json.stringify is only perceived and the cost is ultimately still paid before the process exits. That’s an interesting fact.

Keep in mind, async operations may change the impact, as an async operation might give nodejs more idle time to run GC. Of course, if postponing GC leads to OOMs we need to re-evaluate that.

---

The repro.

I had to install mongo (sudo apt-get install mongodb mongo-clients) because that wasn’t available on my xfce/ubuntu system.

I had to update the script a tiny bit to get the repo working;

    db.repro.insert({
			title: `${rest.title}-${i}`,
			body: `${rest.body}-${i}`,
			slug: `${rest.slug}-${i}`
    });

because I was getting “invalid id” errors by mongo (added the suffix because why not, I realize the repo doesn’t have that).

Running it on 10k pages without bumping the memory quickly OOMs during sourcing.

Running it with 12GB;

Memory consumption remains fairly stable during the sourcing step (~4gb?). Sourcing takes about 730s (yikes). I’ll have to look into that on a separate note. On the next run this took just 70 seconds, maybe mongo is caching it? The run queries step runs at literally 1 query per second. Will be testing a fix that was merged yesterday to improve this ~1000x. This patch will not apply to loki btw. Memory consumption during the 1q/s “run queries” slowly increased to 7gb. Immediatey after the run queries step it crashed out, well under the available memory.

Here’s my runtime output:

 😶  13:50:04 (master) v8-issue-repro $ yarn clean; NODE_OPTIONS=--max_old_space_size=12288 SKIP_PAGE_BUILD=1 yarn build
yarn run v1.21.1
$ rm -rf public .cache
Done in 0.06s.
yarn run v1.21.1
$ NODE_ENV=production gatsby build
success open and validate gatsby-configs - 0.020s
success load plugins - 0.300s
success onPreInit - 0.009s
success delete html and css files from previous builds - 0.010s
success initialize cache - 0.007s
success copy gatsby files - 0.022s
success onPreBootstrap - 0.012s

 ERROR 

(node:5411) DeprecationWarning: current Server Discovery and Monitoring engine is deprecated, and will be removed in a future version. To use the new Server Discover and Monitoring engine, pass option { useUnifiedTopology: true } to the MongoClient constructor.

success source and transform nodes - 730.717s
success building schema - 2.564s
success createPages - 2.514s
success createPagesStatefully - 0.177s
success onPreExtractQueries - 0.003s
success update schema - 0.020s
success extract queries from components - 0.075s
warn The GraphQL query in the non-page component "v8-issue-repro/src/templates/post.js" will not be run.
Exported queries are only executed for Page components. It's possible you're
trying to create pages in your gatsby-node.js and that's failing for some
reason.

If the failing component(s) is a regular component and not intended to be a page
component, you generally want to use a <StaticQuery> (https://gatsbyjs.org/docs/static-query)
instead of exporting a page query.

If you're more experienced with GraphQL, you can also export GraphQL
fragments from components and compose the fragments in the Page component
query and pass data down into the child component — http://graphql.org/learn/queries/#fragments
success write out requires - 0.052s
success write out redirect data - 0.004s
success onPostBootstrap - 0.002s
⠀
info bootstrap finished - 739.732 s
⠀
warn Browserslist: caniuse-lite is outdated. Please run next command `yarn upgrade`
success Building production JavaScript and CSS bundles - 8.467s
success Rewriting compilation hashes - 0.004s
success run queries - 2136.418s - 3335/3335 1.56/s
node/v10.18.1/bin/node[5411]: ../src/node_buffer.cc:420:v8::MaybeLocal<v8::Object> node::Buffer::New(node::Environment*, char*, size_t): Assertion `length <= kMaxLength' failed.
 1: 0x8fa090 node::Abort() [node/v10.18.1/bin/node]
 2: 0x8fa165  [node/v10.18.1/bin/node]
 3: 0x91b8fa  [node/v10.18.1/bin/node]
 4: 0x990755  [node/v10.18.1/bin/node]
 5: 0xb8e7df  [node/v10.18.1/bin/node]
 6: 0xb8f349 v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*) [node/v10.18.1/bin/node]
 7: 0x5b254ddbe1d 
Aborted (core dumped)
error Command failed with exit code 134.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.

The crash is not a regular OOM but a string length assertion error. Perhaps the serialized content is too much to bear. (After all, there are inherent limits to nodejs, a maximum string length is one of them.)

The above ran on gatsby@2.17.7 in node v10.17.

Bumping it to gatsby@2.19.8 (yarn add gatsby@2.19.8).

This time the sourcing step improved, but there was no change to the run queries time. Debugging that it seems it doesn’t use a filter at all. It seems the slowness is coming from the html handler. Will have to look into that later.

After about three or four restarts (while debugging) the build now OOMs during the createPages step, which took 2s before. And I cannot get it to move forward. In this case I can see the memory grow (relatively) rapidly and after ~2 minutes the 12gb are up and it OOMs. I took a break and picked it up the next day. When I got back to it this step was fine again, not sure what is causing this… Can anyone reliably repro this problem?

This makes me wonder whether there aren’t two things at play here. My OOM problem certainly seems to stem from another source. I use gatsby clean for every step so it’s not something that’s stored in .cache or public. Maybe Mongo does something differently. Restarting it did not help.

Regenerating the db with 100 pages makes the run finish fine, in 10s. Not unexpected but good to see that still works. I checked into why the queries run so slow. Turns out they are actually under reporting their work; each query is running remark for every post on the page. By default there are 30 pages on each page so remark is called 30 times for that fact alone, but it visually counts as one step for the query.

If I go into gatsby-transformer-remark and add return 'foo' in the resolve(markdownNode, { format, pruneLength, truncate }) { function, then the queries speed up drastically and the 100k site completes within reasonable time (~4.5 minutes). (This does expose a scaling issue as the small site runs to completion much faster than a big site, but that’s a different issue to deal with later). And with this hack the assert is still proced so that’s a decent repro. And allows us to skip a decent chunk of code 😃

success run queries - 186.415s - 3335/3335 17.89/s
node[8201]: ../src/node_buffer.cc:420:v8::MaybeLocal<v8::Object> node::Buffer::New(node::Environment*, char*, size_t): Assertion `length <= kMaxLength' failed.
 1: 0x8fa090 node::Abort() [node]
 2: 0x8fa165  [node]
 3: 0x91b8fa  [node]
 4: 0x990755  [node]
 5: 0xb8e7df  [node]
 6: 0xb8f349 v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*) [node]
 7: 0x190294e5be1d 
Aborted (core dumped)

Then I confirmed whether this problem pops up with JSON.stringify; Change the v8 bits in persist.ts to use json instead. No assert crash.

Now this isn’t necessarily a surprise. v8.serialize is more efficient because of a few reasons, but it probably also serializes more data than JSON.stringify, which is not designed to serialize functions or class instances. Let’s take a look at the output for a small number of pages;

I compared the v8.serialize to the old way of doing json.stringify (using https://github.com/stefanprobst/gatsby/blob/c043816915c0e4b632730091c1d14df08d6249d4/packages/gatsby/src/redux/persist.js as a reference point). Both ways dump about 500k of data.

Before I “checked” the assert with a simple JSON.stringify. However, I need to run this again since the original way of stringifying was capturing a lot more. Running it again also shows warn Error persisting state: Invalid string length, but it’s non-fatal and teh build completes. Probably not saving the redux state, though 😉

Next I checked whether I could catch the assertion error. This is more difficult because the error happens somewhere inside the serialzation call and we don’t control the assert. It doesn’t appear to be try-catchable… 😦 Arguably this is a bug in nodejs as the assert should instead throw a catchable error (like happens with JSON.stringify), but I doubt anyone cares to change that.

---

The way forward

So after some discussion we’re going to try to chunk the pages nodes. Ultimately we’re hitting the arbitrary buffer limit and there’s no easy way to fix that. So instead we’ll first serialize the redux state without the page nodes. Then we’ll try to apply some heuristics to chunk the page nodes such that they stay well below this limit. This means the redux state has to be serialized across multiple files, but that should also means that it won’t fatal.

We’re gonna be a little busy the next week but watch this space.

I have tested this issue on gatsby 2.17.7 and node 13.0.1. Issue still persists.

Updated the repro repo.

Currently facing this issue with a production site running on gatsby.

Awesome @ganapativs thanks for creating this repro.

@sidharthachatterjee As discussed the other day, created a repro here. Please look into it 👍