970641 - GET requests fail randomly

Status: RESOLVED WORKSFORME

(Marketplace Graveyard :: API, defect, P2)

Description

[krupa raj[:krupa]]

Android: 4.0.3
Firefox mobile: 30.0a1(2014-02-06)

steps to reproduce:
1. Launch marketplace-dev on the latest Firefox mobile nightly
2. After the page loads, switch to the New tab

expected behavior:
New tab loads with apps

actual behavior:
Sometimes, switching to the New tab fails and the entire section disappears since the GET request fails

ashes: b487f


logs shows:
02-10 14:56:06.080 E/GeckoConsole( 5041): [req] GETing from cache https://marketplace-dev.allizom.org/api/v1/fireplace/search/featured/?_user=---&cache=1&cat=&dev=android&device=mobile&lang=en-US&region=us&vary=0
02-10 14:56:06.080 E/GeckoConsole( 5041): [model] Stored keeper-web-app as app
02-10 14:56:06.080 E/GeckoConsole( 5041): [model] Stored buddyspot as app
02-10 14:56:06.080 E/GeckoConsole( 5041): [model] Stored hackerweb as app
02-10 14:56:06.080 E/GeckoConsole( 5041): [req] GETing https://marketplace-dev.allizom.org/api/v1/fireplace/search/featured/?_user=---&cache=1&cat=&dev=android&device=mobile&lang=en-US&region=us&sort=reviewed&vary=0
02-10 14:56:06.085 E/GeckoConsole( 5041): [tracking] Tracking page view /?sort=reviewed&src=category-new
02-10 14:56:06.085 E/GeckoConsole( 5041): [nav] Setting scroll to 99
02-10 14:56:06.090 D/GeckoTabs( 5041): handleMessage: DOMTitleChanged
02-10 14:56:06.115 E/GeckoConsole( 5041): [JavaScript Warning: "Content Security Policy: The page's settings blocked the loading of a resource at https://www.google-analytics.com/collect?v=1&_v=j16&a=261088610&t=pageview&_s=2&dl=https%3A%2F%2Fmarketplace-dev.allizom.org%2F&dp=%2F%3Fsort%3Dreviewed%26src%3Dcategory-new&ul=en-us&de=UTF-8&dt=Firefox%20Marketplace&sd=24-bit&sr=320x533&vp=320x460&je=0&_utma=117863061.441600063.1356035187.1391977896.1392071077.41&_utmz=117863061.1356035187.1.1.utmcsr%3D(direct)%7Cutmccn%3D(direct)%7Cutmcmd%3D(none)&_utmht=1392072965958&_u=eIAC~&cid=ho0togv9.ikk&tid=UA-36116321-11&z=165332905 ("img-src https://marketplace-dev.allizom.org:443 http://dev1.addons.phx1.mozilla.com:80 https://www.google.com:443 https://mozorg.cdn.mozilla.net:443 http://mozorg.cdn.mozilla.net:80 https://www.getpersonas.com:443 https://ssl.google-analytics.com:443 http://www.google-analytics.com:80 data://*:* https://marketplace-dev-cdn.allizom.org:443")."]
02-10 14:56:06.225 E/GeckoConsole( 5041): [req] Request failed: GET 0

Comment 1

[krupa raj[:krupa]]

FYI, i kept the summary non-specific since i see this behavior on other pages as well

Comment 2

[krupa raj[:krupa]]

another example: Where search fails to find results upon searching for "hacker"

02-10 16:38:42.875 E/GeckoConsole( 5041): [req] GETing https://marketplace-dev.allizom.org/api/v1/apps/search/?_user=---&cache=1&dev=android&device=mobile&lang=en-US&q=hacker&region=us&vary=0
02-10 16:38:43.075 E/GeckoConsole( 5041): [req] Request failed: GET 0

Comment 3

[krupa raj[:krupa]]

homepage is blank:

02-10 17:03:22.275 E/GeckoConsole( 5041): [req] GETing https://marketplace-dev.allizom.org/api/v1/fireplace/search/featured/?_user=---&cache=1&cat=&dev=android&device=mobile&lang=en-US&region=us&vary=0
02-10 17:03:22.275 E/GeckoConsole( 5041): [nav] Setting scroll to 0
02-10 17:03:22.280 E/GeckoConsole( 5041): [nav] Navigation loop truncated: 
02-10 17:03:22.280 D/GeckoTabs( 5041): handleMessage: DOMTitleChanged
02-10 17:03:22.280 D/GeckoToolbar( 5041): onTabChanged: TITLE
02-10 17:03:22.285 D/GeckoBrowserApp( 5041): BrowserApp.onTabChanged: 5: TITLE
02-10 17:03:22.380 E/GeckoConsole( 5041): [req] Request failed: GET 0

This is usually indicative of bad connectivity but i have no issues with other sites and other people are also hitting what may be the same issue. See bug 960235

Comment 4

[Kevin Ngo [:ngoke]]

Switching new tab triggers page rebuild, which probably aborts all GET requests.

Marking dupe with another "switching tab breaks Fireplace" bug.

Comment 5

[krupa raj[:krupa]]

Many of the usecases listed in this bug are still happening. Particularly, switching between tabs Popular/New cause both tabs to disappear.

Comment 6

[Kevin Ngo [:ngoke]]

This is on Firefox for Android, and has been reproducing from before bug 960235, right?

Comment 7

[Andy McKay]

This is causing multiple failures on Android so bumping up in priority.

Comment 8

[Kevin Ngo [:ngoke]]

May I have a screencast? I'm playing with an Android tablet and having troubles reproducing.

Comment 9

[krupa raj[:krupa]]

One more -  clicking on 'More' link

02-13 15:37:01.418 E/GeckoConsole(22339): [req] GETing https://marketplace-dev.allizom.org/api/v1/fireplace/search/featured/?lang=en-US&region=us&cache=1&vary=0&dev=android&cat=games&limit=25&offset=100&device=mobile&_bust=1392332733159
02-13 15:37:01.618 E/GeckoConsole(22339): [req] Request failed: GET 0

Comment 10

[krupa raj[:krupa]]

Attachment: screencast for empty categories

ashes: 23128

Comment 11

[krupa raj[:krupa]]

Attachment: the disappearing New tab

Comment 12

[Kevin Ngo [:ngoke]]

Thanks for the screencasts, Krupa.

Comment 14

[Andy McKay]

We can't reproduce this anymore, see also bug 977704.

Comment 16

[Andy McKay]

krupa said: For the first time i hit 970641 on my firefoxos phone which proves it is not an android issue :(

Comment 17

[Dethe Elza [:dethe]]

Still digging on this, but having harder time reproducing.

Comment 18

[Andy McKay]

The fact that it occurs in Firefox OS suggests this might not be a platform bug.

Comment 19

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

Perhaps not, but FxOS uses the same platform, so it could still be one.  Knowing the specific version of Gecko on the FxOS installation where this was reproduced would be helpful.

Comment 20

[Kevin Ngo [:ngoke]]

I'm taking a stab at this request caching bug, I can reproduce on Fireplace/Yogafire.

Comment 21

[Christopher Van Wiemeersch [:cvan]]

Keep in mind this happened before we started adding client-side localStorage requests.js caching.

Comment 22

[Kevin Ngo [:ngoke]]

But there was still in-memory caching. I believe something wrong happens when we try to GET from that.

Comment 23

[Christopher Van Wiemeersch [:cvan]]

Gotcha

Comment 25

[Andy McKay]

I don't know if its possible, but a concern here is that network requests will fail, they fail all the time. Should we be doing anything specific *when* network requests fail, a little "Problem connecting to server" toast popup (maybe with a lock on it so that you only get one message when 20 requests fail).

Comment 26

[Kevin Ngo [:ngoke]]

I had a brief idea that we retry GET 0 requests when they fail, but it's a bit tough to hook into the system of promises.

Comment 27

[Kevin Ngo [:ngoke]]

Here is what I know so far:

The main suspect is sporadic CORS failures. This is evidenced by the HTTP status of 0, the readyState of 4, empty responseText, and occasional reporting by the console that the request was blocked due to CORS. It is sporadic because the request sometimes gets through after re-navigating to re-fire the request or after implementing request retries that fail on status 0.

At least in Commonplace, we sometimes get a status 0 when attempting to request a page that shows a 404 or 500 in the browser. Examples are https://marketplace-dev.mozflare.net/media/docs/privacy/hi-IN.html?20140419 404s, but requesting it through require('requests').get returns status 0. Or fetching an API resource through the CDN such as https://marketplace-dev.mozflare.net/api/v1/fireplace/search/?cache=1&carrier=deutsche_telekom&dev=firefoxos&device=firefoxos&lang=hi-IN&limit=10&offset=70&q=&region=us&tag=tarako&vary=0 that hasn't been cached returns a 500 in the browser, but requesting it through require('requests').get returns status 0.

In Tarako, we implemented retries in case this issue arises. On our last try, it took Krupa 20 minutes of browsing to run into the issue, and when it did, the retried request successful returned after the first one ended in a status 0.

Another thing we tried was setting mozSystem to true on XHRs (XMLHttpRequest({mozSystem: true})). mozSystem pretty much allows cross-domain requests without requiring the server to opt-in with CORS. This only works for privileged packaged apps. Once setting this, 404 pages actually returned 404, and I could request pages such as http://google.com which would normally be blocked by CORS. We did not try it out any further, but it is obviously not the most ideal solution.

My most recent STR was to hit the search page with an empty query and keep on clicking "More". Once the offset hit 70, the page 500'ed (and in the meantime showed status 0). Although now the page no longer 200s and everything works fine. Some kind of API -> CDN hiccup. 

For now, we can at least uplift the retrying as a workaround.

Ashes:

85d00
afce8
23128

Evidenced logs:

Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at https://marketplace-dev-cdn.allizom.org/api/v1/fireplace/search/featured/?cache=1&cat=tarako-games&lang=en-US&limit=10&offset=10&region=us&tag=tarako&vary=0. This can be fixed by moving the resource to the same domain or enabling CORS.

CORS error: http://imgur.com/plMwTMZ.jpg

Full XHR object: http://imgur.com/xIBafGc.jpg

Related bugs:

https://bugzilla.mozilla.org/show_bug.cgi?id=1003005

Comment 28

[Kevin Ngo [:ngoke]]

I've seen from other projects that although the console notes the failure as a 0 status, the backend is actually a 500. There might be something wrong with the logging itself.

I've seen the dev CDN fail with a 500, it get reported as 0, and then it would fix itself, and then stuff would work again. This might be the cause of the "intermittency".

Comment 29

[Mathieu Pillard [:mat]]

If it's really a 500, then maybe we don't correctly apply CORS to it and that would explain the 0 status.

Comment 30

[Kevin Ngo [:ngoke]]

We're going to spin off a new bug to CORS our 500s. Don't think this bug is a problem anymore?