Closed Bug 1601499 Opened 2 years ago Closed 2 years ago

All cookies are lost after restarting Firefox, cookies.sqlite is gone

Categories

(Core :: Networking: Cookies, defect, P3)

70 Branch
x86_64
Linux
defect

Tracking

()

RESOLVED FIXED
mozilla74
Tracking Status
firefox74 --- fixed

People

(Reporter: peter, Assigned: robwu)

Details

(Whiteboard: [necko-triaged])

Attachments

(3 files)

Sometimes, restarting Firefox causes all cookies to be lost. Closer inspection of the profile folder reveals that cookies.sqlite got renamed to cookies.sqlite.bak. A new cookies.sqlite.bak-rebuild file is present, but without any database rows.

When the problematic situation is observed, Firefox is still active and operates normally. I don't recall seeing special messages in the global browser console or standard error.

Expected result:

  1. Obviously I would expect cookies.sqlite not to get corrupted, and not observe the cookies.sqlite.bak file.
  2. If cookies.sqlite becomes corrupt, Firefox should try its best to recover it. For example, by writing all in-memory cookies to cookies.sqlite.

Reproducer:
I have no reliable steps to reproduce. 11 days ago I started Firefox with special debug options, and today I finally detected the problematic event. To debug, start Firefox with:

mkdir /tmp/moz-cookies
MOZ_LOG=cookie:3 MOZ_LOG_FILE=/tmp/moz-cookies/cookies firefox

In cookies.moz_log, the following messages were visible around the time the cookies.sqlite file got renamed (see attachment for full context):

DBListenerErrorHandler::HandleError(): Error 19 occurred while performing operation 'INSERT' with message 'UNIQUE constraint failed: moz_cookies.name, moz_cookies.host, moz_cookies.path, moz_cookies.originAttributes'; rebuilding database.

HandleDBClosed(): DBState 0x7f33886ac100 encountered error rebuilding db; move to 'cookies.sqlite.bak-rebuild' gave rv 0x0

Environment:
My Firefox profile is several years old, probably from 2011 or 2013.
The above issue was reproduced with Firefox 70.0.1 on Arch Linux.
I noticed the problem for the first time at 2019-08-10, at that time I was running either Firefox 67.0.4-1 or Firefox 68.0.1-2. Not sure if relevant, but the laptop was not properly shutdown prior to that event while Firefox was still running (system sleep, failure to resume -> hard shutdown). I rarely restart my browser, it may take several weeks before I do so.

In total I have noticed the problem five times:
2019-08-10 Firefox 67.0.4-1 or Firefox 68.0.1-2
2019-09-07 Firefox 68.0.1-2
2019-10-11 Firefox 69.0-1
2019-11-11 Firefox 70.0.1-1
2019-12-04 Firefox 70.0.1-3

Other information:
If it is relevant, there appears to be a difference between the cookies.sqlite database scheme of my cookies.sqlite and one from a fresh Firefox profile (both using Firefox 71.0-1):

--- my old Firefox profile/cookies.sqlite
+++ a fresh Firefox profile/cookies.sqlite
@@ -1,3 +1,3 @@
-CREATE TABLE IF NOT EXISTS "moz_cookies" (
+CREATE TABLE moz_cookies (
     id INTEGER PRIMARY KEY,
     baseDomain TEXT,
@@ -13,6 +13,6 @@
     isHttpOnly INTEGER,
     inBrowserElement INTEGER DEFAULT 0,
-    sameSite INTEGER,
-    rawSameSite INTEGER,
+    sameSite INTEGER DEFAULT 0,
+    rawSameSite INTEGER DEFAULT 0,
     CONSTRAINT moz_uniqueid UNIQUE (name, host, path, originAttributes)
 );

In my cookies.sqlite, about 60% of all cookies have NULL sameSite and rawSite fields.

(In reply to Peter Wu from comment #0)

If it is relevant, there appears to be a difference between the cookies.sqlite database scheme of my cookies.sqlite and one from a fresh Firefox profile (both using Firefox 71.0-1):

  • sameSite INTEGER,
  • rawSameSite INTEGER,
  • sameSite INTEGER DEFAULT 0,
  • rawSameSite INTEGER DEFAULT 0,

This shouldn't cause the problem. It seems we're trying to insert a duplicate record to the DB.

Honza, can you have a look at this?

Flags: needinfo?(honzab.moz)
Whiteboard: [necko-triaged]

Ehsan, Baku, just in case you get to this sooner than me or can quickly assess. Thanks.

Flags: needinfo?(ehsan)
Flags: needinfo?(amarchesini)

Peter,

Based on comment 0 it appears that your cookie database wasn't upgraded properly. My guess is that this shows a bug somewhere in the Firefox code that handles the cookie database upgrades from older versions. Unfortunately it is impossible to say how the problem happened from the information that you have provided. :-(

The easiest way for us to debug this issue and get to the source of the problem would be if you could provide us with a copy of your original cookie database (from the old Firefox profile). I believe this should be the cookies.sqlite.bak file, but in case you have retained a copy of the old profile you were trying to use, it would be cookies.sqlite within that folder. If you are comfortable with sharing this file, I would really appreciate if you could please send me a copy of it via email. Please avoid attaching it to Bugzilla as the database may contain your private information (such as your login cookies to various services). I would be happy to look at what's happening in our code which is resulting in this problem.

Thanks!

Flags: needinfo?(ehsan)

Rob pinged me on Slack and asked if I can provide some details on how to debug this without sending the full cookie DB which understandably contains a lot of sensitive private data. Here is some info to help you get started, please let me know if you get stuck somewhere or if you needed help.

The way we upgrade the cookie database (and many other internal databases for that matter) is by reading the current "sqlite user version" of the database to detect if it matches the current version that our build knows about, and if not run a set of steps to upgrade the versions in order. For example, our current cookie database version is 10. You can discover the version of the old cookie database file with a command like this:

sqlite3 /path/to/cookies.sqlite.bak
pragma user_version;
5

Let's assume the version of the old DB is 5. When we're initializing the database we read this version and compare it to the latest version (in our case 10). If it is less than that we use a giant switch statement here with a number of case statements one for each old DB version which all fall through to the next case statement. The idea here is that a case statement N upgrades the DB from version N to N+1.

So if we start at 5 we would enter the switch around here for example. So somewhere before this switch statement would be an ideal place to set a breakpoint if you'd like to debug this. Of course you need to place the old cookie DB as cookies.sqlite in the profile folder to trigger the upgrade code to run.

Based on the error message in comment 0 I would expect that the upgrade would fail at some point, probably while running an INSERT statement, due to us attempting to insert some duplicate data somehow. Once you found out what INSERT statement is failing, that is the first interesting bit of information. The second interesting bit of information is to discover something about the duplicate data. Based on the SQL statement in question you can inspect the contents of the DB after that point in the sqlite3 command line application manually to discover what the DB contents are and how you are ending up with duplicate data. The how behind that is the second bit of interesting information here. Here I would expect the name/value/site of the cookie(s) in your DB to be of interest but since all we need to know is whether they're duplicates if you're uncomfortable with sharing the real values you can substitute dummy values instead.

Once we have all of this figured out it should be possible to delete everything in the original (pre-upgrade) moz_cookies table except for the data that causes the duplicate insertion bug and reproduce the upgrade error. Once we're there we have everything we need in order to figure out how to fix the bug and create a test case for it.

Thanks!

Thanks for the pointers! No database upgrade was necessary, user_version is 10 which seems to be the current version. The problem occurs while Firefox is running. I managed to isolate a reproducer based on this cookie:

id:                 202497
baseDomain:         'freedesktop.org'
originAttributes:   ''
name:               'sidebar_collapsed'
value:              'false'
host:               'gitlab.freedesktop.org'
path:               '/'
expiry:             1852128348
lastAccessed:       1536768348400118
creationTime:       1536768141428630
isSecure:           0
isHttpOnly:         0
inBrowserElement:   0
sameSite:           0
rawSameSite:        0

The attached cookies.sqlite is based on by cookie database with all other cookies removed and VACUUMed. Revised steps to reproduce:

  1. Create a new directory "prof" with the attached cookies.sqlite
  2. Run MOZ_LOG=cookie:4 MOZ_LOG_FILE=$PWD/cookies firefox -no-remote -profile $PWD/prof
  3. Open https://gitlab.freedesktop.org/NetworkManager/NetworkManager/issues/310#note_378903
  4. Observe corruption in log and note that cookies.sqlite got renamed (confirmed with Firefox 72.0-1).

The following can be found in cookies.moz_log (the [Parent 44669: Main Thread]: ` prefix was stripped and some lines were wrapped):

D/cookie ===== COOKIE ACCEPTED =====
D/cookie request URL: https://gitlab.freedesktop.org/NetworkManager/NetworkManager/issues/310#note_378903
D/cookie cookie string: sidebar_collapsed=false; expires=Sun, 06 Jan 2030 00:15:57 GMT; path=/
D/cookie replaces existing cookie: false
D/cookie current time: Thu Jan 09 00:15:57 2020 GMT
D/cookie ----------------
D/cookie name: sidebar_collapsed
D/cookie value: false
D/cookie host: gitlab.freedesktop.org
D/cookie path: /
D/cookie expires: Sun Jan 06 00:15:57 2030 GMT
D/cookie created: Thu Jan 09 00:15:57 2020 GMT
D/cookie is secure: false
D/cookie is httpOnly: false
D/cookie origin attributes: {empty}
D/cookie 
W/cookie DBListenerErrorHandler::HandleError(): Error 19 occurred while
        performing operation 'INSERT' with message 'UNIQUE constraint failed:
        moz_cookies.name, moz_cookies.host, moz_cookies.path,
        moz_cookies.originAttributes'; rebuilding database.
W/cookie 
D/cookie HandleCorruptDB(): DBState 0x7ff1fcf8d2e0 has corruptFlag 0
D/cookie 
D/cookie HandleDBClosed(): DBState 0x7ff1fcf8d2e0 closed
D/cookie 
D/cookie RebuildCorruptDB(): creating new database
D/cookie 
W/cookie DBListenerErrorHandler::HandleError(): Error 19 occurred while
        performing operation 'INSERT' with message 'UNIQUE constraint failed:
        moz_cookies.name, moz_cookies.host, moz_cookies.path,
        moz_cookies.originAttributes'; rebuilding database.
W/cookie 
D/cookie HandleCorruptDB(): DBState 0x7ff1fcf8d2e0 has corruptFlag 2
D/cookie 
D/cookie HandleDBClosed(): DBState 0x7ff1fcf8d2e0 closed
D/cookie 
W/cookie HandleDBClosed(): DBState 0x7ff1fcf8d2e0 encountered error rebuilding
        db; move to 'cookies.sqlite.bak-rebuild' gave rv 0x0

Interestingly, the affected website does not send this "sidebar_collapsed" cookie, but Firefox does send it with some requests (not all). Are you able to reproduce the issue based on this information?

Forgot to add:

  • Renaming that cookie from "sidebar_collapsed" to "dummy" using sqlite3 prevented the corruption problem.
  • I did not see the "sidebar_collapsed" cookie in a HTTP response header (verified in Developer tools as well as in Wireshark). It is presumably set from Javascript.
  • The site was in fact the same site that made me report the initial bug.
  • The original "sidebar_collapsed" cookie was still valid until September 2028.
  • If I delete the original cookie, the new cookie will have a baseDomain of "gitlab.freedesktop.org" as opposed to the previous "freedesktop.org".

Based on the debug log message, I think that findCookie somehow fails in: https://searchfox.org/mozilla-central/rev/a92ed79b0bc746159fc31af1586adbfa9e45e264/netwerk/cookie/nsCookieService.cpp#3401-3402

Assuming that the host is gitlab.freedesktop.org, path is / and name is sidebar_collapsed, I guess that for whatever reason this condition fails:

  nsCookieEntry* entry = mDBState->hostTable.GetEntry(aKey);
  if (!entry) return false;

I tried this on https://www.example.com/ as well as https://anongit.freedesktop.org/:

document.cookie="foo=bar; expires=Fri, 01 Jan 2038 00:00:00 GMT; path=/"

The former yields a "baseDomain" of "example.com" whereas the latter yields "anongit.freedesktop.org". My guess is that this is related to "freedesktop.org" appearing on the PSL since 10 May 2018 https://github.com/publicsuffix/list/commit/65ddeb3eca4cfd9f436f7b2fed49df57624d40f7
(pushed on 24 October 2018 for Firefox 65.0a1 in https://hg.mozilla.org/mozilla-central/rev/23895ff54c060382cc4a4900d9e5b61157beb746)

When my cookie was originally created (Wed 12 Sep 16:02:21 UTC 2018 according to date -ud@1536768141.428630), it presumably used the old PSL which would result in a baseDomain of "freedesktop.org". This explains why the previously mentioned GetEntry(aKey) would fail. baseDomain has changed:

  nsAutoCString baseDomain;
  nsresult rv =
      GetBaseDomain(mTLDService, aHostURI, baseDomain, requireHostMatch);
  //   ...
  nsCookieKey key(baseDomain, aOriginAttrs);
  // ...
  while (SetCookieInternal(aHostURI, key, requireHostMatch, cookieStatus,

the baseDomain (via key) propagates:

bool nsCookieService::SetCookieInternal(
    nsIURI* aHostURI, const mozilla::net::nsCookieKey& aKey,
    bool aRequireHostMatch, CookieStatus aStatus, nsCString& aCookieHeader,
    int64_t aServerTime, bool aFromHttp, nsIChannel* aChannel) {
// ...
  AddInternal(aKey, cookie, PR_Now(), aHostURI, savedCookieHeader, aFromHttp);

Finally AddInternal passes aKey to FindCookie. The hostTable keys are however based on the old baseDomain from cookies.sqlite (freedesktop.org) whereas the given aKey uses the new baseDomain (gitlab.freedesktop.org). Hence no cookie is found even though a duplicate index entry indeed exists. Possible solutions:

  • Implement migration where baseDomain is updated based on host and the current PSL. If this is too expensive, it could be added as fallback when no cookie was initially found.
  • Add baseDomain to the index. I don't think this is correct though.
  • ...

I can confirm the findings above, in 71 and Nightly.

New Firefox produces the following:

INSERT INTO moz_cookies VALUES(4,'gitlab.freedesktop.org','','sidebar_collapsed','false','gitlab.freedesktop.org','/',1893895783,1578535783606026,1578535775964779,0,0,0,0,0);

Old Firefox produced the following:

INSERT INTO moz_cookies VALUES(202497,'freedesktop.org','','sidebar_collapsed','false','gitlab.freedesktop.org','/',1852128348,1536768348400118,1536768141428630,0,0,0,0,0);

Due to the dynamic nature of the public suffix list (entries can be added and removed), it is likely not feasible to add database migrations.
I think that the most effective way to fix this bug is to normalize the key upon reading from the database, at https://searchfox.org/mozilla-central/rev/be7d1f2d52dd9474ca2df145190a817614c924e4/netwerk/cookie/nsCookieService.cpp#2706,2708 . Doing so would fix this bug, because that (normalized) key would then correctly be inserted in the hash table at https://searchfox.org/mozilla-central/rev/be7d1f2d52dd9474ca2df145190a817614c924e4/netwerk/cookie/nsCookieService.cpp#1407 .

Ehsan, could you find someone to work on this?

Status: UNCONFIRMED → NEW
Ever confirmed: true
Flags: needinfo?(ehsan)

I've written a unit test, and confirmed that my suggestion from comment 8 works as expected. I'll attach the patch.

It seems that the baseDomain field is obsolete, and it could be removed from the database (if compatibility with older Firefox versions is not a concern). It used to be used to look up cookies, but that was removed in bug 870460. As part of that bug, the whole database is read at once instead of individually. Because of this, even if the column is kept for backwards-compatibility, then at least the index can be removed because maintaining it has overhead, for no benefit in Firefox.

Assignee: nobody → rob
Status: NEW → ASSIGNED
Flags: needinfo?(honzab.moz)
Flags: needinfo?(ehsan)
Flags: needinfo?(amarchesini)

baseDomain is used as a key for cookies in a hashmap. For cookie
operations to work properly, the baseDomain generation must be stable.
This is however not the case, because the result can change by updates
to the public suffix list.

Since the stored baseDomain is not reliable, the value must be
recomputed when the database is read.

Thanks for the great detective work here, Peter! I filed bug 1609176 as a follow-up to deal with the baseDomain field.

Pushed by rob@robwu.nl:
https://hg.mozilla.org/integration/autoland/rev/3ca301cd061f
Compute baseDomain when cookies are read from the db r=Ehsan
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla74

Fuck! This shit isnt fixed! Firefox keeps wiping my cookies, after power outage or 1-2 browser crashs in a row (1-3 mins betwwen them). It just place empty 512kb cookies file -_- VERY DISSAPOINTED!!!!!!!!!!!!!!!!!!!!!!

On other profile FF rebuild cookies or somthing and also wipe cookies (and storage maybe) and created cookies.sqlite.bak-rebuild (maybe other files, I dont check)
^This profile never used since NOV, 2020

check this^

Flags: needinfo?(rob)

(In reply to dddddddddddddd from comment #14)

****! This shit isnt fixed! Firefox keeps wiping my cookies, after power outage or 1-2 browser crashs in a row (1-3 mins betwwen them). It just place empty 512kb cookies file -_- VERY DISSAPOINTED!!!!!!!!!!!!!!!!!!!!!!

This looks unrelated to the bug report here. It sounds like your disk (or at least Firefox's profile data) might have been corrupted as the result of the power outage, and that Firefox unsuccessfully tries to recover your data. I suggest that you verify the integrity and repair errors if needed (e.g. with chkdsk).

According to your comment, you've experienced some crashes too. If you submit the crash reports and share the crash IDs (see about:crashes), then these can be investigated further.

In any case, the issues you've reported are unrelated to this old bug report, so please file a new bug instead of adding further comments here.

Flags: needinfo?(rob)
You need to log in before you can comment on or make changes to this bug.