Closed Bug 1022607 Opened 10 years ago Closed 10 years ago

JavaScript Error: "TypeError: request.response is null" when downloading webapp in Fennec

Categories

(Firefox for Android Graveyard :: Web Apps (PWAs), defect, P1)

ARM
Android
defect

Tracking

(firefox30 unaffected, firefox31 unaffected, firefox32 fixed, firefox33 fixed)

RESOLVED FIXED
Firefox 33
Tracking Status
firefox30 --- unaffected
firefox31 --- unaffected
firefox32 --- fixed
firefox33 --- fixed

People

(Reporter: mhaigh, Assigned: swu)

References

Details

(Keywords: regression)

Attachments

(1 file, 1 obsolete file)

When downloading a packaged app, the following error occurs and the download fails, preventing web app from being installed:

32396               Timeline  I  Timeline: Activity_idle id: android.os.BinderProxy@41bef068 time:2890714
 32396           GeckoConsole  E  [model] Found app with lookup key box-it
 32396           GeckoConsole  E  [buttons] Install requested for Box It
 32396           GeckoConsole  E  [buttons] Starting app installation for Box It
 32396           GeckoConsole  E  [tracking][helpers] No associated search term to track.
 32396           GeckoConsole  E  [apps] Using `navigator.mozApps.installPackage` installer.
 32396     GeckoWebappManager  D  _downloadApk for https://marketplace.firefox.com/app/95a5dcbb-8a74-4580-b829-ad33a3721431/manifest.webapp?feature_profile=755
                               8a9ff6e68.47.4
 32396     GeckoWebappManager  D  downloading APK from https://controller.apk.firefox.com/application.apk?manifestUrl=https%3A%2F%2Fmarketplace.firefox.com%2Fa
                               pp%2F95a5dcbb-8a74-4580-b829-ad33a3721431%2Fmanifest.webapp%3Ffeature_profile%3D7558a9ff6e68.47.4
 32396     GeckoWebappManager  D  downloading APK to /storage/emulated/0/Download/httpsmarketplacefirefoxcomapp95a5dcbb8a744580b829ad33a3721431manifestwebappfe
                               atureprofile7558a9ff6e68474-1.apk
 32396     GeckoHardwareUtils  D  HardwareUtils already inited.
 32396   GeckoWebappManager..  D  onreadystatechange: 2
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onprogress: received 30202 bytes
 32396   GeckoWebappManager..  D  onprogress: wrote 30202 bytes
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 3
 32396   GeckoWebappManager..  D  onreadystatechange: 4
 32396           GeckoConsole  E  [JavaScript Error: "TypeError: request.response is null" {file: "resource://gre/modules/WebappManagerWorker.js" line: 23}]

 32396         GeckoHealthRec  D  Recording session end: P
 32396         GeckoHealthRec  V  Recorded session entry for env 7, current is 7
 32396          GeckoSessInfo  D  Recording session done: 1402312694658
 32396   GeckoBrowserProvider  D  Expiring history.
 32396   GeckoBrowserProvider  D  Expiring thumbnails.
 32396     GeckoMemoryMonitor  D  onTrimMemory() notification received with level 20
 32396            GeckoHealth  I  fennec_martyn :: HealthReportBroadcastService :: Registering HealthReportPruneService.
 32396            GeckoHealth  I  fennec_martyn :: BackgroundService :: Setting inexact repeating alarm for interval 86400000
 32396     GeckoHardwareUtils  D  HardwareUtils already inited.
 32396           GeckoConsole  E  [JavaScript Warning: "[buttons] Spinner timeout for Box It"]
 32396     GeckoMemoryMonitor  D  Decreased memory pressure to 0
  6072         ActivityThread  D  handleBindApplication:org.mozilla.fennec_martyn
  6072         ActivityThread  D  setTargetHeapUtilization:0.75
  6072         ActivityThread  D  setTargetHeapMinFree:524288
  6072               dalvikvm  D  Trying to load lib /data/app-lib/org.mozilla.fennec_martyn-2/libmozglue.so 0x41bf5e50
  6072               dalvikvm  D  Added shared lib /data/app-lib/org.mozilla.fennec_martyn-2/libmozglue.so 0x41bf5e50
  6072               dalvikvm  D  No JNI_OnLoad found in /data/app-lib/org.mozilla.fennec_martyn-2/libmozglue.so 0x41bf5e50, skipping init
  6072   GeckoScreenOrienta..  D  updating to new orientation PORTRAIT_PRIMARY
  6072               dalvikvm  I  DexOpt: illegal method access (call Landroid/content/res/TypedArray;.<init> (Landroid/content/res/Resources;[I[II)V from Land
                               roid/content/res/XResources$XTypedArray;)
  6072               dalvikvm  I  Could not find method android.content.res.TypedArray.<init>, referenced from method android.content.res.XResources$XTypedArra
                               y.<init>
  6072               dalvikvm  W  VFY: unable to resolve direct method 82: Landroid/content/res/TypedArray;.<init> (Landroid/content/res/Resources;[I[II)V
  6072               dalvikvm  D  VFY: replacing opcode 0x70 at 0x0002
  6072             Adreno-EGL  I  <qeglDrvAPI_eglInitialize:320>: EGL 1.4 QUALCOMM Build: I0404c4692afb8623f95c43aeb6d5e13ed4b30ddbDate: 11/06/13
  6072       GeckoSharedPrefs  D  Current version = 1, prefs version = 1
  6072          GeckoSessInfo  D  Building SessionInformation from prefs: 0, 0, true, false
  6072     GeckoHardwareUtils  D  System memory: 1795MB.
  6072           GeckoProfile  D  Found profile dir.
  6072               GeckoApp  I  Creating HealthRecorder.
  6072               GeckoApp  D  OS locale is en_GB, app locale is null
  6072         GeckoHealthRec  D  Initializing. Dispatcher is org.mozilla.gecko.EventDispatcher@41c4c6f8
  6072         GeckoHealthRec  D  Initializing profile cache.
  6072            GeckoLogger  I  fennec_martyn :: GeckoProfileInfo :: Restoring ProfileInformationCache from file.
  6072         GeckoHealthRec  D  Successfully restored state. Initializing storage.
  6072         GeckoHealthRec  D  Done initializing profile cache. Beginning storage init.
  6072     GeckoHardwareUtils  D  HardwareUtils already inited.
  6072            GeckoLogger  I  fennec_martyn :: HealthReportStorage :: Initializing measurement org.mozilla.appSessions to 4 (current 4)
  6072            GeckoLogger  I  fennec_martyn :: HealthReportStorage :: Measurement org.mozilla.appSessions already at v4
  6072            GeckoLogger  I  fennec_martyn :: HealthReportStorage :: Initializing measurement org.mozilla.searches.counts to 5 (current 5)
  6072            GeckoLogger  I  fennec_martyn :: HealthReportStorage :: Measurement org.mozilla.searches.counts already at v5
  6072         GeckoHealthRec  D  Ensuring environment.
  6072               dalvikvm  D  Trying to load lib /data/app-lib/org.mozilla.fennec_martyn-2/libmozglue.so 0x41bf5e50
  6072               dalvikvm  D  Shared lib '/data/app-lib/org.mozilla.fennec_martyn-2/libmozglue.so' already loaded in same CL 0x41bf5e50
  6072         GeckoHealthRec  D  Finishing init.
  6072         GeckoHealthRec  D  Checking for orphan session.
  6072          GeckoSessInfo  D  Recording start of session: 1402313141405
  6072        GeckoBrowserApp  D  onLocaleReady: en_GB
  6072         GeckoHealthRec  D  Recording session end: P
  6072         OpenGLRenderer  D  Enabling debug mode 0
  6072         OpenGLRenderer  D  GL error from OpenGLRenderer: 0x502
  6072         OpenGLRenderer  E  GL_INVALID_OPERATION
  6072         GeckoHealthRec  V  Recorded session entry for env 7, current is 7
  6072          GeckoSessInfo  D  Recording session done: 1402313141405
  6072               Timeline  I  Timeline: Activity_idle id: android.os.BinderProxy@41bf3a18 time:3337444
  6072   GeckoBrowserProvider  D  Expiring history.
  6072   GeckoBrowserProvider  D  Expiring thumbnails.
  6072   GeckoWebappUninsta..  I  Package is being replaced; ignoring removal intent
  6072             FxAccounts  I  fennec_martyn :: FxAccountUpgradeReceiver :: Upgrade broadcast received.
  6072             FxAccounts  I  fennec_martyn :: FxAccountUpgradeReceiver :: Trying to unpickle any pickled Firefox Account.
  6072             FxAccounts  I  fennec_martyn :: FxAccountUpgradeReceiver :: Trying to advance 0 existing Firefox Accounts from the Doghouse to Separated (if
                                necessary).
  6072            GeckoHealth  I  fennec_martyn :: HealthReportBroadcastService :: Registering HealthReportPruneService.
  6072            GeckoHealth  I  fennec_martyn :: BackgroundService :: Setting inexact repeating alarm for interval 86400000
  6072     GeckoHardwareUtils  D  HardwareUtils already inited.
  6072         OpenGLRenderer  D  GL error from OpenGLRenderer: 0x502
  6072         OpenGLRenderer  E  GL_INVALID_OPERATION
  6072    GeckoBatteryManager  W  Already started!
  6072          GeckoSessInfo  D  Recording start of session: 1402313468105
  6072              GeckoAxis  I  Prefs: 0.85,0.97,10.0,0.1,0.04,0.3,0.5
  6072              GeckoTabs  D  Setting about: tab favicon inline.
  6072            GeckoLoader  D  Gecko environment env0: null
Keywords: regression
OS: Mac OS X → Android
Hardware: x86 → ARM
Bug 1008126 looks relevant.
Severity: normal → blocker
Priority: -- → P1
I confirmed through bisection that this is a regression from bug 1008126.  In my tests, request.response is as expected the first time the onprogress handler is called, after which it's always null.

shianyow, bent: Any idea why we started seeing this after the fix for that bug landed?
Blocks: 1008126
Flags: needinfo?(swu)
Flags: needinfo?(bent.mozilla)
(In reply to Myk Melez [:myk] [@mykmelez] from comment #2)
> I confirmed through bisection that this is a regression from bug 1008126. 
> In my tests, request.response is as expected the first time the onprogress
> handler is called, after which it's always null.
> 
> shianyow, bent: Any idea why we started seeing this after the fix for that
> bug landed?

Thanks for these information, that's helpful.  I think I know the root cause and work on it.
Flags: needinfo?(swu)
Assignee: nobody → swu
The patch should solve the problem.

On my PC, I have to use 16MB+ data in the test case to make response separated into chunks, and it takes about 10 seconds to run the test case with 40MB data.

I imagine that there might be some way to force seperating response into smaller chunks, but due the this bug is blocking, we can consider test with current approach and reduce testing time by follow up bug.
Attachment #8437562 - Flags: review?(bent.mozilla)
Martyn, could you test if this patch works for you?
Flags: needinfo?(mhaigh)
This works for me now.  Cheers!
Flags: needinfo?(mhaigh)
Comment on attachment 8437562 [details] [diff] [review]
Patch: Only use cached arraybuffer response at DONE state.

Review of attachment 8437562 [details] [diff] [review]:
-----------------------------------------------------------------

This looks good! r=me with these fixed:

::: dom/workers/XMLHttpRequest.cpp
@@ +1198,5 @@
>              obj = JS_NewArrayObject(aCx, argv);
>              if (obj) {
>                transferable.setObject(*obj);
> +              // Only in readyState DONE that we can make sure the response
> +              // will not be changed and to allow using cached response.

Nit: Let's make this comment:

  Only cache the response when the readyState is DONE.

@@ +1199,5 @@
>              if (obj) {
>                transferable.setObject(*obj);
> +              // Only in readyState DONE that we can make sure the response
> +              // will not be changed and to allow using cached response.
> +              if (xhr->ReadyState() == 4) {

Nit: Please replace |4| with |nsIXMLHttpRequest::DONE|.
Attachment #8437562 - Flags: review?(bent.mozilla) → review+
Shian-Yow, after this patch lands on trunk please request approval to land it on mozilla-aurora too.
Flags: needinfo?(bent.mozilla)
Try server: 
https://tbpl.mozilla.org/?tree=Try&rev=202b46b0727f
(The test case takes about 5 seconds on Linux Opt and 30 seconds on Linux Debug)

remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/ea611fa342ff
https://hg.mozilla.org/mozilla-central/rev/ea611fa342ff
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 33
ni?-swu for comment 8.
Flags: needinfo?(swu)
[Approval Request Comment]
Bug caused by (feature/regressing bug #): bug 1008126
User impact if declined: Fail to install packaged app on Firefox Android.
Testing completed (on m-c, etc.): Manual test by reporter and mochitest on try server.
Risk to taking this patch (and alternatives if risky): Low.  The patch caches the response when the readyState is DONE.  For readyState before DONE, the only possible array buffer response is moz-chunked-arraybuffer sent with progress event.  Each of such response is unique and the progress event with regard to the response is dispatched just once, so we must not cache it and it is safe not to cache it.
String or IDL/UUID changes made by this patch: None
Attachment #8437562 - Attachment is obsolete: true
Attachment #8438838 - Flags: review+
Flags: needinfo?(swu)
Attachment #8438838 - Flags: approval-mozilla-aurora?
Comment on attachment 8438838 [details] [diff] [review]
Patch(as landed): Only cache the response when the readyState is DONE. r=bent

Aurora approval granted.
Attachment #8438838 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: