1549129 - Add-ons without explicit ID in their manifest.json are removed when the signature is invalid AND their modification time has changed

Status: RESOLVED WONTFIX

(Toolkit :: Add-ons Manager, defect, P1)

Description

[Rob Wu [:robwu]]

We derive the extension ID from the add-on's signature. When the signature is not recognized (e.g. because of bug 1548973), we fall back to manifest.json. But the ID in manifest.json is not required, so we end up believing that some extension packages are not associated with the ID when we parse the XPI again.
When the XPI file has been modified (this does normally not happen), we try to update the database based on the disk content, and because we cannot find an ID, we delete the xpi here in XPIDatabase.jsm. Note that any data that the add-on saved is not lost, and becomes available again when the user re-installs the add-on.

This affects all add-ons without ID in their manifest.json (i.e. most if not all static themes, and many extensions).

Steps to reproduce:

1. Download the XPI for an affected extension, e.g.
   https://addons.mozilla.org/en-US/firefox/addon/epubreader/
   https://addons.mozilla.org/firefox/downloads/file/1753729/epubreader-2.0.8-fx.xpi
2. Prepare a profile directory that is affected by bug 1548973:

# Create a new profile directory
mkdir profiledir

# Disable the hotfix for bug 1548973
echo 'user_pref("app.normandy.enabled", false);' > profiledir/user.js

# Start Firefox with a past time to be able to install the test extension.
faketime '2019-05-04 00:00:00' firefox --no-remote -profile profiledir/ .

# Install epubreader.xpi by clicking on it.
# Quit Firefox.

3. Look at profiledir/extensions/ and observe the existence of "{5384767E-00D9-40E9-B72F-9CC39D655D6F}.xpi"

4. Start Firefox again using the profile above:

firefox --no-remote -profile profiledir/

5. Look at profiledir/extensions/ for the XPI.
6. Look at the global JS console (Ctrl-Shift-J).

Expected:
5. The XPI should still be there.
6. The global JS console is not interesting.

Actual:
5. The XPI is gone.
6. The global JS console contains the following (in Firefox 66.0.3):

addons.xpi-utils    WARN    updateMetadata: Add-on {5384767E-00D9-40E9-B72F-9CC39D655D6F} is invalid: Error: Incorrect id in install manifest for existing add-on {5384767E-00D9-40E9-B72F-9CC39D655D6F}(resource://gre/modules/addons/XPIDatabase.jsm:2441:15) JS Stack trace: [e-mail]:2441:15
[e-mail]:2608:18
[e-mail]:2680:26
[e-mail]:2570:34
[e-mail]:2148:25
[e-mail]:203:12
[e-mail]:652:5
[e-mail]:805:9
[e-mail]:2775:5
[e-mail]:66:9

Environment:

• ArchLinux
• Firefox 66.0.3
• Tested with tmpfs and ext4

Comment 1

[Andrew Swan [:aswan]]

The stack trace (plus additional information provided offline by Rob) implies that we are scanning for sideloads.
Which should not happen in this case (the app version and build id don't change, and extension.startupScanScopes is 0.

Comment 2

[Rob Wu [:robwu]]

Note: When this bug occurs, only the extension package is removed.
All extension data is still in the profile directory. So, if the add-on is re-installed, the user won't experience dataloss.

While testing I noted that in Firefox 66.0.3 (and probably also in the current beta, but NOT Nightly 68 because of LWT removal, bug 1469930), the ID of https://addons.mozilla.org/en-US/firefox/addon/smiling-happy-birds/ was stored in the following pref:

lightweightThemes.persistedThemeID = "<addon ID here>-<addon version here>"

The pref is set on release at https://searchfox.org/mozilla-release/rev/428b60a515be4ca901d5c64596d5b910c86db415/toolkit/mozapps/extensions/internal/LightweightThemePersister.jsm#54

So if we are going to try to restore add-ons, then at least for themes there seems to be a potentially viable way to determine which theme to use, contrary to the claim in bug 1549022 (at least for release and beta, NOT Nightly 68).

Comment 3

[Rob Wu [:robwu]]

Some people reported that they were not able to reproduce the exact issue.

From QA (vladikoff) in Slack:

I have followed your STR, the 66.0.4 build recovered Google Translate, Last Pass. However, EPUB reader got thrown into “Unsupported” http://v14d.com/i/504a9420d5ebda9ef3794c62f5b7d5ae7ca932dcaeaf26a8a5a99d6380e3fe85.jpg

From the "Testing for add-on signing intermediate certificate dot release" document:

macOS 10.14 - RED (addons were automatically re-enabled after update to 66.0.4-build2 but themes are moved to Unsupported and there is no way to re-enable them. Only Find a Replacement and Remove options are available.).

While the exact manifestation of the bug seems to differ (in my case the add-ons are gone and not visible in the UI, in the case of QA the add-on is marked as Unsupported), it seems that they may have a shared cause (described in this bug).

Comment 4

[David Durst [:ddurst]]

ckarlof was able to reproduce Vlad's result -- as far as getting into the state with epub being unsupported after a restart on 66.0.3. After applying 66.0.4 build 3, the Unsupported extension was restored (and enabled).

Comment 5

[David Durst [:ddurst]]

Assigning to Rob because he can reliably reproduce, and since this is not blocking 66.0.4 build 3's trajectory, it's a mystery we'd like solved because surprises are bad -- but it's not as pressing as 1549061.

Comment 6

[voltron]

As an extension developer with around 50 000 daily users and both popular extensions without ID in the manifest.json this is very disturbing information. Is there something I can do as a developer? For instance submit a new version with the ID in the manifest.json? Should it be the same as the UUID in Technical Details page? With or without curly braces?

Or should I just do nothing and hope that I won't lose vast majority of my users?

Comment 7

[voltron]

We already got several reports from users that Firefox has removed our extension completely. This is totally unacceptable. We are going to lose ALL users at least temporarily (and many probably permanently) and since people are quick to jump into conclusions and there's also incorrect information floating around (as if this had something to do with obfuscated code or something), this is a huge hit to us.

There has to be a way to detect that the extension data is still on the hard drive of the user even if Firefox has removed the extension. Therefore it must be possible to automatically reinstall the extension while keeping the data in-tact without requiring any action from the user. I sincerely hope this recovery mechanism will be built into the fixpack you are working on.

Comment 8

[David Durst [:ddurst]]

(In reply to voltron from comment #7)

We already got several reports from users that Firefox has removed our extension completely. This is totally unacceptable. We are going to lose ALL users at least temporarily (and many probably permanently) and since people are quick to jump into conclusions and there's also incorrect information floating around (as if this had something to do with obfuscated code or something), this is a huge hit to us.

I understand your concern and share it. For what it's worth, no extensions are being removed intentionally (meaning, if an extension has been disabled as part of the larger cert issue, that doesn't result in the XPI being removed as we fix things).

So far, we have no reason to believe this is a widespread bug (one root cause appears to be users changing their system time). Also, when we've been able to reproduce it, we've also been able to verify that it's resolved when the upcoming dot release (66.0.4) is applied. But we're still looking to see if there are other things that could cause it which could be widespread.

Comment 9

[Rob Wu [:robwu]]

The bug happens when:

• The signature of a xpi is invalid (e.g. by bug 1548973 without any fix (hotfix or bug 1549061)).
• The last modified date of the xpi does not match with the one in our database.
• Firefox restarts.

About mismatch last modified date (mtime):

• In my STR, I used faketime (on Linux) to run Firefox in the past without changing the clock of the system. This resulted in an observable difference in mtime values.
• When I change the system-wide clock, the mtime does not change. (tested on Linux and macOS)
• When the xpi (or even the whole profile directory) is modified or copied without preserving timestamps, the bug will be triggered.

---

(In reply to Andrew Swan [:aswan] from comment #1)

The stack trace (plus additional information provided offline by Rob) implies that we are scanning for sideloads.

I checked again, and from the stack trace it is obvious that we are not scanning for sideloads.
The stack trace from comment #0 clearly points to startup as the caller of processFileChanges, not getNewSideloads. Being called from startup is normal, especially with the schema bump.

The reason for not seeing the measure you were asking for is not recorded by default on release builds. When I enable extended recording on release, I do get XPIDB_startup_load_reasons = [directoryState].

When I dig a bit deeper, I see that the xpis are considered changed because the mtime changed. In my test case, I created the first version of the profile with faketime, and the mtime difference matches with what I had set.

When I fix up the timestamps before starting Firefox again with the correct time, then the add-on package is preserved.

---

(In reply to voltron from comment #6)

We already got several reports from users that Firefox has removed our extension completely.

Do you know whether they tried to copy or modify their Firefox profile? Maybe manually or by some other external software?

Is there something I can do as a developer? For instance submit a new version with the ID in the manifest.json?

When this bug happens, the add-on entry has been deleted from the user profile. Your updates won't reach the user in this case.

Or should I just do nothing and hope that I won't lose vast majority of my users?

There is nothing that you can do to work around this bug. You can try to assess the impact by looking at the statistics dashboard of your add-on, at https://addons.mozilla.org/developers/firefox/addon/<your addon sug here>/statistics, and check if the number of daily users drops significantly compared to before. Make sure to look at the graph of multiple weeks, to account for expected deviations (e.g. fewer users in the weekends/holidays compared to weekdays).

Comment 10

[Rob Wu [:robwu]]

Attachment: fixtime.py

This is the script that I used to ensure that the database has the same timestamps as the filesystem. Usage: python3 fixtime.py /path/to/profiledir/

When I fix up the timestamps before starting Firefox again with the correct time, then the add-on package is preserved.

Comment 11

[Rob Wu [:robwu]]

This does not block bug 1548973 any more, because the circumstances are quite specific.

I will keep this bug open in case there are other common ways to trigger this bug.

If there are not, then we can either try to fix immediate cause for the file removal (i.e. updating the code to not delete files if their ID becomes unknown) or just close the bug.

Comment 12

[Rob Wu [:robwu]]

EDIT: Disregard this comment. The issue described below is observed because there are two addon databases, and neglecting to update an add-on's updateTime in extensions.json to match the mtime triggers the code path from comment 0. So comment 9 is still 100% accurate.

This bug does not only happen when mtime is changed. It is also triggered when I use a profile from Firefox 66.0.3 (where the add-on was disabled by the signature bug) in Firefox Beta 67.0b14.

To reproduce, follow the STR, but run fixtime.py after the faketime command to fix up the profile.
And in the second Firefox run, force the signature verification check with XPIDatabase.verifySignatures()
Then finally start the profile with Firefox beta, and the add-on disappears from the profile, with the same stack trace.

XPIDB_startup_load_reasons = [appChanged, directoryState, schemaChanged]

This bug could affect more people than described in comment 9, but it is still not a blocker for a dot release.

Comment 13

[Liz Henry (:lizzard) (relman/hg->git project)]

Locking this bug down to only users who have editbugs permissions, for now.

Comment 14

[David Durst [:ddurst]]

If this code path is also verified as valid, we should close this in favor of a potential recovery that Product can weigh in on.

Comment 15

[Andrew Swan [:aswan]]

(In reply to Rob Wu [:robwu] from comment #9)

The stack trace (plus additional information provided offline by Rob) implies that we are scanning for sideloads.

I checked again, and from the stack trace it is obvious that we are not scanning for sideloads.
The stack trace from comment #0 clearly points to startup as the caller of processFileChanges, not getNewSideloads. Being called from startup is normal, especially with the schema bump.

Right, this isn't getNewSideloads(). I don't have your original log in front of me right now, but I think we were seeing this log message:
https://searchfox.org/mozilla-central/rev/e7d9a8749303b39dadcc0e18ea0d60a570a68145/toolkit/mozapps/extensions/internal/XPIProvider.jsm#1430

which is in code that is intended to be skipped during startup:
https://searchfox.org/mozilla-central/rev/e7d9a8749303b39dadcc0e18ea0d60a570a68145/toolkit/mozapps/extensions/internal/XPIProvider.jsm#1401-1404

Comment 16

[Rob Wu [:robwu]]

Closing for the same reason as bug 1549718.

The cause for the unexpected sideload scan was identified and reported separately in bug 1554703.