2005613 - Opening the Suggest database on Android does a lot of IO (32MB read + 16MB write)

Status: RESOLVED FIXED

(Application Services :: Suggest, defect)

Description

[Markus Stange [:mstange]]

Once the data has been loaded from the server and inserted into the local database, it appears we get into a bad state (permanently):

• The WAL is 16MB big due to a big transaction (WAL limit is set to 512KB but can't be satisfied due to transaction size)
• The WAL doesn't get truncated because we don't ask for it to be truncated, and because we never close the database, because there's no application shutdown on Android
• During startup, we run a small write transaction (to set the version to the same version it's already at) which triggers a checkpoint
• Odd circumstances make it so that this checkpoint re-applies the WAL changes even when they've already been applied before, during every subsequent startup

Profile: https://share.firefox.dev/3MuCOuJ

It's doing 16MB of reads to build the WAL index, and then 16MB read + 16MB write to re-apply the WAL changes.

I've attempted to create a more-or-less faithful reduced testcase: https://github.com/mstange/sqlite-testcase-repeated-wal-application

I believe we just need the following remedies:

• Run PRAGMA wal_checkpoint(TRUNCATE) after big write transactions
• Potentially split the big insert transaction into multiple smaller transactions, so that the WAL never grows to 16MB in the first place
• Potentially avoid an unnecessary write during DB opening when the version is already the current version
• Maybe also truncate after opening the database, to fix up existing databases in this state

Comment 1

[Markus Stange [:mstange]]

Hi Nan, can you find someone to fix this? It causes activity during startup which slows down Gecko initialization and the initial page load.
Our CI performance tests don't encounter this issue, I believe because we don't wait long enough during the warmup run to fetch the suggest data. But I was able to reproduce it very consistently during manual tests, and I believe our users are hitting this consistently.

Comment 2

[Nan Jiang [:nanj]]

Hi Markus, thanks for the flag and the fix suggestions! We will review this in our next triage.

One more question: does this only happen at the first startup with new profiles, or do you also see it in other cases.

Comment 3

[Markus Stange [:mstange]]

No, it seems to happen at every startup. The bad state doesn't fix itself unfortunately.

Comment 4

[Nan Jiang [:nanj]]

I see. Thanks!

Comment 5

[Jeff Muizelaar [:jrmuizel]]

Some more details about what's going on here.

After doing the large transaction the WAL is large and checkpointed. The WAL index says that maybe the WAL can be reset but the PRAGMA user_version = doesn't trigger the reset (perhaps because it's stored in the database header?). Without any more writes to trigger writing new WAL frames to the WAL it remains untouched.

When sqlite attaches to the database for the first time it truncates the current WAL index and rebuilds it. This reads in the entire WAL because it doesn't have any indication that the WAL has been reset.

My understanding is that if there were a new small write to the WAL it would then get properly reset because the rolling checksums up the subsequent frames would no longer be correct, but since we only do large writes this doesn't ever happen and we're left a large WAL.

Comment 6

[Nan Jiang [:nanj]]

Thanks!

I think this should affect other platforms as well.

Comment 7

[Nan Jiang [:nanj]]

Loop Luc in as we're in talk with AMP about the suggestion data volume.

Comment 8

[BMO Github Automation]

Attachment: [mozilla/application-services] Bug 2005613: Truncate WAL after ingestions for suggest (#7151)

Comment 9

[Nan Jiang [:nanj]]

Closed via https://github.com/mozilla/application-services/pull/7151.

Comment 10

[BMO Github Automation]

Authored by https://github.com/ncloudioj
https://github.com/mozilla/application-services/commit/32693fef638471a3667869ba0c0b7a8bb52c15e3
[main] Bug 2005613: Truncate WAL after ingestions for suggest (#7151)