974692 - Install of packaged apps from Reviewer tools fails with a 400

Status: RESOLVED FIXED

(Marketplace Graveyard :: Integration, defect, P2)

Description

[krupa raj[:krupa]]

Android 4.0.4/ Nightly 30.0a1 (02/19)
Samsung Galaxy tablet

steps to reproduce:
1. Load marketplace-dev.allizom.org/reviewers
2. Log in with an account with access
3. Navigate to the reviewer details page for a packaged app (I used Memo Calc)
4. Click the install button

observed behavior:
Install fails with a 400.

02-19 23:51:54.603 I/Gecko   (18237): _downloadApk for https://marketplace-dev.allizom.org/reviewers/memo-calc/1513794/mini-manifest
02-19 23:51:54.603 I/Gecko   (18237): downloading APK from https://apk-controller.stage.mozaws.net/application.apk?manifestUrl=https%3A%2F%2Fmarketplace-dev.allizom.org%2Freviewers%2Fmemo-calc%2F1513794%2Fmini-manifest
02-19 23:51:54.613 I/Gecko   (18237): downloading APK to /mnt/sdcard/Download/httpsmarketplacedevallizomorgreviewersmemocalc1513794minimanifest.apk
02-19 23:51:54.613 E/Profiler(18237): BPUnw: [32 total] thread_register_for_profiling(me=0x6bc318, stacktop=0x6f3ffc7b)
02-19 23:51:55.513 W/PowerManagerService(  193): Timer 0x7->0x3|0x0
02-19 23:51:55.513 I/PowerManagerService(  193): Ulight 7->3|0
02-19 23:51:55.513 D/PowerManagerService(  193): setLightBrightness : mButtonLight : 0
02-19 23:51:55.523 V/WindowOrientationListener(  193): nearestRotation : 0   Angle: 0   tilt: 53
02-19 23:51:55.863 I/Gecko   (18237): WebManagerWorker onreadystatechange: 2
02-19 23:51:55.863 I/Gecko   (18237): WebManagerWorker onreadystatechange: 3
02-19 23:51:55.863 I/Gecko   (18237): WebManagerWorker onprogress: received 31 bytes
02-19 23:51:55.863 I/Gecko   (18237): WebManagerWorker onprogress: wrote 31 bytes
02-19 23:51:55.863 I/Gecko   (18237): WebManagerWorker onreadystatechange: 4
02-19 23:51:55.873 I/Gecko   (18237): error downloading APK: 400 - Bad Request
02-19 23:51:55.883 I/Gecko   (18237): error downloading APK: 400 - Bad Request
02-19 23:51:55.923 E/Profiler(18237): BPUnw: [31 total] thread_unregister_for_profiling(me=0x6bc318) 
02-19 23:51:56.023 E/GeckoConsole(18237): Error code: 400 - Bad Request

Comment 1

[Austin King [:ozten]]

Couple Notes:

1) This will not hit http://dapk.net as suggested in IRC

I don't know why dapk.net (dev) was mentioned, to hit that environment the browser.webapps.apkFactoryUrl config must be flipped to 

    browser.webapps.apkFactoryUrl=http://dapk.net/application.apk

BUT See Point #3 ;)

2) Manifest URL redirects to HTML

    curl -v 'https://marketplace-dev.allizom.org/login?to=/reviewers/memo-calc/1513794/mini-manifest'
    302 Location: https://marketplace-dev.allizom.org/login?to=/reviewers/memo-calc/1513794/mini-manifest

I think this is where we need the hawk or other one time use URLs

3) The Reviewer should be using the review instance of stage.

There is a release and review instance of stage. Release instance would not cache APKs and would sign with DEBUG instead of final signing keys. Marketplace would generate one time use URLs for mini-manifest and package.

Hope that is helpful!

Comment 2

[Andy McKay]

We fixed an issue with the JS in the reviewer tools and we now get a manifest URL being sent like this:

https://www.dropbox.com/s/i3472l1xsrs5igy/Screenshot%202014-02-20%2011.29.26.png

(That's a one time token, trying to reuse the value from the screenshot won't work). This should go through correctly, but it doesn't look like it is. I'm going to guess that its the querystring in the URL, but if anyone else has a better idea I'm all ears.

As a test, if I get that URL and wget it, then open up the manifest and wget the package_url I get the packaged app correctly. So I think the marketplace side of things is correct.

If Myk has any ideas from the client, glad for help.

Comment 3

[Kumar McMillan [:kumar]]

isn't this a dupe of bug 889744?

Comment 4

[Andy McKay]

(In reply to Kumar McMillan [:kumar] (needinfo for quickness) from comment #3)
> isn't this a dupe of bug 889744?

Possibly, we aren't sure where the issue in the client is yet. We thought it was around permissions, but I don't think thats the case.

Comment 5

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

I tried to reproduce this problem yesterday and again this morning, but I ran into bug 977657, which stymied me.  Can anyone suggest a workaround?

Comment 6

[krupa raj[:krupa]]

(In reply to Myk Melez [:myk] [@mykmelez] from comment #5)
> I tried to reproduce this problem yesterday and again this morning, but I
> ran into bug 977657, which stymied me.  Can anyone suggest a workaround?

We reverted the change that broke login. Please try again after clearing your cookies.

Comment 7

[Andy McKay]

I saw this in adb logcat:

I/Gecko   ( 1812): _downloadApk for https://marketplace-dev.allizom.org/reviewers/memo-calc/1513794/mini-manifest?token=5120e0fd-48f7-4817-8dc0-8a8239c4e111
I/Gecko   ( 1812): downloading APK from https://apk-controller.stage.mozaws.net/application.apk?manifestUrl=https%3A%2F%2Fmarketplace-dev.allizom.org%2Freviewers%2Fmemo-calc%2F1513794%2Fmini-manifest%3Ftoken%3D5120e0fd-48f7-4817-8dc0-8a8239c4e111
D/dalvikvm(  650): GC_CONCURRENT freed 386K, 6% free 9319K/9864K, paused 2ms+4ms, total 25ms
I/Gecko   ( 1812): downloading APK to /storage/emulated/0/Download/httpsmarketplacedevallizomorgreviewersmemocalc1513794minimanifesttoken5120e0fd48f748178dc08a8239c4e111.apk
E/GeckoConsole( 1812): [install] manifest_url: https://marketplace-dev.allizom.org/reviewers/memo-calc/1513794/mini-manifest?token=5120e0fd-48f7-4817-8dc0-8a8239c4e111
E/Profiler( 1812): BPUnw: [12 total] thread_register_for_profiling(me=0x5d421390, stacktop=0x6b2cec73)

Comment 8

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

This seems like a problem with the APK Factory service or Marketplace, not the client, since the client logs show that the client is requesting an APK from the service using a valid URL, and it's the service that returns the 400 error:

 24950                  Gecko  I  _downloadApk for https://marketplace-dev.allizom.org/reviewers/memo-calc/1513794/mini-manifest?token=24c45770-0416-4264-9d4f-03520741ba7e
 24950                  Gecko  I  downloading APK from http://dapk.net/application.apk?manifestUrl=https%3A%2F%2Fmarketplace-dev.allizom.org%2Freviewers%2Fmemo-calc%2F1513794%2Fmini-manifest%3Ftoken%3D24c45770-0416-4264-9d4f-03520741ba7e
 24950                  Gecko  I  downloading APK to /storage/emulated/0/Download/httpsmarketplacedevallizomorgreviewersmemocalc1513794minimanifesttoken24c45770041642649d4f03520741ba7e.apk
…
 24950                  Gecko  I  WebManagerWorker onreadystatechange: 2
 24950                  Gecko  I  WebManagerWorker onreadystatechange: 3
 24950                  Gecko  I  WebManagerWorker onprogress: received 31 bytes
 24950                  Gecko  I  WebManagerWorker onprogress: wrote 31 bytes
 24950                  Gecko  I  WebManagerWorker onreadystatechange: 4
 24950                  Gecko  I  error downloading APK: 400 - Bad Request
 24950                  Gecko  I  error downloading APK: 400 - Bad Request

To confirm that this is unrelated to the client, we could generate a tokened URL to the mini-manifest, use it to construct a "get APK" URL to the service, and then try to wget that URL.  That's different from what andym did in comment 2, as he tested the tokened URL directly, bypassing both the client and the service.

In any case, I hacked Fennec to log the contents of the response (i.e. those "31 bytes" the client receives), which is:

  SyntaxError: Unexpected token <

So it seems like some code in APK Factory is throwing that error when it processes the request to generate an APK for the URL in question.  Perhaps Marketplace is returning an HTML page rather than a JSON file, and the APK Factory raises that exception when it tries to parse the HTML page as JSON?

Comment 9

[Austin King [:ozten]]

I believe the one time use urls return HTML on the second try asking the user to sign in.

Comment 10

[Andy McKay]

So one of the URL's in this flow is being requested twice by the whole flow here? That would be a 403. 

Does the APK Factory check the status of the response and log URLs which return a 4xx or 5xx?

Comment 11

[Kumar McMillan [:kumar]]

A couple notes (I'm still digging in)

- The APK generator seems to be stripping ?token= from the URL when requesting the manifest
- When the token is stripped, the Marketplace redirects to a page that asks you to sign in but the response is a 200

both of those things seem wrong

Comment 12

[Kumar McMillan [:kumar]]

I'm pretty sure this is an APK Factory bug but I'm having a hard time syncing up with the repo. I'm assigning it to ozten because he has been doing a lot of refactoring / merging and might have a better chance at landing a patch.

What's happening is the APK Factory is stripping out the ?token part of the URL so it's not loading the manifest correctly. This is my theoretical fix. url.resolve() was stripping off ?token.

diff --git a/lib/front_controller.js b/lib/front_controller.js
index 895fc85..49e3c43 100644
--- a/lib/front_controller.js
+++ b/lib/front_controller.js
@@ -56,7 +56,7 @@ function cacheMissGenerateAPK(manifestUrl, appType, config, log, cacheApkFn, cb,
   var loaderDirname;
 
   if (/^\w+:\/\//.test(manifestUrl)) {
-    loaderDirname = url.resolve(manifestUrl, ".");
+    loaderDirname = manifestUrl;
   } else {
     loaderDirname = path.loaderDirname(path.resolve(process.cwd(), manifestUrl));
   }

Comment 13

[Austin King [:ozten]]

WIP https://github.com/mozilla/apk-factory-service/pull/57

Kumar, thanks for diving in on this one.

I think you should be unblocked if you pull from master.
Can you try this PR's branch also?

thanks!

Comment 14

[Kumar McMillan [:kumar]]

I landed this on dev so we can test it out https://github.com/mozilla/apk-factory-service/commit/2b9ad55d8147d51c794a22a3da1620177b249030

Comment 15

[krupa raj[:krupa]]

(In reply to Kumar McMillan [:kumar] (needinfo for quickness) from comment #14)
> I landed this on dev so we can test it out
> https://github.com/mozilla/apk-factory-service/commit/
> 2b9ad55d8147d51c794a22a3da1620177b249030

Kumar, what settings should I use in about:config to verify this?

Comment 16

[Kumar McMillan [:kumar]]

I'm not sure what the state of dev is. Jason, do you know?

I believe the URL is https://apk-controller.dev.mozaws.net/application.apk but that has a self-signed cert so you might get an error?

Comment 17

[Jason Thomas [:jason]]

https://apk-controller.dev.mozaws.net/application.apk is the correct URL to -dev. I am troubleshooting issues with signer but the server should be available for use.

Comment 18

[krupa raj[:krupa]]

(In reply to Jason Thomas [:jason] from comment #17)
> https://apk-controller.dev.mozaws.net/application.apk is the correct URL to
> -dev. I am troubleshooting issues with signer but the server should be
> available for use.

what's the link for reviewers?

Comment 19

[krupa raj[:krupa]]

Using https://apk-controller.dev.mozaws.net/application.apk is throwing a 

03-12 13:48:51.440 W/PackageParser(24723): Unable to read AndroidManifest.xml of /mnt/sdcard/Download/httpphotomirrornetopenwebapp1webapp.apk
03-12 13:48:51.440 W/PackageParser(24723): java.io.FileNotFoundException: AndroidManifest.xml


from both reviewer tools and public pages. I am blocked from testing this fix.

Comment 20

[Austin King [:ozten]]

There was a bug with our fix for query string support.
To unblock QA, I've committed an initial fix
0def1a81efd8b5eef2ed7aa9561fbeafa921426c

Let me know if this doesn't unblock you on https://apk-controller.dev.mozaws.net/application.apk which should auto-deploy this fix in a few minutes.

But I still need to make a deeper fix to how file_loader.js works.

Comment 21

[krupa raj[:krupa]]

I get 

03-13 18:22:09.705 E/GeckoConsole(17785): [JavaScript Error: "apk-controller.dev.mozaws.net:443 uses an invalid security certificate.
03-13 18:22:09.705 E/GeckoConsole(17785): 
03-13 18:22:09.705 E/GeckoConsole(17785): The certificate is not trusted because no issuer chain was provided.
03-13 18:22:09.705 E/GeckoConsole(17785): 
03-13 18:22:09.705 E/GeckoConsole(17785): (Error code: sec_error_unknown_issuer)
03-13 18:22:09.705 E/GeckoConsole(17785): "]

Comment 22

[Andy McKay]

Have you tried visiting apk-controller.dev.mozaws.net in a browser and accepting the certificate exception to avoid us having to buy a cert?

Comment 23

[Andy McKay]

Also, if you install this on Android, this should address the issue:

https://wiki.mozilla.org/MozillaRootCertificate

Comment 24

[krupa raj[:krupa]]

install now works! thanks.