Opened 4 months ago

Closed 4 months ago

Last modified 4 months ago

#34365 closed defect (fixed)

10.0a1 mar update failing

Reported by: sysrqb Owned by: tbb-team
Priority: Medium Milestone:
Component: Applications/Tor Browser Version:
Severity: Normal Keywords: tbb-update
Cc: brade, mcs Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

*** AUS:SVC Creating UpdateService
*** AUS:SVC Logging current UpdateService status:
*** AUS:SVC UpdateService.canCheckForUpdates - able to check for updates
*** AUS:SVC getCanApplyUpdates - testing write access /home/user/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
*** AUS:SVC Elevation required: false
*** AUS:SVC Update being handled by other instance: false
*** AUS:SVC Downloading: false
*** AUS:SVC End of UpdateService status
*** AUS:SVC getCanStageUpdates - staging updates is disabled by preference app.update.staging.enabled
*** AUS:SVC UpdateManager:_loadXMLFileIntoArray - XML file does not exist. path: /home/user/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/active-update.xml
*** AUS:SVC getCanStageUpdates - staging updates is disabled by preference app.update.staging.enabled
*** AUS:SVC Checker: checkForUpdates, force: true
*** AUS:SVC Creating UpdateService
*** AUS:SVC Logging current UpdateService status:
*** AUS:SVC UpdateService.canCheckForUpdates - able to check for updates
*** AUS:SVC getCanApplyUpdates - testing write access /home/user/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
*** AUS:SVC Elevation required: false
*** AUS:SVC Update being handled by other instance: false
*** AUS:SVC Downloading: false
*** AUS:SVC End of UpdateService status
*** AUS:SVC UpdateService.canCheckForUpdates - able to check for updates
*** AUS:SVC Checker:getUpdateURL - update URL: https://aus1.torproject.org/torbrowser/update_3/alpha/Linux_x86_64-gcc3/9.5a13/en-US?force=1
*** AUS:SVC Checker:checkForUpdates - sending request to: https://aus1.torproject.org/torbrowser/update_3/alpha/Linux_x86_64-gcc3/9.5a13/en-US?force=1

*** AUS:SVC Checker:onLoad - request completed downloading document
*** AUS:SVC Checker:onLoad - Getting sslStatus failed.
*** AUS:SVC Checker:onLoad - number of updates available: 1
*** AUS:SVC getCanApplyUpdates - testing write access /home/user/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/update.test
*** AUS:SVC getCanApplyUpdates - able to apply updates
*** AUS:SVC Creating Downloader
*** AUS:SVC UpdateService:_downloadUpdate
*** AUS:SVC readStringFromFile - file doesn't exist: /home/user/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/updates/0/update.status
*** AUS:SVC readStatusFile - status: null, path: /home/user/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/updates/0/update.status
*** AUS:SVC getCanUseBits - Not using BITS because this is not Windows
*** AUS:SVC Downloader:downloadUpdate - Starting nsIIncrementalDownload with url: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar, path: /home/user/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/updates/0/update.mar, interval: 0


*** AUS:SVC Downloader:onStartRequest - original URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar, final URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar
*** AUS:SVC Downloader:onStopRequest - downloader: nsIIncrementalDownload, original URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar, final URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar, status: 2147549183
*** AUS:SVC Downloader:onStopRequest - status: 2147549183, current fail: 0, max fail: 10, retryTimeout: 2000
*** AUS:SVC Downloader:onStopRequest - non-verification failure
*** AUS:SVC getStatusTextFromCode - transfer error: Failed (unknown reason), default code: 2152398849
*** AUS:SVC Downloader:onStopRequest - setting state to: download-failed
*** AUS:SVC Downloader:onStopRequest - verification of patch failed, downloading complete update patch
*** AUS:SVC UpdateService:_downloadUpdate
*** AUS:SVC readStringFromFile - file doesn't exist: /home/user/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/updates/0/update.status
*** AUS:SVC readStatusFile - status: null, path: /home/user/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/updates/0/update.status
*** AUS:SVC Downloader:_selectPatch - found existing patch with state: null
*** AUS:SVC getCanUseBits - Not using BITS because this is not Windows
*** AUS:SVC Downloader:downloadUpdate - Starting nsIIncrementalDownload with url: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-10.0a1_en-US.mar, path: /home/user/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/updates/0/update.mar, interval: 0

*** AUS:SVC Downloader:onStartRequest - original URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-10.0a1_en-US.mar, final URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-10.0a1_en-US.mar
*** AUS:SVC Downloader:onStopRequest - downloader: nsIIncrementalDownload, original URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-10.0a1_en-US.mar, final URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-10.0a1_en-US.mar, status: 2147549183
*** AUS:SVC Downloader:onStopRequest - status: 2147549183, current fail: 0, max fail: 10, retryTimeout: 2000
*** AUS:SVC Downloader:onStopRequest - non-verification failure
*** AUS:SVC getStatusTextFromCode - transfer error: Failed (unknown reason), default code: 2152398849
*** AUS:SVC Downloader:onStopRequest - setting state to: download-failed
*** AUS:SVC Downloader:onStopRequest - notifying observers of error. topic: update-error, status: download-attempt-failed
*** AUS:SVC UpdateManager:_writeUpdatesToXMLFile - no updates to write. removing file: /home/user/tor-browser_en-US/Browser/TorBrowser/UpdateInfo/active-update.xml

Child Tickets

Change History (6)

comment:1 Changed 4 months ago by sysrqb

Status 2147549183 is NS_ERROR_UNEXPECTED. That appears in two places in UpdateService.jsm, but I don't see the associated Downloader:onProgress log entries.

I'm not sure if this is related to #34315.

comment:2 Changed 4 months ago by sysrqb

Summary: 10.0a1 incremental mar update failing10.0a1 mar update failing

comment:3 in reply to:  1 Changed 4 months ago by gk

Keywords: tbb-update added
Status: newneeds_information

Replying to sysrqb:

Status 2147549183 is NS_ERROR_UNEXPECTED. That appears in two places in UpdateService.jsm, but I don't see the associated Downloader:onProgress log entries.

I don't see this. Testing from a clean 9.5a13 this (i.e. incremental updates) works fine for me.

I'm not sure if this is related to #34315.

I don't think this can be the case for the error you gave:

*** AUS:SVC Downloader:onStartRequest - original URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar, final URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar
*** AUS:SVC Downloader:onStopRequest - downloader: nsIIncrementalDownload, original URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar, final URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar, status: 2147549183
*** AUS:SVC Downloader:onStopRequest - status: 2147549183, current fail: 0, max fail: 10, retryTimeout: 2000
*** AUS:SVC Downloader:onStopRequest - non-verification failure
*** AUS:SVC getStatusTextFromCode - transfer error: Failed (unknown reason), default code: 2152398849

This says that the download of the mar file failed. For whatever reason. I see no way where our patch/backout for #34315 can kick in here. The likely explanation is some network error along the way from your computer to the server hosting the .mar files.

Assuming that it is your computer. Just the error message in the description is providing not much context.

comment:4 Changed 4 months ago by gk

FWIW: This might have been caused by our servers not being in sync. Even, though, as the log shows we call cdn.torproject.org directly we only get the .mar files from the cdn if our servers know about them.

comment:5 in reply to:  4 Changed 4 months ago by sysrqb

Resolution: fixed
Status: needs_informationclosed

Replying to gk:

FWIW: This might have been caused by our servers not being in sync. Even, though, as the log shows we call cdn.torproject.org directly we only get the .mar files from the cdn if our servers know about them.

Yeah. It's still a mystery, but this seems the most likely answer right now.

In any case, I'm successfully getting the update now.

*** AUS:SVC Checker:onLoad - request completed downloading document
*** AUS:SVC Checker:onLoad - Getting sslStatus failed.
*** AUS:SVC Checker:onLoad - number of updates available: 1
*** AUS:SVC getCanApplyUpdates - testing write access /home/sysrqb/tor-browser_en-US_alpha2_work/Browser/TorBrowser/UpdateInfo/update.test
*** AUS:SVC getCanApplyUpdates - able to apply updates
*** AUS:SVC Creating Downloader
*** AUS:SVC UpdateService:_downloadUpdate
*** AUS:SVC readStringFromFile - file doesn't exist: /home/sysrqb/tor-browser_en-US_alpha2_work/Browser/TorBrowser/UpdateInfo/updates/0/update.status
*** AUS:SVC readStatusFile - status: null, path: /home/sysrqb/tor-browser_en-US_alpha2_work/Browser/TorBrowser/UpdateInfo/updates/0/update.status
*** AUS:SVC getCanUseBits - Not using BITS because this is not Windows
*** AUS:SVC Downloader:downloadUpdate - Starting nsIIncrementalDownload with url: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar, path: /home/sysrqb/tor-browser_en-US_alpha2_work/Browser/TorBrowser/UpdateInfo/updates/0/update.mar, interval: 0
*** AUS:SVC Downloader:onStartRequest - original URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar, final URI spec: https://cdn-fastly.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar
*** AUS:SVC Downloader:onProgress - progress: 512/4930574
*** AUS:SVC Downloader:onProgress - progress: 5484/4930574
*** AUS:SVC Downloader:onProgress - progress: 9597/4930574
*** AUS:SVC Downloader:onProgress - progress: 16452/4930574
[snip]
*** AUS:SVC Downloader:onProgress - progress: 4765386/4930574
*** AUS:SVC Downloader:onProgress - progress: 4896458/4930574
*** AUS:SVC Downloader:onProgress - progress: 4930574/4930574
*** AUS:SVC Downloader:onProgress - progress: 4930574/4930574
*** AUS:SVC Downloader:onStopRequest - downloader: nsIIncrementalDownload, original URI spec: https://cdn.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar, final URI spec: https://cdn-fastly.torproject.org/aus1/torbrowser/10.0a1/tor-browser-linux64-9.5a13-10.0a1_en-US.incremental.mar, status: 0
*** AUS:SVC Downloader:onStopRequest - status: 0, current fail: 0, max fail: 10, retryTimeout: 2000
*** AUS:SVC Downloader:_verifyDownload called
*** AUS:SVC Downloader:_verifyDownload downloaded size == expected size.
*** AUS:SVC Downloader:_verifyDownload hashes match.
*** AUS:SVC shouldUseService - returning false
*** AUS:SVC getCanStageUpdates - staging updates is disabled by preference app.update.staging.enabled
*** AUS:SVC Downloader:onStopRequest - setting state to: pending
*** AUS:SVC getCanStageUpdates - staging updates is disabled by preference app.update.staging.enabled
*** AUS:SVC getCanStageUpdates - staging updates is disabled by preference app.update.staging.enabled
*** AUS:SVC showUpdateDownloaded - Notifying observers that an update was downloaded. topic: update-downloaded, status: pending

comment:6 Changed 4 months ago by mcs

For what its worth, Matt's log shows that both the incremental and full MAR downloads failed with the same error: 2147549183, which is 0x8000FFFF, which is NS_ERROR_UNEXPECTED. It is difficult to determine the root cause given such a general error, but there are several places inside:

https://searchfox.org/mozilla-esr68/source/netwerk/base/nsIncrementalDownload.cpp

where NS_ERROR_UNEXPECTED is returned due to unusual server responses. I don't know a lot about how fastly works but gk's comment:4 seems like a good guess. I wonder if there is a way to delay making the update manifest available until after all of the MAR files are in the right place and available via the CDN....

Note: See TracTickets for help on using tickets.