940998 - Firefox 28.0a1: Using proxy, many web pages never finish loading

Status: RESOLVED WORKSFORME

(Core :: Networking, defect)

Description

[Al Dunsmuir]

User Agent: Mozilla/5.0 (Windows NT 5.1; rv:25.0) Gecko/20100101 Firefox/25.0 (Beta/Release)
Build ID: 20131112160018

Steps to reproduce:

We access external internet at RBC via a proxy.

I use the nightly Mozilla 32-bit windows build, currently 28.0a1 (2013-11-20).
Since about a week ago, nearly all external web pages never complete loading.  

Examples:
https://www.google.ca
- Displays page, but continues with rotating green loading indicator, and the
  status message "Waiting for www.gstatic.com".
http://forums.mozillazine.org
- Search board for "proxy" never gets to the point of displaying search results

Same setup works great using Firefox release version (25.0.1).  

Same nightly works for local pages, and at home (64-bit and 32-bit, but no proxy) just fine so I suspect that the proxy support in nightly is not currently working correctly.


Actual results:

Web pages accessed via proxy may or may display... but the rotating green loading indicator keeps on a-rotating and the page never finishes loading.


Expected results:

Display page... finish.

Comment 1

[Patrick McManus [:mcmanus]]

need this:

https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging?redirectlocale=en-US&redirectslug=HTTP_Logging

Comment 2

[Al Dunsmuir]

Attachment: log.txt file, output from HTTP logging procedure (1,844,161 bytes!)

Comment 3

[Al Dunsmuir]

By the way, I encounter the same issue connecting to https://bugzilla.mozilla.org to view this bug.

Comment 4

[Patrick McManus [:mcmanus]]

you're using a rfc1918 addressed proxy - which would point at bug 853423 as a guess. It was also checked in nov 11th, so that would also match your bug report.

Later on I'll identify two builds for you to test to confirm.

Comment 5

[Patrick McManus [:mcmanus]]

Al, I just started some try builds with 853423 backed out of them for you to test.. when they are done in a few hours they can be downloaded from here:

http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/[e-mail]-46699c39593c

can you test one out and let this bug know if it works ok for you (and confirm that the latest nightly is still broken)?

Thanks for the report and the help.

Comment 6

[Al Dunsmuir]

Patrick,

I was off sick with the flu... now back in the office.

I installed firefox-28.0a1.en-US.win32.installer.exe on my desktop (as NightyFix, in parallel with regular Nighly and 25.0.1).  It exhibits the same symptoms as I reported, as does the current nightly build.  Do you need another capture?

Note that I will be working from home on Friday and Monday, with no access to proxied desktop.
Al

Comment 7

[Patrick McManus [:mcmanus]]

I guess I do need another capture.

use the firefox-28 "nightlyfix" that you downloaded. Make certain no other copy of firefox of any version is running when you start it.

Can you please test just this bugzilla URL that illustrates the problem? That will create a considerably simpler log (and hopefully easier to identify the issue). Also please describe the issue you are seeing wrt the bugzilla url in detail again - I'm not sure if its a matter of not loading, partly loading, fully loading but still spinning etc..

thanks!

Comment 8

[Al Dunsmuir]

Will do capture using "https://bugzilla.mozilla.org/show_bug.cgi?id=940998".

Comment 9

[Al Dunsmuir]

Attachment: Tab 1: Google, Tab 2: Mozilla bugzilla for bug 940998

I verified that NightlyFix has problem without tracing.
Exited, started up again:
- Tab1: www.google.ca home page
        Green clockwise circle network animation in tab remains active
        Lower left has "waiting for" msg
        Page is fully drawn
        Accepts focus on query line
- Opened Tab2: (this bugzilla url)
        Green animation in tab remains active
        Lower left has "waiting for bugzilla.mozilla.org"
        Page is clear - no elements drawn!

Comment 10

[Al Dunsmuir]

I hope the new log helps illuminate the problem area.  

If necessary, I can change home page to this bug to get simpler log.txt file.

Comment 11

[Patrick McManus [:mcmanus]]

Thanks Al - that helps some. I'm sorry its not obvious what is going on. That's a good test case though - it helps illustrate the problem:

a] we connect to the proxy and do a CONNECT for bugzilla.mozilla.org.. the proxy replies with a 407 (auth required) and a connection close.
b] We then call nsHttpTransaction::Close(), which should call mPipeOut->CloseWithStatus()
c] Closing that pipe should trigger nsHttpChannel::onStopRequest().. which is the code that figures out you need fancy windows integrated auth and retries everything based on the challenge in the 407. But OnStopRequest() is clearly not being called

I don't know why. So I'm going to ask you to try a bunch of nightlies to find the first one that fails for you. Then I can at least look at a fairly small amount of code that went into that build. Is that cool?

you can find the november nightlies here:
http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2013/11/

you want the ones labeled like 2013-11-01-03-02-05-mozilla-central/

it seems like you have a decent idea of when this started, so hopefully you'll only need to try a few. Wish I could reproduce it for you :(

Thanks!

Comment 12

[Josh Matthews [:jdm]]

Using the mozregression tool (http://mozilla.github.io/mozregression/) should be easier than downloading nightlies manually.

Comment 13

[Al Dunsmuir]

Network access is pretty restricted, so I will do binary search with 2013-11-10 as a starting point.

Comment 14

[Al Dunsmuir]

You are SO not going to expect this news.

I got failures on 2013/11/10 and 2013/11/01 so went back to October.
I got failures on 2013/10/31, 2013/10/28 AND 2013/10/01.

I initially figured that it was something related to a 28 change, or the 27->28 transition but 27 is also affected!  

Since FF 25 works fine, I suspect that they installed an updated proxy (version, vendor, or config) around November 10th and FF 27/27 Nightlies are incompatible with THAT.  I need to check a recent FF26.

Hmmmm. maybe related to 27->28 transition.  2013/10/

Comment 15

[Al Dunsmuir]

Trying http://ftp.mozilla.org/pub/mozilla.org/firefox/candidates/26.0-candidates/build1/win32/en-US/Firefox Setup 26.0.exe next.

Comment 16

[Al Dunsmuir]

The 26.0 candidate works fine... whew.

It looks like the RBC networking folks changed something in our proxy that happens to give FF 27 and 28 heartburn.   I tend to use nightly all the time, and only temporarily revert to the release version when I see on a news site that a new release level has been released.

Unfortunately, this sounds like it's going to take a bit more work to find out what is going on than a simple regression in the Firefox codebase.

Comment 17

[Al Dunsmuir]

In the comment 2013-12-04 09:47:46 PST, ignore the line starting with "Hmmmm.".  
Leftovers from thinking "out loud".

Comment 18

[Patrick McManus [:mcmanus]]

Thanks Al. I'll make you a special build chock full of annotations to see if we can't get a better idea of the problem. It might take me a bit of time to do it.

Comment 19

[Al Dunsmuir]

Thank YOU Patrick!

I leave work by 13:45 EST today, and will be back in the office on Tuesday morning.

Comment 20

[Patrick McManus [:mcmanus]]

for my own notes - al's log doesn't have onstart OR onstop for the transaction in question.

Comment 21

[Patrick McManus [:mcmanus]]

Al, when you make your next log (comment 1) can you use this modules list instead of the one on the documentation page? (it's a little more data)

nsHttp:5,nsSocketTransport:5,nsHostResolver:5,nsWebSocket:4,nsStreamPump:5,nsPipe:5,timestamp

Comment 22

[Patrick McManus [:mcmanus]]

Al, when you get a chance a new annotated ff28 build will be here
https://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/[e-mail]-aa6880fb80de/

the log file from that (comment 21) will be interesting.. maybe even helpful too :)

Comment 23

[Al Dunsmuir]

Attachment: log.zip is the zipped log.txt

12.5 MB log created using your debug build and new options.
- Had to zip (now 680KB) as it exceeded Bugzilla 10 MB limit

Tab1: Google.ca
      - Fully displayed, never stops green network icon rotation
Tab2: Bugzilla for this bug
      - Not displayed (even after 15 secs), icon still spinning

Comment 24

[Patrick McManus [:mcmanus]]

Hey al - I think you didn't change the logging line in the way I asked from comment 21.. I say that because there are no nsPipe log statements in your log - and that's what I'm interested in seeing.

the log you provided allowed me to rule a couple things out, but didn't really point its finger at anything new.

if you don't use google.ca in your case your log will be a lot smaller - and I'm really only interested in the bugzilla bit anyhow.

-P

Comment 25

[Al Dunsmuir]

****.  I thought I did it correctly, but there was likely a typo - I've been fighting a cold/flu for the last 2 weeks.

I'll change my home page to this defect, and redo.

Comment 26

[Al Dunsmuir]

Attachment: Tab1: Mozilla bugzilla (only)

I hope I got it right this time 8^)

Comment 27

[Patrick McManus [:mcmanus]]

Thanks al - that is weird that I'm still not seeing the right info.

to confirm:
set NSPR_LOG_MODULES=timestamp,nsHttp:5,nsSocketTransport:5,nsStreamPump:5,nsHostResolver:5,nsPipe:5


Have you tried this with a clean profile?

Comment 28

[Al Dunsmuir]

In comment 21 you also had nsWebSocket:4 so that's in there too.

Comment 29

[Al Dunsmuir]

I reset the profile.  It worked!

I added back in NoScript and Linkificator add-ons.  It still works!

Comment 30

[Patrick McManus [:mcmanus]]

thanks al - I should have suggested that first.