Page loading is slow on certain site due to NSS upgrade

RESOLVED INCOMPLETE

Status

()

RESOLVED INCOMPLETE
7 years ago
3 years ago

People

(Reporter: alice0775, Unassigned)

Tracking

({regression})

10 Branch
x86
All
regression
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

(URL)

Attachments

(2 attachments, 1 obsolete attachment)

667.35 KB, application/zip
Details
536.26 KB, text/plain
Details
(Reporter)

Description

7 years ago
Build Identifier:
http://hg.mozilla.org/mozilla-central/rev/9989b866c3a8
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:14.0) Gecko/20120320 Firefox/14.0a1 ID:20120320091259

I encounter a problem when I test Bug 738006
Page loading is slow on certain site.


Reproducible: Always

Steps to Reproduce:
1. Start Firefox with new profile + clear cache
2. Open https://www.vodafone.ro/personal/telefoane-si-abonamente/telefoane/toate-telefoanele/index.htm

Actual Results:
 Page loading is slow.
 Complete within 20-30 sec sec(FTTH 100Mbps)

Expected Results:  
 Page load quickly.

Regression window:
Complete within 20-30 sec:
http://hg.mozilla.org/mozilla-central/rev/35954e6f3167
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:10.0a1) Gecko/20111007 Firefox/10.0a1 ID:20111007120745
More than 40 sec:
http://hg.mozilla.org/mozilla-central/rev/8f011395145e
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:10.0a1) Gecko/20111007 Firefox/10.0a1 ID:20111007144324
Pushlog:
http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=35954e6f3167&tochange=8f011395145e

Triggered by:
8f011395145e	Brian Smith — Bug 669061: Upgrade to NSS 3.13 RC0, r=wtc
(Reporter)

Updated

7 years ago
OS: Windows 7 → All
Component: Networking → Security: PSM
QA Contact: networking → psm
Summary: Page loading is slow on certain site → Page loading is slow on certain site due to NSS upgrade
(Reporter)

Comment 1

7 years ago
Created attachment 608285 [details]
HTTP Log

I capture HTTP activity in Nightly 14.0a1 by https://developer.mozilla.org/en/HTTP_Logging
(Reporter)

Comment 2

7 years ago
Created attachment 608293 [details]
HTTP log

log9.0.txt for Firefox9 --- (Page loading is fast)
log14.0a1.txt for Nightly14.0a1 --- (Page loading is remarkably slow and slooooow)
Attachment #608285 - Attachment is obsolete: true

Comment 3

7 years ago
Comment on attachment 608293 [details]
HTTP log

From the log file, the bottleneck seems to be related to repeatedly reaching the active connection limit and queuing the requests ad infinitum 

Example (this section is repeated many many times):

-1247806608[b7547c10]: nsHttpConnectionMgr::GetConnection [ci = .S.www.vodafone.ro:443]at active connection limit - will queue
-1247806608[b7547c10]: nsHttpConnectionMgr::GetConnection [ci=.S.www.vodafone.ro:443 caps=21]
-1247806608[b7547c10]: nsHttpConnectionMgr::AtActiveConnectionLimit [ci=.S.www.vodafone.ro:443 caps=21]
-1247806608[b7547c10]:    total=7, persist=6
(In reply to Bogdan Bocse from comment #3)
> Comment on attachment 608293 [details]
> HTTP log
> 
> From the log file, the bottleneck seems to be related to repeatedly reaching
> the active connection limit and queuing the requests ad infinitum 
> 

that part is pretty normal. Average page has 80+ resources and we can only move 6 at a time per hostname, so most page loads go through a period where they are bottlenecked by the active connection limit.

the issue is pretty easy to reproduce - that page is really painful for me too. (though I haven't confirmed that 9 is faster).

Comment 5

7 years ago
(In reply to Patrick McManus [:mcmanus] from comment #4)
> (In reply to Bogdan Bocse from comment #3)
> > Comment on attachment 608293 [details]
> > HTTP log
> > 
> > From the log file, the bottleneck seems to be related to repeatedly reaching
> > the active connection limit and queuing the requests ad infinitum 
> > 
> 
> that part is pretty normal. Average page has 80+ resources and we can only
> move 6 at a time per hostname, so most page loads go through a period where
> they are bottlenecked by the active connection limit.
> 
> the issue is pretty easy to reproduce - that page is really painful for me
> too. (though I haven't confirmed that 9 is faster).

Indeed you are right, Patrick.
However in the logs sent by Alice I've noticed that:
For FF 9 there are 873 occurrences of "at active connection limit - will queue"
and
For FF14 there are 14078 occurences of "at active connection limit - will queue"

In my view, that clearly indicates a problem with reaching the connection limit waaaaaay to often :)
(In reply to Bogdan Bocse from comment #5)

> Indeed you are right, Patrick.
> However in the logs sent by Alice I've noticed that:
> For FF 9 there are 873 occurrences of "at active connection limit - will
> queue"
> and
> For FF14 there are 14078 occurences of "at active connection limit - will
> queue"
> 
> In my view, that clearly indicates a problem with reaching the connection
> limit waaaaaay to often :)

I'm open to anything - but I think it probably just means the connection is alive for longer so it sees these scheduling events (and then logs a lot) more with deeper queues.

we'll see.. I assume brian will want to look at nss possibilities first, all I'm saying is that part of the log doesn't strike me a priori as a problem.
It would be nice to use the visual profiler to investigate on this...

Comment 8

7 years ago
Could this in anyway be related to having keepalive active?
Would disabling keepalive solve this issue?
(Reporter)

Comment 9

7 years ago
(In reply to Bogdan Bocse from comment #8)
> Could this in anyway be related to having keepalive active?
> Would disabling keepalive solve this issue?

I set network.http.keep-alive to false.
And then it fixed!  Page loading is fast as Firefox9.

Comment 10

7 years ago
Thanks for the confirmation, Alice. That sounds like great news!
For those interested, the profiler visualization (opt m-c build [no pipelining patches yet], clean profile, cache removed before load):

Load with keep-alive enabled (~5800ms): http://www.janbambas.cz/moz/profiler/?logs/vodafone-long-load-keep-alive.txt

Load with keep-alive disabled (~2700ms): http://www.janbambas.cz/moz/profiler/?logs/vodafone-long-load-no-keep-alive.txt
Note: I did 3 runs of loads with and without keep-alive enabled each and there seems to be just a very little of jitter between each run.  So the timings are probably quit precise.
there is a different amount of parallelism allowed when KA is off.. so it might just be a workaround rather than a root issue.
(In reply to Patrick McManus [:mcmanus] from comment #13)
> there is a different amount of parallelism allowed when KA is off.. so it
> might just be a workaround rather than a root issue.

Changing network.http.max-persistent-connections-per-server to 15 changes the load time to 5233ms (the same scenario).

There is something else here, and I'd like to figure out what.
Perhaps, we are now doing a bunch of SSL handshakes for the subresources whereas before we were only doing one. (Previously, we could only do one SSL handshake at a time, but now we can do up to five.)

I am not going to work on this bug until April 1.

Comment 16

6 years ago
Created attachment 625129 [details]
HTTP Log

I'm seeing this on a ssl internal site.  It takes forever (20+ seconds) to make the first request to get the bare HTML of the page.  I opened wireshark and had it watch the traffic and I can see the ssl handshake and then nothing for 20+ seconds.  After the long wait, Nightly (v15) finally sends the GET request and the page quickly renders.  After the first request, most of the other requests (images, scripts, css) run fine but every now and then one of them hangs as well.  Refreshing the page shows this happening about 1 every 5 requests.

I've grabbed the HTTP log and I'm attaching it.  I only one tab with the ssl site set to automatically open.  You can near the top a 30 second span of "canceling pipeline due to a Xms stall - depth 1".  After 30 seconds, it cancels the transaction and then the page loads.

Comment 17

3 years ago
Is this still an issue? The URL loads quickly for me in a fresh profile on a DevEdition 46 build.
Flags: needinfo?(alice0775)
(Reporter)

Comment 18

3 years ago
The site changed their contents. So, no longer be able to test this.
Status: NEW → RESOLVED
Last Resolved: 3 years ago
Flags: needinfo?(alice0775)
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.