841631 - [Intermittent] Large Packaged App Downloads on Weak Connections can have HTTP requests stopped in the middle of download, which results in a corrupted package download

Status: RESOLVED FIXED

(Core Graveyard :: DOM: Apps, defect)

Description

[Jason Smith [:jsmith]]

he problem that I could reproduce (only for packaged apps so far) is not related with insufficient storage in the device but with large downloads with a not so good connection (I could only reproduce it while tethering from other device). The issue that I am seeing (not easy to reproduce) is that, for some reason that I still don't know, we are stopping the HTTP request in the middle of the download. Note the "onStopRequest 0" from this log:

I/Gecko   (  109): -*-*- Webapps.jsm : onProgress: 3312057/98948661
I/Gecko   (  109): -*-*- Webapps.jsm : Saving /data/local/webapps/webapps.json
I/Gecko   (  109): -*-*- FreeSpaceWatcher.jsm : Free bytes: 18366464
I/Gecko   (  109): -*-*- Webapps.jsm : onProgress: 3405957/98948661
I/Gecko   (  109): -*-*- Webapps.jsm : Saving /data/local/webapps/webapps.json
I/Gecko   (  109): -*-*- FreeSpaceWatcher.jsm : Free bytes: 18280448
I/Gecko   (  109): -*-*- Webapps.jsm : onProgress: 3524529/98948661
I/Gecko   (  109): -*-*- Webapps.jsm : Saving /data/local/webapps/webapps.json
I/Gecko   (  109): -*-*- FreeSpaceWatcher.jsm : Free bytes: 18145280
I/Gecko   (  109): -*-*- Webapps.jsm : onStopRequest 0
I/Gecko   (  109): -*-*- FreeSpaceWatcher.jsm : Free bytes: 18083840
I/Gecko   (  109): -*-*- Webapps.jsm : packageHash=a893832e589c17072eb1a8a96ebf0b9c
I/Gecko   (  109): -*-*- Webapps.jsm : aRv 2152857611
I/Gecko   (  109): -*-*- Webapps.jsm : Cleanup: INVALID_SIGNATURE
I/Gecko   (  109): -*-*- AppDownloadManager.jsm : Getting http://apptester.eu01.aws.af.cm/apps/bigPackagedApp/manifest.webapp
I/Gecko   (  109): -*-*- Webapps.jsm : Saving /data/local/webapps/webapps.json
I/Gecko   (  109): -*-*- AppDownloadManager.jsm : Removing http://apptester.eu01.aws.af.cm/apps/bigPackagedApp/manifest.webapp
I/Gecko   (  109): -*-*- AppDownloadManager.jsm : Removing http://apptester.eu01.aws.af.cm/apps/bigPackagedApp/manifest.webapp

As you can see, the file is not fully downloaded when we receive the notification of the stopped request, which makes the signature validation fail and leave the app with the following state:

  "{65e8a42f-9c2f-4738-945e-ccbfc065a520}": {
    "name": "Big Packaged App",
    "csp": "",
    "installOrigin": "http://apptester.eu01.aws.af.cm",
    "origin": "app://{65e8a42f-9c2f-4738-945e-ccbfc065a520}",
    "receipts": [],
    "installTime": 1360746449611,
    "manifestURL": "http://apptester.eu01.aws.af.cm/apps/bigPackagedApp/manifest.webapp",
    "appStatus": 1,
    "removable": true,
    "id": "{65e8a42f-9c2f-4738-945e-ccbfc065a520}",
    "localId": 1025,
    "basePath": "/data/local/webapps",
    "progress": 3625413,
    "installState": "pending",
    "downloadAvailable": false,
    "downloading": false,
    "readyToApplyDownload": false,
    "downloadSize": 0,
    "lastUpdateCheck": 1360746449612,
    "etag": "4fa85a90282b927fcc428c943127bfca",
    "manifestHash": "ccf0c88b9451c9b701a87b23afbe0590",
    "installerAppId": 1002,
    "installerIsBrowser": true,
    "retryingDownload": true
  }

IMO the app state is correct. We should not be setting 'downloadAvailable' to true here if the file is corrupted (we need to notify about this, not about an invalid signature though). The current app state will make the download fail as soon as the user clicks in the icon again. Uninstalling the app would allow its download again.

I only added a check for the NS_ERROR_FILE_CORRUPTED (Note the "aRv 2152857611" log above. http://james-ross.co.uk/mozilla/misc/nserror?0x8052000B) to throw the appropriate error, but that does not solve the issue. I am gonna need some help here to check why the download is being cut in the middle of the process and reported as a success. Not sure if Jason or Honza are familiar with this HTTP request code. (We are getting the unexpected stopped request notification at https://mxr.mozilla.org/mozilla-central/source/dom/apps/src/Webapps.jsm#2152).

Comment 1

[Jason Duell]

You must of course always be prepared for a server connection to drop off before completing (this is the Internet after all :).  And by design apparently (I was just talking to :mayhemer about this today), it's intentional that necko returns NS_OK if the TCP connection closes politely, even if the bytes downloaded != the length specified in the Content-Length header (if one was provided).  It's the client code's job to check that if it's relevant. So unless I hear otherwise I don't think there's necko changes needed here (well, there might be a separate bug if we're doing something that causes the network cutout, but that's a separate issue).

I'm no app guru, but it still seems odd to me to give up on downloading an app after one try and mark downloadAvailable=false.  Seems better to try to allow user to update again (if update), or fail install and let them try it again if they want. Unless you have some better metric for determining if bytes are actually corrupt (checksum, etc) versus just not completely downloaded.  This bug was just for installs, IIRC?

Comment 2

[Fernando Jiménez Moreno [:ferjm]]

Attachment: Add APP_PACKAGE_CORRUPTED error

Comment 3

[Fernando Jiménez Moreno [:ferjm]]

(In reply to Jason Duell (:jduell) from comment #1)
> You must of course always be prepared for a server connection to drop off
> before completing (this is the Internet after all :).  And by design
> apparently (I was just talking to :mayhemer about this today), it's
> intentional that necko returns NS_OK if the TCP connection closes politely,
> even if the bytes downloaded != the length specified in the Content-Length
> header (if one was provided).  It's the client code's job to check that if
> it's relevant. So unless I hear otherwise I don't think there's necko
> changes needed here (well, there might be a separate bug if we're doing
> something that causes the network cutout, but that's a separate issue).
> 

It feels odd to me returning NS_OK in the case that we get less bytes than the ones specified in the Content-Length. Anyway, if that's client code's job we better add that check in the web apps implementation.

> I'm no app guru, but it still seems odd to me to give up on downloading an
> app after one try and mark downloadAvailable=false.

Yes, it might not sound "fair" enough, but as I already mentioned before in the other bug, knowing that the download returned NS_OK and the file is corrupted is a combination of a suspicious unrecoverable error.

> Seems better to try to
> allow user to update again (if update), or fail install and let them try it
> again if they want.Unless you have some better metric for determining if
> bytes are actually corrupt (checksum, etc) versus just not completely
> downloaded.  This bug was just for installs, IIRC?

The code is shared by the app installation and update use cases.

The issue here with setting the downloadAvailable to true is not with retying an installation but with repeatedly being notified about an update. Gaia notifies about an update based on the downloadAvailable flag and the onDownloadAvailable event.

We could probably set the downloadAvailable to true in case that the app is not fully installed (installState = pending). Not sure if Gaia checks the installState flag, but it probably should. The user would be able to restart the download by clicking the icon again without been constantly notified about updates in that case.

For the update case, we could set the downloadAvailable to true, but we might need to expose a method to silence the update notification somehow or add a retry count to automatically setting it to false. Not sure if we are too late for the first option for v1 though, so the retry count sounds like an easier solution.

How does it sound?

Thanks!

Comment 4

[Fernando Jiménez Moreno [:ferjm]]

Attachment: Log

I've noticed that the download being cut happens after a period on inactivity. Note the attached log and the consecutive messages from "FreeStorageWatcher". The download continues after some time but it then stops triggering the APP_PACKAGE_CORRUPTED error.

Comment 5

[Jason Duell]

> It feels odd to me returning NS_OK in the case that we get less bytes than the
> ones specified in the Content-Length.

Apparently it's not uncommon for sites to give the wrong info about content-length of some resources and we'd break displaying their images, etc if we failed the load.  So I'm told at least.

> knowing that the download returned NS_OK and the file is corrupted is a 
> combination of a suspicious unrecoverable error.

FWIW the network dropping in the middle of a load is neither all that suspicious nor unrecoverable.

> The issue here with setting the downloadAvailable to true is not with 
> retying an installation but with repeatedly being notified about an update.

Ah, that could be a problem, then. I'm not going to pretend I know the answer to that issue :)

Comment 6

[Fernando Jiménez Moreno [:ferjm]]

Attachment: v1

This patch throws the appropriate APP_PACKAGE_CORRUPTED error and allows the user to retry to install the app by clicking in the app icon again. In case of update failures the user would need to wait for the next checkForUpdates.

Comment 7

[Fernando Jiménez Moreno [:ferjm]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/dc90a0618dd2

Comment 8

[Fernando Jiménez Moreno [:ferjm]]

Comment on attachment 715223 [details] [diff] [review]
v1

[Approval Request Comment]
User impact if declined: The user will be notified with an incorrect error message and won't be able to retry an app installation unless she uninstalls the app before. With this patch the user will be informed with a proper error message and will be able to retry the app download by just clicking in the app icon again.
Testing completed: Local testing
Risk to taking this patch (and alternatives if risky): Very low risk
String or UUID changes made by this patch: None

Comment 9

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/dc90a0618dd2

Comment 10

[Lukas Blakk [:lsblakk] use ?needinfo]

Comment on attachment 715223 [details] [diff] [review]
v1

Approving for v1-train uplift.

Comment 11

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-b2g18/rev/71900a08cfb1