795547 - At first time, doesn't start rendering of the page (http://www.jaxa.jp/)

Status: RESOLVED WORKSFORME

(Core :: Networking: HTTP, defect)

Description

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

I'm not sure which component's bug, but looks like similar to bug 730760. So, I'm ccing bz.

Go to http://www.jaxa.jp/

Then, even though the HTML document is completely loaded (can see the source with the source viewer), the rendering wouldn't start. Then, I can see following error on the Web Console:

> [12:13:56.871] GET http://www.jaxa.jp/shared/js/htv3_rss.js [HTTP/1.1 404 Not Found 302671ms]

The source code around this is:

<script src="/shared/js/htv3_rss.js" type="text/javascript">
</script>
<script src="/shared/js/hoshide_rss.js" type="text/javascript">
</script>

And 5mins later, the rendering was performed. Then, I can see following log in the next line:

> [12:18:59.685] GET http://www.google-analytics.com/__utm.gif?utmwv=5.3.6&utms=6&utmn=1034334835&utmhn=www.jaxa.jp&utmcs=Shift_JIS&utmsr=1920x1080&utmvp=1259x527&utmsc=24-bit&utmul=ja&utmje=0&utmfl=11.4%20r402&utmdt=JAXA%EF%BD%9C%E5%AE%87%E5%AE%99%E8%88%AA%E7%A9%BA%E7%A0%94%E7%A9%B6%E9%96%8B%E7%99%BA%E6%A9%9F%E6%A7%8B&utmhid=2145385566&utmr=http%3A%2F%2Finput.mozilla.org%2Fja%2F%3Fq%3D%26product%3Dfirefox%26version%3D--%26date_start%3D%26date_end%3D%26locale%3Dja&utmp=%2F&utmac=UA-5278794-1&utmcc=__utma%3D54187187.842422833.1348888059.1348888059.1348888059.1%3B%2B__utmz%3D54187187.1348888059.1.1.utmcsr%3Dinput.mozilla.org%7Cutmccn%3D(referral)%7Cutmcmd%3Dreferral%7Cutmcct%3D%2Fja%2F%3B&utmu=D~ [HTTP/1.1 200 OK 17ms]

If you have cache for this site, you cannot see this bug.

This is reported via fxinput.
http://input.mozilla.org/opinion/3234356

Comment 1

[Boris Zbarsky [:bzbarsky]]

> [12:13:56.871] GET http://www.jaxa.jp/shared/js/htv3_rss.js [HTTP/1.1 404 Not Found
> 302671ms]

Hmm...  I see it come in near-instantly with wget or in Chrome.  Why is it taking us 5 minutes to decide that its's a 404?  Smells like some sort of timeout getting hit, and therefore a networking issue...

Patrick, ideas?

Comment 2

[Boris Zbarsky [:bzbarsky]]

But yes, given the really slow response rendering is blocked on that script....

Comment 3

[Alice0775 White]

Regression window:
Good:
http://hg.mozilla.org/mozilla-central/rev/7d7d075d58a3
Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US; rv:1.9.1b2pre) Gecko/20081111 Shiretoko/3.1b2pre ID:20081111032821
Bad:
http://hg.mozilla.org/mozilla-central/rev/8242c6adbf63
Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US; rv:1.9.1b2pre) Gecko/20081112 Namoroka/3.1b2pre ID:20081112034733
Pushlog:
http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=7d7d075d58a3&tochange=8242c6adbf63

Suspected:
db2dd52d47c1	Blake Kaplan — Bug 458440 - Turn speculative parsing back on and clean up the code a little. r+sr=jst

Comment 4

[Alice0775 White]

I confirmed in local build,
Last Good: d11e76e6fab9
First Bad: db2dd52d47c1

Comment 5

[Boris Zbarsky [:bzbarsky]]

That's really odd.  Why would speculative parsing affect this?

Comment 6

[Alice0775 White]

Umm,
If I disable cache, The page is displayed instantly in Firefox15.0.1 and Nightly18.0a1 as well.

browser.cache.memory.enable;false
browser.cache.disk_cache_ssl;false
browser.cache.disk.enable;false

Comment 7

[Boris Zbarsky [:bzbarsky]]

Hmm.  Is it possible that if our speculative fetch gets a really slow response somehow it locks the cache and then the real fetch can't go?  That still leaves the question of why the speculative fetch has a slow response.  And why we don't coalesce them in the scriptloader, if that's what's going on.

Comment 8

[Alice0775 White]

FYI, 
The description of Comment #3 and Comment#4 is for first load...
When I try to open the page in a 2nd new tab, it is reproduced in a "Good"build.

Comment 9

[Alice0775 White]

Attachment: sample html (depend on www.jaxa.jp/shared/js/htv3_rss.js)

Comment 10

[Alice0775 White]

Attachment: HTTP Log when I opened attached sample html

(https://developer.mozilla.org/en-US/docs/HTTP_Logging#Windows)

Comment 11

[Patrick McManus [:mcmanus]]

nick and michal are the cache experts..

Comment 12

[Brian Smith (:briansmith, :bsmith, use NEEDINFO?)]

(In reply to Boris Zbarsky (:bz) from comment #7)
> Hmm.  Is it possible that if our speculative fetch gets a really slow
> response somehow it locks the cache and then the real fetch can't go?  That
> still leaves the question of why the speculative fetch has a slow response. 
> And why we don't coalesce them in the scriptloader, if that's what's going
> on.

If we have to requests, A and B, that try to load the same resource, and request A opens a cache entry, then request B will wait for request A to mark the cache entry as "valid" before request B can read from the cache. If request A has to validate the entry (If-Last-Modified, If-None-Match), then it won't mark that entry valid until it gets a response back. If it gets a cacheable response back, then it won't mark the entry valid until it has received, and written to the cache, the entire response. The whole time, request B will be there, waiting for request A to say "OK, go ahead and use that cache entry."

Comment 13

[Boris Zbarsky [:bzbarsky]]

Sure.  The question is why request A is taking 5 minutes.  It shouldn't.

Comment 14

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

Now, I cannot reproduce this bug. If this is hidden by the website side and we still have this bug, feel free to reopen this bug.