Opened 4 weeks ago

Closed 3 weeks ago

#27221 closed defect (fixed)

Tor Browser 8.0a10 wants to update to 8.0a10

Reported by: boklm Owned by: tbb-team
Priority: Very High Milestone:
Component: Applications/Tor Browser Version:
Severity: Normal Keywords: ff60-esr, TorBrowserTeam201808R
Cc: mcs, brade, sysrqb, arthuredelstein, pospeselr Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

After updating my 8.0a9 browser to 8.0a10, on Linux, the browser still thinks that an update is available and will download and update again to 8.0a10.

After setting app.update.log to true, I can see this in the logs:

UTM:SVC TimerManager:registerTimer - id: xpi-signature-verification
[08-20 19:38:02] TorLauncher INFO: debug output ready
[08-20 19:38:02] TorLauncher INFO: SOCKS port type: TCP
[08-20 19:38:02] TorLauncher INFO: SOCKS host: 127.0.0.1
[08-20 19:38:02] TorLauncher INFO: SOCKS port: 9250
1534793884386	addons.webextension.https-everywhere-eff@eff.org	WARN	Please specify whether you want browser_style or not in your browser_action options.
1534793884387	addons.webextension.{73a6fe31-595d-460b-a920-fcc0f8843232}	WARN	Please specify whether you want browser_style or not in your browser_action options.
Tor NOTICE: Bootstrapped 85%: Finishing handshake with first hop 
Tor NOTICE: Bootstrapped 90%: Establishing a Tor circuit 
Tor NOTICE: Tor has successfully opened a circuit. Looks like client functionality is working. 
Tor NOTICE: Bootstrapped 100%: Done 
AUS:SVC Creating UpdateService
AUS:SVC readStatusFile - status: downloading, path: /home/user/tor-alpha/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/updates/0/update.status
[08-20 19:38:07] Torbutton NOTE: Initializing security-prefs.js
[08-20 19:38:07] Torbutton NOTE: security-prefs.js initialization complete
Tor NOTICE: New control connection opened from 127.0.0.1. AUS:SVC getCanApplyUpdates - testing write access /home/user/tor-alpha/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/update.test
AUS:SVC getCanApplyUpdates - able to apply updates
AUS:SVC getCanStageUpdates - staging updates is disabled by preference app.update.staging.enabled
UTM:SVC TimerManager:registerTimer - id: browser-cleanup-thumbnails
AUS:SVC gCanCheckForUpdates - able to check for updates
AUS:SVC getCanApplyUpdates - testing write access /home/user/tor-alpha/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/update.test
AUS:SVC getCanApplyUpdates - able to apply updates
AUS:SVC readStatusFile - status: downloading, path: /home/user/tor-alpha/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/updates/0/update.statusAUS:SVC UpdateService:_postUpdateProcessing - removing update for older application version or same application version with same build ID. update application version: 8.0a10, application version: 60.1.0, update build ID: 20180204020101, application build ID: 20180204020101
AUS:SVC Checker:getUpdateURL - update URL: https://aus1.torproject.org/torbrowser/update_3/alpha/Linux_x86_64-gcc3/8.0a9/en-US
AUS:SVC Checker: checkForUpdates, force: false
AUS:SVC Checker:getUpdateURL - update URL: https://aus1.torproject.org/torbrowser/update_3/alpha/Linux_x86_64-gcc3/8.0a9/en-US
AUS:SVC Checker:checkForUpdates - sending request to: https://aus1.torproject.org/torbrowser/update_3/alpha/Linux_x86_64-gcc3/8.0a9/en-US
[08-20 19:38:08] Torbutton WARN: no SOCKS credentials found for current document.
AUS:SVC UpdateManager:_writeUpdatesToXMLFile - no updates to write. removing file: /home/user/tor-alpha/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/active-update.xml
AUS:SVC Checker:onLoad - request completed downloading document
AUS:SVC Checker:onLoad - number of updates available: 1
AUS:SVC getCanApplyUpdates - testing write access /home/user/tor-alpha/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/update.test
AUS:SVC getCanApplyUpdates - able to apply updates
AUS:SVC UpdateService:_selectAndInstallUpdate - download the update
AUS:SVC Creating Downloader
AUS:SVC UpdateService:_downloadUpdate
AUS:SVC readStringFromFile - file doesn't exist: /home/user/tor-alpha/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/updates/0/update.status
AUS:SVC readStatusFile - status: null, path: /home/user/tor-alpha/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/updates/0/update.status
AUS:SVC Downloader:downloadUpdate - url: https://cdn.torproject.org/aus1/torbrowser/8.0a10/tor-browser-linux64-8.0a9-8.0a10_en-US.incremental.mar, path: /home/user/tor-alpha/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/updates/0/update.mar, interval: null
AUS:SVC Downloader:onStartRequest - original URI spec: https://cdn.torproject.org/aus1/torbrowser/8.0a10/tor-browser-linux64-8.0a9-8.0a10_en-US.incremental.mar, final URI spec: https://cdn-fastly.torproject.org/aus1/torbrowser/8.0a10/tor-browser-linux64-8.0a9-8.0a10_en-US.incremental.mar
AUS:SVC Downloader:onProgress - progress: 512/6568735
AUS:SVC Downloader:onProgress - progress: 27420/6568735
AUS:SVC Downloader:onProgress - progress: 81920/6568735

According to this line, it seems the browser still thinks it is version 8.0a9:

AUS:SVC Checker:getUpdateURL - update URL: https://aus1.torproject.org/torbrowser/update_3/alpha/Linux_x86_64-gcc3/8.0a9/en-US

However, the about:tor page correctly shows 8.0a10.

Child Tickets

Change History (28)

comment:1 Changed 4 weeks ago by boklm

I can't reproduce the issue with a new 8.0a10 install, so it seems to be an issue specific to my 8.0a9 -> 8.0a10 update.

comment:2 in reply to:  1 Changed 4 weeks ago by boklm

Replying to boklm:

I can't reproduce the issue with a new 8.0a10 install, so it seems to be an issue specific to my 8.0a9 -> 8.0a10 update.

I also cannot reproduce this issue when doing a new 8.0a9 install and updating it to 8.0a10.

comment:3 Changed 4 weeks ago by boklm

And I also cannot reproduce the issue when doing a new 8.0a8 install, updating it to 8.0a9 and then 8.0a10.

comment:4 Changed 4 weeks ago by gk

Cc: mcs brade added
Priority: MediumHigh

FWIW: I think I saw a similar behavior on my Linux box, too.

comment:5 Changed 4 weeks ago by gk

Keywords: TorBrowserTeam201808 added

comment:6 Changed 4 weeks ago by boklm

On the browser showing this issue, I also noticed that after the 8.0a9 -> 8.0a10 update, the changelog tab was missing (and is also missing in the following 8.0a10 -> 8.0a10 updates). However, in the browser that does not have this issue, the changelog tab is present after the 8.0a9 -> 8.0a10 update.

comment:7 Changed 4 weeks ago by gk

Cc: sysrqb added

#27232 is a duplicate. sysrqb noted in it:

`browser.startup.homepage_override.torbrowser.version` and `extensions.lastTorBrowserVersion` are both `8.0a9`

while

`extensions.torbutton.lastBrowserVersion` and `torbrowser.version` are `8.0a10`.

On my TB 7.5 installation, I see all four of these are currently `7.5.6`.

comment:8 Changed 4 weeks ago by gk

Keywords: ff60-esr added
Priority: HighVery High

Happens on Windows, too.

comment:9 in reply to:  7 Changed 4 weeks ago by boklm

Replying to gk:

browser.startup.homepage_override.torbrowser.version and extensions.lastTorBrowserVersion are both 8.0a9

Also for me. They are defined to 8.0a9 in profile.default/prefs.js.

If I remove those prefs from prefs.js, the browser doesn't try to update anymore (and the logs show that 8.0a10 is used in the update URL).

comment:10 Changed 4 weeks ago by gk

Okay, some more info: I can reproduce the bug with a clean 8.0a9 if I start it once and then shut it down again as soon as a window is visible, making sure the update gets applied on a used profile.

However, the update succeeds in this case if I move the Tor Browser dir before updating (i.e. before the second start), which is kind of weird, but hey!

comment:11 in reply to:  10 Changed 4 weeks ago by boklm

Replying to gk:

Okay, some more info: I can reproduce the bug with a clean 8.0a9 if I start it once and then shut it down again as soon as a window is visible, making sure the update gets applied on a used profile.

I can reproduce it this way too.

However, the update succeeds in this case if I move the Tor Browser dir before updating (i.e. before the second start), which is kind of weird, but hey!

Ah, I also noticed that if I move the Tor Browser directory to a different path (even after updating), it solves the issue.

comment:12 in reply to:  10 Changed 4 weeks ago by boklm

Replying to gk:

Okay, some more info: I can reproduce the bug with a clean 8.0a9 if I start it once and then shut it down again as soon as a window is visible, making sure the update gets applied on a used profile.

If I follow the same steps, but instead of clicking on the Restart to update Tor Browser button I manually close the browser, remove the Browser/TorBrowser/Data/Browser/profile.default/startupCache/ directory, and restart the browser, then the browser is updated correctly and doesn't want to update again. So the issue might be related to this startupCache directory.

comment:13 Changed 4 weeks ago by mcs

For the record, this is easy to reproduce on macOS as well; simply follow the hint given in comment:10 (startup 8.0a9, shutdown, start again and apply the update).

And it does seem to be a startupCache problem. Specifically, the problem disappears if I remove the file TorBrowser-Data/Browser/Caches/*.default/startupCache/scriptCache.bin.

In fact, the wrong JS code is being executed. E.g., an update URL that contains 8.0a9 is generated and used even though toolkit/modules/UpdateUtils.jsm has a hard-coded (build- time) value of 8.0a10.

Kathy and I looked at the code and cannot determine where or how the script cache is invalidated. We did not find any evidence that individual entries (for individual files such as UpdateUtils.jsm) are invalidated; it looks like the entire cache is invalidated via ScriptPreloader::InvalidateCache() (see js/xpconnect/loader/ScriptPreloader.cpp).

As far as we can tell, that InvalidateCache() method is only called in response to a startupcache-invalidate observer notification. But we don't see a place where that is generated after an update or if one were to install new bits over the top of an existing browser.

comment:14 in reply to:  13 ; Changed 4 weeks ago by boklm

Replying to mcs:

As far as we can tell, that InvalidateCache() method is only called in response to a startupcache-invalidate observer notification. But we don't see a place where that is generated after an update or if one were to install new bits over the top of an existing browser.

In startup() in toolkit/mozapps/extensions/internal/XPIProvider.jsm, it seems that a startupcache-invalidate notification is sent if flushCaches is true:

     let flushCaches = this.checkForChanges(aAppChanged, aOldAppVersion,
                                             aOldPlatformVersion);

And it seems that it is looking at the AppVersion and PlatformVersion to decide that.

I see that the prefs extensions.lastAppVersion and extensions.lastPlatformVersion are both set to 60.1.0, which didn't change between 8.0a9 and 8.0a10.

comment:15 Changed 4 weeks ago by gk

Hm, so that code does not seem to have changed much since esr52 but I am pretty sure we had releases bumping just the Tor Browser version without according Firefox version bumps (the chemspills come to mind). Yet, we did not run into this issue...

comment:16 in reply to:  14 Changed 4 weeks ago by mcs

Replying to boklm:

In startup() in toolkit/mozapps/extensions/internal/XPIProvider.jsm, it seems that a startupcache-invalidate notification is sent if flushCaches is true:

     let flushCaches = this.checkForChanges(aAppChanged, aOldAppVersion,
                                             aOldPlatformVersion);

And it seems that it is looking at the AppVersion and PlatformVersion to decide that.

I see that the prefs extensions.lastAppVersion and extensions.lastPlatformVersion are both set to 60.1.0, which didn't change between 8.0a9 and 8.0a10.

Replying to boklm:

In startup() in toolkit/mozapps/extensions/internal/XPIProvider.jsm, it seems that a startupcache-invalidate notification is sent if flushCaches is true:

     let flushCaches = this.checkForChanges(aAppChanged, aOldAppVersion,
                                             aOldPlatformVersion);

And it seems that it is looking at the AppVersion and PlatformVersion to decide that.

I see that the prefs extensions.lastAppVersion and extensions.lastPlatformVersion are both set to 60.1.0, which didn't change between 8.0a9 and 8.0a10.

Thanks for tracking that down! A few things are starting to come back to Kathy and me. Inside the startup() function within XPIProvider.jsm, aAppChanged should be true because we added code to toolkit/mozapps/extensions/AddonManager.jsm that checks the Tor Browser version against the extensions.lastTorBrowserVersion pref:

#ifdef TOR_BROWSER_VERSION
      // To ensure that extension override prefs are reinstalled into the
      // user's profile after each update, set appChanged = true if the
      // Mozilla app version has not changed but the Tor Browser version
      // has changed.
      let tbChanged = undefined;
      try {
        tbChanged = TOR_BROWSER_VERSION !=
                   Services.prefs.getCharPref(PREF_EM_LAST_TORBROWSER_VERSION);
      }
      catch (e) { }
      if (tbChanged !== false) {
        // Because PREF_EM_LAST_TORBROWSER_VERSION was not present in older
        // versions of Tor Browser, an app change is indicated when tbChanged
        // is undefined or true.
        if (appChanged === false) {
          appChanged = true;
        }

        Services.prefs.setCharPref(PREF_EM_LAST_TORBROWSER_VERSION,
                                   TOR_BROWSER_VERSION);
      }
#endif

Alas, due to the script cache the old 8.0a9 AddonManager.jsm code is still running after the update to 8.0a10. I am going to try sending email to Kris Maglione from Mozilla to see if there is some other trick that causes the script cache to be invalidated. But I believe that Firefox won't encounter this problem because they are testing against the app version valued returned by Services.appinfo.version which is implemented in C++ (therefore the JS script cache won't interfere).

comment:17 in reply to:  15 Changed 4 weeks ago by mcs

Replying to gk:

Hm, so that code does not seem to have changed much since esr52 but I am pretty sure we had releases bumping just the Tor Browser version without according Firefox version bumps (the chemspills come to mind). Yet, we did not run into this issue...

Agreed. I think the difference is due to the script cache (which as far as I can tell is new in ESR60, having first shipped in Firefox 55).

comment:18 Changed 4 weeks ago by gk

https://hg.mozilla.org/mozilla-central/rev/b658ca8e2aed has the comment:

Flushing the cache at startup is already handled automatically by the AppStartup code, which removes the entire startupCache directory when necessary.

comment:19 Changed 4 weeks ago by gk

Oh, and that commit made me think that we could capture a relevant "update-applicable" notification (assuming the updater related code is emitting something usable before/during the green icon is shown on the hamburger menu), set a flag and flush the startup cache in Torbutton during shutdown in case that flag is set.

Just to have "we-don't-have-a-better-solution"-solution...

Last edited 4 weeks ago by gk (previous) (diff)

comment:20 in reply to:  19 Changed 4 weeks ago by gk

Replying to gk:

Oh, and that commit made me think that we could capture a relevant "update-applicable" notification (assuming the updater related code is emitting something usable before/during the green icon is shown on the hamburger menu), set a flag and flush the startup cache in Torbutton during shutdown in case that flag is set.

Just to have "we-don't-have-a-better-solution"-solution...

Oh, and we'd need to make sure that the startup cache does not get written (again) during session shutdown after we issue the flush notification via Torbutton.

Last edited 4 weeks ago by gk (previous) (diff)

comment:21 Changed 4 weeks ago by mcs

Keywords: TorBrowserTeam201808R added; TorBrowserTeam201808 removed
Status: newneeds_review

Here is a fix:
https://gitweb.torproject.org/user/brade/tor-browser.git/commit/?h=bug27221-01&id=d97dc2bdddf642bf192962b40afaf6d220c9fc2d

Kathy and I did some testing on macOS; it would be great if someone could do some independent testing. One simple test is to replace the binary bits of a 8.0a10 install that is in a bad state due to this bug and then restart. The startupCache should be removed and life should be good again.

comment:22 in reply to:  21 Changed 4 weeks ago by boklm

Replying to mcs:

Here is a fix:
https://gitweb.torproject.org/user/brade/tor-browser.git/commit/?h=bug27221-01&id=d97dc2bdddf642bf192962b40afaf6d220c9fc2d

Kathy and I did some testing on macOS; it would be great if someone could do some independent testing. One simple test is to replace the binary bits of a 8.0a10 install that is in a bad state due to this bug and then restart. The startupCache should be removed and life should be good again.

I did some testing on Linux. I made a build of 8.0a10 + this patch. After comparing this build with 8.0a10, the only file that is different is Browser/libxul.so.

When I copy the new Browser/libxul.so file to a browser affected by the issue, then it solves the issue. So it looks like the fix is working.

comment:24 Changed 4 weeks ago by boklm

I also see that LastTorBrowserVersion=8.0a10 is correctly getting added to the file Browser/TorBrowser/Data/Browser/profile.default/compatibility.ini.

While looking at this I noticed that the build id is included in the LastVersion line:

LastVersion=60.1.0_20180204020101/20180204020101

Currently we generate a build id based on the firefox version number (using the script projects/firefox/get-moz-build-date), so it does not change when we don't change the firefox version. An other option could be to generate it based on the Tor Browser version number, so that it is changing even when the firefox version is not.

comment:25 in reply to:  24 Changed 4 weeks ago by gk

Replying to boklm:

While looking at this I noticed that the build id is included in the LastVersion line:

LastVersion=60.1.0_20180204020101/20180204020101

Currently we generate a build id based on the firefox version number (using the script projects/firefox/get-moz-build-date), so it does not change when we don't change the firefox version. An other option could be to generate it based on the Tor Browser version number, so that it is changing even when the firefox version is not.

That's an interesting idea. However, I remember getting that right was not trivial and I feel there is no need to introduce new side effects so close to the release. I think the patch is not big and well understood and does its job (nice work mcs/brade!) which sounds like the ideal candidate for 8.0.

comment:26 in reply to:  21 Changed 4 weeks ago by gk

Cc: arthuredelstein pospeselr added

Replying to mcs:

Here is a fix:
https://gitweb.torproject.org/user/brade/tor-browser.git/commit/?h=bug27221-01&id=d97dc2bdddf642bf192962b40afaf6d220c9fc2d

Kathy and I did some testing on macOS; it would be great if someone could do some independent testing. One simple test is to replace the binary bits of a 8.0a10 install that is in a bad state due to this bug and then restart. The startupCache should be removed and life should be good again.

Works here and the patch looks good to me. Adding some folks for a second pair of eyes...

comment:27 Changed 3 weeks ago by pospeselr

Patch looks good to me!

comment:28 Changed 3 weeks ago by gk

Resolution: fixed
Status: needs_reviewclosed

Thanks. Cherry-picked for tor-browser-60.1.0esr-8.0-1 (commit 7b269d1c44ba383444a1bfed3acb67ab3cac5071).

Note: See TracTickets for help on using tickets.