1541681 - Reproducible MOZ_RELEASE_ASSERT(mUsage == mDEBUGUsage) crash

Status: RESOLVED FIXED

(Core :: Storage: localStorage & sessionStorage, defect)

Description

[Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧]

I updated Nightly on a Mac and it's now crashing on startup while restoring my session. Se bp-e9817abe-3187-4837-aef4-3a1960190404 and bp-0be3befe-86e1-4d0d-a60b-445740190404 but I don't know what page is causing it. I tried creating a new profile and loading the sites from the foreground tab and each of the pinned tabs, but it doesn't reproduce with that, only my main profile. From the stack, it seems to have something to do with some kind of local storage.

Comment 1

[Jan Varga [:janv]]

Attachment: Bug 1541681 - LSNG: Disable assertion in optimized builds until the issue is solved; r=jld

Comment 2

[Jan Varga [:janv]]

Hey, sorry for the trouble, but this is actually very useful. Can you privately share the webappsstore.sqlite from your profile ?
It contains all your existing local storage data. It's probably the conversion from old database to new database that is causing this assertion.
You can disable new local storage implementation by setting dom.storage.next_gen to false until the assertion is disabled in next Nightly.

Comment 3

[Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧]

I tried the attached patch (modified slightly, because I'd just finished a debug build) and it got farther into startup, but failed in Snapshot::RecvCheckpoint:

Assertion failure: mUsage >= 0, at /Volumes/src/gecko-dev/dom/localstorage/ActorsParent.cpp:5357
#01: mozilla::dom::PBackgroundLSSnapshotParent::OnMessageReceived(IPC::Message const&)[/Volumes/src/gecko-dev/obj-x86_64-apple-darwin17.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0xc4835d]

Comment 4

[Jan Varga [:janv]]

Jed, could you please convert all such assertions to MOZ_ASSERT ?
It would be also very useful if you identified the origin that is causing this while you are there.
PrepareDatastoreOp has mOrigin string member, also Datastore has mOrigin string member.
Snapshot has mDatastore member.

Comment 5

[Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧]

The origin was mozilla.slack.com; I had it open in a pinned tab. I've seen other people report that navigating to Slack reproduces it, so probably the reason it didn't reproduce for me in a clean profile is what comment #2 said about the database conversion.

Bug 1540401 was backed out of m-c; I'll try an opt build of that once it finishes.

Comment 7

[Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧]

I've verified that the revision with the backout works.

Comment 8

[Jan Varga [:janv]]

So this is actually a bug in mozStorage.
Here's a quick fix:

diff --git a/storage/mozStorageStatement.cpp b/storage/mozStorageStatement.cpp
--- a/storage/mozStorageStatement.cpp
+++ b/storage/mozStorageStatement.cpp
@@ -665,17 +665,17 @@ Statement::GetString(uint32_t aIndex, ns
   NS_ENSURE_SUCCESS(rv, rv);
   if (type == mozIStorageStatement::VALUE_TYPE_NULL) {
     // NULL columns should have IsVoid set to distinguish them from the empty
     // string.
     _value.SetIsVoid(true);
   } else {
     const char16_t *value = static_cast<const char16_t *>(
         ::sqlite3_column_text16(mDBStatement, aIndex));
-    _value.Assign(value, ::sqlite3_column_bytes16(mDBStatement, aIndex) / 2);
+    _value.Assign(value);
   }
   return NS_OK;
 }

 NS_IMETHODIMP
 Statement::GetVariant(uint32_t aIndex, nsIVariant **_value) {
   if (!mDBStatement) {

         return NS_ERROR_NOT_INITIALIZED;

Comment 9

[Jan Varga [:janv]]

However, there are probably other spots in mozStorage that need to be updated. We will have to review it carefully.

Comment 10

[Lina Butler [:lina]]

Oops, I added another use of sqlite3_column_bytes16 here, following Mak's suggestion. (Statement::GetVariant is only used for Sync code that's pref'd off by default, though...and I forgot to commit the changes to Row::initialize, which is probably good in retrospect).

Comment 11

[Jan Varga [:janv]]

Yeah, "sqlite3_column_bytes16 / 2" doesn't work well if there are characters that take more than 2 bytes.
I'm investigating this more, since this requires more sophisticated fix.

Comment 12

[Marco Bonardo [:mak]]

I'm not sure plain removing the usage of sqlite3_column_bytes16 is correct, its usage is actually suggested by the Sqlite docs (https://www.sqlite.org/c3ref/column_blob.html).
Are we storing non utf8 text in utf8 columns, or non utf16 in utf16?

Comment 13

[Marco Bonardo [:mak]]

(that said, it sounds to just divide by 2, it's number of bytes, the string requires an appropriate conversion)

Comment 14

[Jan Varga [:janv]]

The problem is that nsString sometimes needs to use more than 2 bytes for a "char" or code unit. I need to do more investigation, since this is probably quite sensitive/risky change.

Comment 15

[Marco Bonardo [:mak]]

Well, units are always 2 bytes, symbols can take more than 1 unit. _bytes16 / 2 is correct if we are looking for the number of units. It seems to boil down to whether nsString.Assign expects number of units or number of symbols. That said, the original string stored in the db should be proper utf-16 (not multibyte or such).
Anyway, I asked to the Sqlite team if the policy in the documentation is for specific cases or general, all the strings returned by _text and _test16 are zero terminated, so we may not actually need those length checks. I'll let you know what they say.

Comment 16

[Jan Varga [:janv]]

Ok, thanks. We definitely had to remove _bytes16 / 2 when we were implementing utf16Length in mozStorage.

Comment 17

[Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧]

My understanding, which seems to be backed up by the comments, is that nsTString in general deals with lengths in terms of code units: the UTF-8 instances (nsACString) take byte counts, so the UTF-16 instances (nsAString) should use 2-byte code units, and the bytes / 2 value should be compatible.

Comment 18

[Jan Varga [:janv]]

We already had a discussion about this in bug 1513892.

Comment 19

[Marco Bonardo [:mak]]

So, I got the answer, because _text and _text16 are always 0-terminated and we pass the buffer to our string class (that is zero terminated) we can go without _bytes and _bytes16. In practice we don't need at the same time the buffer and its size, because we don't do any special handling of it apart from moving into a string class.

You're free to remove all the _bytes and _bytes16 calls in mozStorage where they are only used to assign to an xpcom string.

Comment 20

[Jan Varga [:janv]]

Ok, but I still want to do more investigation to be totally sure, especially what is slack storing and why it causes the assertion.

Comment 21

[Lina Butler [:lina]]

Hmm, can the text contain NUL characters? We pass the byte length when we bind; does that mean we'll truncate on the way out?

Comment 22

[Marco Bonardo [:mak]]

I'd consider NUL in the text as a caller bug, anyway.

Comment 23

[Lina Butler [:lina]]

Attachment: slack-localStorage.json

Hmm, on a hunch, I checked my Slack localStorage. There are several Emojis, what looks like combining characters, and NULs.

Comment 24

[Lina Butler [:lina]]

Attachment: data.sqlite

And the DB from profile/storage/default/https+++mozilla.slack.com/ls/data.sqlite.

Comment 25

[Jan Varga [:janv]]

Yeah, it looks like there are NULs in the middle of string values!
So, utf16Length which lets nsDependentString to compute the length is wrong in the end. It stops counting on first NUL:
https://searchfox.org/mozilla-central/rev/9ee63566281365f26e7a4b06c9d4e2219e64c3e8/xpcom/string/nsCharTraits.h#245

Comment 26

[Jan Varga [:janv]]

Filed bug 1542104.

Comment 27

[Jan Varga [:janv]]

Sorry, my original quick patch was a bit misleading. I felt there was something else that was causing this.
Lina, thanks a lot for mentioning NULs, it helped me to find correct solution.
Other comments helped too, thanks to everyone!

Comment 28

[Jan Varga [:janv]]

This is now fixed by bug 1542104.