Bug 37919 – [Qt] aviary.com loads slow

• Component: Page Loading
• Status: RESOLVED INVALID

[Markus Goetz]

I have not tested with using webkit trunk.

Firefox loads the page very fast.

[Jesus Sanchez-Palencia]

Reproduced on Snow Leopard with Qt 4.7 trunk (HEAD 03f8f1df0d88f5ffe0b3120cffce614cbeefdb70) and WebKit trunk (r59155).

[Ademar Reis]

Reproduced on Linux with Qt-4.7.2+ (b31b4c46e70401745572b808c916088afb839614) and qtwebkit trunk (r79900), the test browser basically hangs for a couple of minutes before anything is rendered (app is still reponsive though).

Loading from chrome/firefox is fast.

From Web Inspector, I see that it takes 2min to download this WebResource.axd file (a script with parameters):

GET http://www.aviary.com/apps/WebResource.axd?d=ucJE4LQHkjxbfFLZQ7RDN7Mx77t4T1Y1NIYEATEckcEVLh0OWT7jmbhPHvZoud9rApgriK1m5Wst7TME8ecRHFw0JOk1&t=634269766488712880 200 (OK)

And it's served as application/octet-stream intead of application/x-javascript:

WebResource.axd:-1 Resource interpreted as Script but transferred with MIME type application/octet-stream.

I don't know where to go from here. :-(

[Joe Wild]

I'd like to take a look at this one if no one is in the middle of it.
Feel free to assign to me.

So far I can see in Wireshark logs that it takes 2s to load this page in
Chrome and 30s in QtTestBrowser.  Another interesting thing in the
QtTestBrowser log is that there is a 30s gap in HTTP activity after
the 1st second of acivity.

A good guess may be WebResource.axd's involvement as mentioned in the
previous comment.

[Joe Wild]

"11:05:37.942" :<*JPW*> QNetworkReplyHandler::QNetworkReplyHandler() req url =  "http://www.aviary.com/apps/WebResource.axd?d=ucJE4LQHkjxbfFLZQ7RDN7Mx77t4T1Y1NIYEATEckcEVLh0OWT7jmbhPHvZoud9rApgriK1m5Wst7TME8ecRHFw0JOk1&t=634269766488712880" 
"11::05:37.942" :<*JPW*> QNetworkReplyHandler::start() req url =  "http://www.aviary.com/apps/WebResource.axd?d=ucJE4LQHkjxbfFLZQ7RDN7Mx77t4T1Y1NIYEATEckcEVLh0OWT7jmbhPHvZoud9rApgriK1m5Wst7TME8ecRHFw0JOk1&t=634269766488712880" 

"11:06:07.988" :<*JPW*> QNetworkReplyHandler::finish() req url =  "http://www.aviary.com/apps/WebResource.axd?d=ucJE4LQHkjxbfFLZQ7RDN7Mx77t4T1Y1NIYEATEckcEVLh0OWT7jmbhPHvZoud9rApgriK1m5Wst7TME8ecRHFw0JOk1&t=634269766488712880"  reply url =  "http://www.aviary.com/apps/WebResource.axd?d=ucJE4LQHkjxbfFLZQ7RDN7Mx77t4T1Y1NIYEATEckcEVLh0OWT7jmbhPHvZoud9rApgriK1m5Wst7TME8ecRHFw0JOk1&t=634269766488712880" 
  contentTypeHeader =  "" 
  bytesAvailable =  0 
  header:  Cache-Control  =  public 
  header:  Date  =  Tue, 08 Mar 2011 22:59:25 GMT 
  header:  Expires  =  Wed, 07 Mar 2012 15:48:52 GMT 
  header:  Last-Modified  =  Fri, 03 Dec 2010 17:37:28 GMT 
  header:  Server  =  Microsoft-IIS/6.0 
  header:  Vary  =  Accept-Encoding 
  header:  X-AspNet-Version  =  2.0.50727 
  header:  X-Compressed-By  =  FluorineHttpCompress 
  header:  X-Powered-By  =  ASP.NET 
  header:  Connection  =  Keep-Alive 
  header:  Content-Encoding  =  gzip 
  header:  Age  =  147870 


If we can believe my traces, it takes > 30s to return 
WebResource.axd with no bytes or content type.  Wonder
if this is a server side issue.

Also, I don't see any data coming through for WebResource.axd for
ResourceLoader::addData().  So maybe this does come through late and
empty.  Not sure I believe it yet.

[Joe Wild]

Created attachment 85619 [details]
Log file of aviary.com load without WebResource.axd.

Log file.

I think I finally have a handle on what is going on here.  The problem
seems to be below WebKit in the loader levels.  And I'm not quite
sure of where to assign this error or even if it is an error.

I would guess there is some limitation on the number of outstanding
load requests, open connections, or whatever that make this page take
so long to load.

It turns out that the load request to a supposed Javascript file
WebResource.axd takes 30 or more seconds to return empty content.
While we are waiting for that page, other loading is at a stand still.

Once I finally figurued out how to keep this load request from being
issued, the page loads in a pretty reasonable time.

I added the following to 

Source/WebCore/loader/ResourceLoadScheduler.cpp
PassRefPtr<SubresourceLoader> ResourceLoadScheduler::scheduleSubresourceLoad(Frame* frame, SubresourceLoaderClient* client, const ResourceRequest& request, ResourceLoadPriority priority, SecurityCheckPolicy securityCheck, bool sendResourceLoadCallbacks, bool shouldContentSniff)
{
---
    if ( url.contains("WebResource") ) {
        qDebug() << "    <*JPW*>  ResourceLoadScheduler::scheduleSubresourceLoad skip WebResource.axd load";
        return 0;
    } 

Without WebResource.axd, the page loads in about 6 seconds and
makes steady progress all along the way. Attached is the full
log file, aviary_load_log01.txt

[Laszlo Gombos]

Joe, would increasing initializeMaximumHTTPConnectionCountPerHost() in ResourceRequestQt.cpp help ?

[Joe Wild]

I wanted to add some more information.

First, I tried to replicate the User Agent String and HTTP Headers as
Google Chromium uses and that did not affect the problem.

Second, I tried to increase the session and channel counts in
the WebKit and the Qt network code with little increase
in performance. 

  ./WebCore/platform/network/qt/ResourceRequestQt.cpp:40:unsigned
  initializeMaximumHTTPConnectionCountPerHost()


  ...qt/src/network/access/qhttpnetworkconnection.cpp
  const int QHttpNetworkConnectionPrivate::defaultChannelCount = 6;

May be some hard limit with lower level network stack I haven't 
figured out yet.  I'd like to see if can build Chromium Webkit
and compare the logs.

[Joe Wild]

This seems like a server-side problem or at least I may need some server-side
help to dig further.

What seems to be the problem is that the fetch of the following
external javascript takes 30 seconds on QtTestBrowser/WebKit.

  <script
  src="/apps/WebResource.axd?d=XBzH3H_Yx0wNM5ykooAgaA2&amp;t=634193708782958808"
  type="text/javascript">
  </script>

I understand the latest WebKit behavior is that external scripts are
executed in the order they appear in the input stream (HTML page in
this case).  So this could be the reason the page is paused for so long.
We could be waiting to execute the other external scripts after this one.

On both Firefox, Chromium, and QtTestBrowser/Webkit this HTTP Get
request comes back as an HTTP 200 with 0 bytes.  However, on both
Firefox and Chromium this response comes back in < 1s and on
QtTestBrowser/WebKit it takes 30s.

It's a little confusing to try to match my WebKit traces against the
HTTP traces on the other browsers with Wireshark and/or their Web Inspectors.
However, when I use the WebInspector on the QtTestBrower I also get
a 30s load time for WebResource.axd.

  WebResource.axd, GET, 200 OK, application/octet-stream, 0B, 31.08s

So is there anyway to investigate why it takes the server 30 seconds to
return this page on QtTestBrowser/WebKit?  Is there someone on the
www.aviary.com that could also investigate this issue?

[Andreas Kling]

I spent the morning digging into this and it turns out it's a bug in Qt. I've opened the following issue in the Qt JIRA to track it:

http://bugreports.qt.nokia.com/browse/QTBUG-18232

Closing this, since we don't need a change in WebKit.

[Andreas Kling]

I've pushed a fix for this to Qt master (4.8), e3df83e8735124dbd15107b0c083d75d99b98ea9

[Siddharth Mathur]

(In reply to comment #10)
> I've pushed a fix for this to Qt master (4.8), e3df83e8735124dbd15107b0c083d75d99b98ea9

Given the large number of devices we are shipping with 4.7 , it would be nice to have this for 4.7 too, no?

[Markus Goetz]

(In reply to comment #11)
> (In reply to comment #10)
> > I've pushed a fix for this to Qt master (4.8), e3df83e8735124dbd15107b0c083d75d99b98ea9
> 
> Given the large number of devices we are shipping with 4.7 , it would be nice to have this for 4.7 too, no?

No. Not for such a minor bug. 4.7 is reserved for really blocking stuff.