970131 - Takes about a minute of inactivity before Android requests installation on old device

Status: RESOLVED WONTFIX

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

Description

[Aaron Train [:aaronmt]]

I don't know what our minimum is here, but this isn't shippable.

HTC Nexus One (Android 2.3)

i) https://marketplace.firefox.com/app/calculator?src=all-popular
ii) Tap Install

Check back in a minute and then you'll see the prompt.

http://dapk.net/application.apk?manifestUrl=http://scientific-calculator.appspot.com/manifest.webapp

The APK is only about ~37KB. This is a hosted application.

02-09 19:48:22.400 I/Gecko   (  810): _downloadApk for http://scientific-calculator.appspot.com/manifest.webapp

A minute later ...

02-09 19:49:37.840 I/ActivityManager(   96): Starting: Intent { act=android.intent.action.VIEW dat=file:///mnt/sdcard/Download/httpscientificcalculatorappspotcommanifestwebapp.apk typ=application/vnd.android.package-archive cmp=android/com.android.internal.app.ResolverActivity } from pid 810


On second attempt

02-09 19:58:32.110 I/Gecko   ( 1058): _downloadApk for http://scientific-calculator.appspot.com/manifest.webapp


02-09 19:59:35.040 I/ActivityManager(   96): Starting: Intent { act=android.intent.action.VIEW dat=file:///mnt/sdcard/Download/httpscientificcalculatorappspotcommanifestwebapp.apk typ=application/vnd.android.package-archive cmp=android/com.android.internal.app.ResolverActivity } from pid 1058

Comment 1

[Myk Melez [:myk] [@mykmelez]]

I'm unsure exactly where the delay occurs, but I suspect it happens on the server side, in which case this is likely to be fixed by moving to the production servers.

Comment 2

[Myk Melez [:myk] [@mykmelez]]

(Note: if it's on the server side, then it shouldn't matter which device you use.  But it might matter whether it's the first request for the app or a subsequent one, since the server caches APKs it generates.)

Comment 3

[Austin King [:ozten]]

time curl 'http://dapk.net/application.apk?manifestUrl=http://scientific-calculator.appspot.com/manifest.webapp' > calculator.apk

This takes between 500 milliseconds and 1 second from my testing.

Can we establish a more informative timeline with a debug build?

Comment 4

[Aaron Train [:aaronmt]]

(In reply to Austin King [:ozten] from comment #3)
> time curl
> 'http://dapk.net/application.apk?manifestUrl=http://scientific-calculator.
> appspot.com/manifest.webapp' > calculator.apk
> 
> This takes between 500 milliseconds and 1 second from my testing.

What device? On my Nexus 4 it's the same. Can you try this with an Android 2.3 based device?

> Can we establish a more informative timeline with a debug build?

Is there verbose logging? Or, perhaps, you can supply me with a custom build?

Comment 5

[Austin King [:ozten]]

> What device? On my Nexus 4 it's the same. Can you try this with an Android 2.3 based device?

To isolate the source of the latency, this is from my laptop over Wi-Fi.

Comment 6

[Myk Melez [:myk] [@mykmelez]]

(In reply to Aaron Train [:aaronmt] from comment #4)
> Is there verbose logging? Or, perhaps, you can supply me with a custom build?

I can do this.  Building it now.

Comment 7

[Myk Melez [:myk] [@mykmelez]]

(In reply to Myk Melez [:myk] [@mykmelez] from comment #6)
> (In reply to Aaron Train [:aaronmt] from comment #4)
> > Is there verbose logging? Or, perhaps, you can supply me with a custom build?
> 
> I can do this.  Building it now.

Here's a debug build that should log more info about the download process:

https://people.mozilla.org/~myk/synthapk/fennec-30.0a1.en-US.android-arm.apk

Let me know if it still doesn't log enough; I can create a custom build with any additional logging that would be useful!

Comment 8

[Aaron Train [:aaronmt]]

02-11 11:03:06.250 I/Gecko   (  860): _downloadApk for http://scientific-calculator.appspot.com/manifest.webapp
02-11 11:03:06.320 I/Gecko   (  860): downloading APK from http://dapk.net/application.apk?manifestUrl=http%3A%2F%2Fscientific-calculator.appspot.com%2Fmanifest.webapp
02-11 11:03:06.380 I/Gecko   (  860): downloading APK to /mnt/sdcard/Download/httpscientificcalculatorappspotcommanifestwebapp-3.apk
02-11 11:03:06.420 E/Profiler(  860): BPUnw: [10 total] thread_register_for_profiling(me=0x488b90, stacktop=0x5b5ffcdf)
02-11 11:03:06.860 I/Gecko   (  860): _downloadApk for http://scientific-calculator.appspot.com/manifest.webapp
02-11 11:03:06.920 I/Gecko   (  860): downloading APK from http://dapk.net/application.apk?manifestUrl=http%3A%2F%2Fscientific-calculator.appspot.com%2Fmanifest.webapp
02-11 11:03:07.480 I/Gecko   (  860): downloading APK to /mnt/sdcard/Download/httpscientificcalculatorappspotcommanifestwebapp-4.apk
02-11 11:03:23.610 I/Gecko   (  860): [860] WARNING: NS_ENSURE_TRUE(!(aRv.Failed())) failed: file /Users/myk/Mozilla/gecko-dev/content/base/src/nsXMLHttpRequest.cpp, line 3637
02-11 11:03:38.290 E/GeckoConsole(  860): [JavaScript Warning: "[buttons] Spinner timeout for Calculator"]
02-11 11:03:46.980 I/Gecko   (  860): [860] WARNING: NS_ENSURE_TRUE(!(aRv.Failed())) failed: file /Users/myk/Mozilla/gecko-dev/content/base/src/nsXMLHttpRequest.cpp, line 3637
02-11 11:03:47.380 I/Gecko   (  860): [860] WARNING: NS_ENSURE_TRUE(!(aRv.Failed())) failed: file /Users/myk/Mozilla/gecko-dev/content/base/src/nsXMLHttpRequest.cpp, line 3637
02-11 11:03:47.680 I/Gecko   (  860): WebManagerWorker onreadystatechange: 2
02-11 11:03:47.690 I/Gecko   (  860): WebManagerWorker onreadystatechange: 3
02-11 11:03:48.030 I/Gecko   (  860): WebManagerWorker onprogress: received 20070 bytes
02-11 11:03:48.110 I/Gecko   (  860): WebManagerWorker onprogress: wrote 20070 bytes
02-11 11:03:48.240 I/Gecko   (  860): WebManagerWorker onreadystatechange: 3
02-11 11:03:48.260 I/Gecko   (  860): WebManagerWorker onprogress: received 17374 bytes
02-11 11:03:48.320 I/Gecko   (  860): WebManagerWorker onprogress: wrote 17374 bytes
02-11 11:03:48.320 I/Gecko   (  860): WebManagerWorker onreadystatechange: 4
02-11 11:03:48.630 I/ActivityManager(   96): Starting: Intent { act=android.intent.action.VIEW dat=file:///mnt/sdcard/Download/httpscientificcalculatorappspotcommanifestwebapp-3.apk typ=application/vnd.android.package-archive cmp=android/com.android.internal.app.ResolverActivity } from pid 860

Comment 9

[Austin King [:ozten]]

> 02-11 11:03:06.860 I/Gecko   (  860): _downloadApk for http://scientific-calculator.appspot.com/manifest.webapp

> 02-11 11:03:48.320 I/Gecko   (  860): WebManagerWorker onreadystatechange: 4

So it sounds like it's taking 42 seconds to download the APK?

What kind of a network is this over?

How long does it take the device to download this:
http://ozten.com/random/apk-factory/scicalc.apk

This will isolate network performance from any issues with the APK Factory.

Comment 10

[Myk Melez [:myk] [@mykmelez]]

(In reply to Austin King [:ozten] from comment #9)
> > 02-11 11:03:06.860 I/Gecko   (  860): _downloadApk for http://scientific-calculator.appspot.com/manifest.webapp
> 
> > 02-11 11:03:48.320 I/Gecko   (  860): WebManagerWorker onreadystatechange: 4
> 
> So it sounds like it's taking 42 seconds to download the APK?
> 
> What kind of a network is this over?

I think the problem is more that it takes 40 seconds to go from "downloading APK to …" to "onreadystatechange: 2" ("processing request"), which happens before any bits of the APK are actually downloaded:

02-11 11:03:07.480 I/Gecko   (  860): downloading APK to /mnt/sdcard/Download/httpscientificcalculatorappspotcommanifestwebapp-4.apk
…
02-11 11:03:47.680 I/Gecko   (  860): WebManagerWorker onreadystatechange: 2


After that, the actual download takes place quickly.  So this isn't a network problem.  But there are multiple suspects between those two debug log messages, and we'd need more debug logging to determine exactly where the stall/slowness occurs.

Here's where we log "downloading APK to …":

http://mxr.mozilla.org/mozilla-central/source/mobile/android/modules/WebappManager.jsm?rev=17aaa1bc6625#117

And here's where we log "onreadystatechange: 2":

http://mxr.mozilla.org/mozilla-central/source/mobile/android/modules/WebappManagerWorker.js?rev=17aaa1bc6625#27

For example, we load WebappManagerWorker.js as a ChromeWorker, which might take longer than we expect; and the ChromeWorker initiates the XMLHttpRequest, which might fail on DNS resolution.

Comment 11

[Aaron Train [:aaronmt]]

(In reply to Austin King [:ozten] from comment #9)
> > 02-11 11:03:06.860 I/Gecko   (  860): _downloadApk for http://scientific-calculator.appspot.com/manifest.webapp
> 
> > 02-11 11:03:48.320 I/Gecko   (  860): WebManagerWorker onreadystatechange: 4
> 
> So it sounds like it's taking 42 seconds to download the APK?
> 
> What kind of a network is this over?

This is on residential WiFi. Again, no problems whatsoever on newer devices.

Comment 12

[Myk Melez [:myk] [@mykmelez]]

(In reply to Aaron Train [:aaronmt] from comment #11)
> This is on residential WiFi. Again, no problems whatsoever on newer devices.

I suspect the problem is in the client, not on the network.  But hard to say if it's because of the device hardware or the Android version.  mhaigh is going to do some testing and see if he can identify it.

Comment 13

[Aaron Train [:aaronmt]]

Re-visiting this again. Today I am testing on an obtained Samsung Nexus S also running Android 2.3 and it is significantly faster than my HTC One also running Android 2.3; this leads me to suspect, overall that this is just a limitation of the hardware at hand. I'm very much less concerned about Android hardware from 2010.

Comment 14

[Myk Melez [:myk] [@mykmelez]]

Per bug 1235869, we're going to disable the Android web runtime, so we won't fix this bug in it.

(This is part of a bulk resolution of bugs in the Firefox for Android::Web Apps component, from which I attempted to exclude bugs that are not specific to the runtime, but it's possible that I included one accidentally.  If so, I'm sorry, and please reopen the bug!)