The default bug view has changed. See this FAQ.

HTTP CONNECT does not properly handle 302 error

RESOLVED FIXED in mozilla1.9.3a5

Status

()

Core
Networking: HTTP
RESOLVED FIXED
7 years ago
4 years ago

People

(Reporter: Ivan, Assigned: bz)

Tracking

(Depends on: 1 bug, {fixed1.9.0.20, regression})

Trunk
mozilla1.9.3a5
fixed1.9.0.20, regression
Points:
---
Dependency tree / graph
Bug Flags:
in-testsuite ?

Firefox Tracking Flags

(blocking2.0 betaN+, blocking1.9.2 needed, status1.9.2 .5-fixed, blocking1.9.1 needed, status1.9.1 .11-fixed)

Details

(URL)

Attachments

(4 attachments)

(Reporter)

Description

7 years ago
User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.2; ru; rv:1.9.2.3) Gecko/20100401 MRA 5.6 (build 03278) Firefox/3.6.3 (.NET CLR 3.5.30729)
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.2; ru; rv:1.9.2.3) Gecko/20100401 MRA 5.6 (build 03278) Firefox/3.6.3 (.NET CLR 3.5.30729)

RequestLine size=253 
===========================================
CONNECT ssl.google-analytics.com:443 HTTP/1.1
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.2; ru; rv:1.9.2.3) Gecko/20100401 MRA 5.6 (build 03278) Firefox/3.6.3 (.NET CLR 3.5.30729)
Proxy-Connection: keep-alive
Host: ssl.google-analytics.com


===============================================
RequestLine size=288 
===========================================
HTTP/1.0 302 Moved Temporarily
Server: squid/3.1.0.15
Mime-Version: 1.0
Date: Sat, 24 Apr 2010 08:19:11 GMT
Content-Type: text/html
Content-Length: 0
Location: http://firewall/clear.gif
X-Squid-Error: 403 Access Denied
X-Cache: MISS from Firewall
Proxy-Connection: keep-alive


===============================================


Reproducible: Always

Steps to Reproduce:
1. use squid as proxy, on squid deny google-analytics.com and set deny_info http://firewall/clear.gif

2. try to open any https page with content from google-analytics.com
Actual Results:  
browser infinite wait answer from ssl.google-analytics.com fnd page dos not displayed

Expected Results:  
show page without content from ssl.google-analytics.com
Something similar seems to happen when the proxy blocks ssl.google-analytics.com, so this might not be related to the 302 status at all.
Is Bug 544979 related here?
It looks like so.
(Reporter)

Comment 4

7 years ago
IE8 work fine: open page with no delay
Proxy redirect all blocked sites/pages to file clear.gif on local server "firewall", with http:// all works fine
What happens if you redirect to a https page ?
There are security restrictions for https proxy redirects that could cause this.
Blocking the page can block the rendering based on the script, that's normal.
(Reporter)

Comment 6

7 years ago
If i redirect to a https page happens infinite waiting for data.

Then proxy server restarted=connection close, FF request other files and display page.

Comment 7

7 years ago
Can you post a HTTP log for this problem - https://developer.mozilla.org/en/HTTP_Logging ? I'm seeing similar symptoms with squid replaced by a small snippet of python code, but would like to confirm it's the same issue.

(And trying to install and configure squid is not really something most people would want to do just to troubleshoot an edge case problem.)
Proxy redirects are disabled with bug 479880 but allowed again for http status codes with bug 491818 (if i read that right).

What happens if you redirect to a document with the right mime-type for a script ?
(Reporter)

Comment 9

7 years ago
Log sended to you by email.

I can give access to my proxy, or config files to squid and nginx
(Reporter)

Comment 10

7 years ago
I tryed without 

C( 257 bytes):
HTTP/1.0 302 Moved Temporarily
Server: squid/3.1.0.15
Mime-Version: 1.0
Date: Sat, 24 Apr 2010 14:21:29 GMT
Location: http://firewall/clear.gif
X-Squid-Error: 403 Access Denied
X-Cache: MISS from Firewall
Content-Length: 0
Connection: keep-alive


and with:
C( 297 bytes):
HTTP/1.0 302 Moved Temporarily
Server: squid/3.1.0.15
Mime-Version: 1.0
Date: Sat, 24 Apr 2010 14:25:06 GMT
Location: http://firewall/clear.gif
X-Squid-Error: 403 Access Denied
X-Cache: MISS from Firewall
Content-Type: application/x-javascript
Content-Length: 0
Connection: keep-alive


no affect :(

Comment 11

7 years ago
Created attachment 441303 [details]
hacked version of TinyHTTPProxy.py that returns constant response to CONNECT

Comment 12

7 years ago
Created attachment 441304 [details]
test page loading the google analytics script over HTTPS

From comparing HTTP logs, I think this testcase is close enough to the problem Ivan is seeing. To reproduce, run TinyHTTPProxy.py, set proxy in Firefox settings to 0.0.0.0:8000 for all protocols, then open this page via file:///

Comment 13

7 years ago
Created attachment 441305 [details]
HTTP logs

My and Ivan's logs.

Comment 14

7 years ago
The relevant part of the log in my testcase shows how Necko ends up calling nsScriptLoader::OnStreamComplete without aContext, which causes it to assert and drop the script load request, which I think should lead to the symptoms (script stuck in the loading state forever).

-1340452864[d553d0]: nsHttpTransaction::HandleContentStart [this=1db25fe0]
-1340452864[d553d0]: http response [
-1340452864[d553d0]:   HTTP/1.0 302 Moved Temporarily
...
-1340452864[d553d0]: SSL proxy CONNECT failed!
-1340452864[d553d0]: nsHttpTransaction::HandleContent [this=1db25fe0 count=0 read=0 mContentRead=0 mContentLength=0]
-1340452864[d553d0]: nsHttpConnection::CloseTransaction[this=db8fd0 trans=1db25fe0 reason=80470002]
-1340452864[d553d0]: nsHttpTransaction::Close [this=1db25fe0 reason=0]
...
-1607481568[d0a9b0]: sending status notification [this=1db25970 status=804b000a progress=0/0]
-1607481568[d0a9b0]: nsHttpChannel::OnStartRequest [this=1db25970 request=1e353480 status=0]
-1607481568[d0a9b0]: nsHttpChannel::ProcessResponse [this=1db25970 httpStatus=302]
-1607481568[d0a9b0]: Cancelling failed SSL proxy connection [this=1db25970 httpStatus=302]
-1607481568[d0a9b0]: nsHttpChannel::Cancel [this=1db25970 status=804b000d]
-1607481568[d0a9b0]: nsHttpConnectionMgr::CancelTransaction [trans=1db25fe0 reason=804b000d]
-1607481568[d0a9b0]: STS dispatch [dd0900]
-1340452864[d553d0]:     ...returned after 303213 milliseconds
-1340452864[d553d0]: nsHttpConnectionMgr::OnMsgCancelTransaction [trans=1db25fe0]
-1340452864[d553d0]: nsHttpTransaction::Close [this=1db25fe0 reason=804b000d]
-1340452864[d553d0]:   already closed
...
-1607481568[d0a9b0]: nsHttpChannel::OnStopRequest [this=1db25970 request=1e353480 status=804b000d]
-1607481568[d0a9b0]: nsHttpTransaction::DeleteSelfOnConsumerThread [this=1db25fe0]
-1607481568[d0a9b0]: Destroying nsHttpTransaction @1db25fe0
-1607481568[d0a9b0]: nsHttpChannel::FinalizeCacheEntry [this=1db25970]
-1607481568[d0a9b0]:   calling OnStopRequest
-1607481568[d0a9b0]: ###!!! ASSERTION: null request in stream complete handler: 'request', file /Users/nickolay/dev/mozilla-work/src/content/base/src/nsScriptLoader.cpp, line 989
-1607481568[d0a9b0]: WARNING: NS_ENSURE_TRUE(request) failed: file /Users/nickolay/dev/mozilla-work/src/content/base/src/nsScriptLoader.cpp, line 990

I'm not sure how this should be fixed, but when the proxy is down, the context is set at this stack:
#0	0x123bcadf in nsStreamLoader::OnStartRequest at nsStreamLoader.cpp:113
#1	0x1246df2b in nsHttpChannel::CallOnStartRequest at nsHttpChannel.cpp:824
#2	0x12474b1d in nsHttpChannel::OnStartRequest at nsHttpChannel.cpp:5210
#3	0x12385ade in nsInputStreamPump::OnStateStart at nsInputStreamPump.cpp:441
#4	0x123868a0 in nsInputStreamPump::OnInputStreamReady at nsInputStreamPump.cpp:397
#5	0x006ef088 in nsInputStreamReadyEvent::Run at nsStreamUtils.cpp:112
#6	0x00722d74 in nsThread::ProcessNextEvent at nsThread.cpp:527
#7	0x006a60ba in NS_ProcessPendingEvents_P at nsThreadUtils.cpp:200
#8	0x131868df in nsBaseAppShell::NativeEventCallback at nsBaseAppShell.cpp:125

and when it's up, but returning the 302 response, we end up here instead:
#0	0x1245f9bc in nsHttpChannel::ProcessFailedSSLConnect at nsHttpChannel.cpp:925
#1	0x124742ba in nsHttpChannel::ProcessResponse at nsHttpChannel.cpp:958
#2	0x124749bf in nsHttpChannel::OnStartRequest at nsHttpChannel.cpp:5181
#3	0x12385ade in nsInputStreamPump::OnStateStart at nsInputStreamPump.cpp:441
#4	0x123868a0 in nsInputStreamPump::OnInputStreamReady at nsInputStreamPump.cpp:397
#5	0x006ef088 in nsInputStreamReadyEvent::Run at nsStreamUtils.cpp:112

.. and never call nsStreamLoader::OnStartRequest, only calling nsStreamLoader::OnStopRequest (which has NULL context at this moment).

I think Necko is supposed to pass the correct context to nsScriptLoader. What I don't know is where the fix should be - should the stream loader have its OnStartRequest called by that point, or should it just pass the context from the channel (I haven't figured out why it's even stored yet). Biesi?
Severity: major → normal
Component: General → Networking: HTTP
Product: Firefox → Core
QA Contact: general → networking.http
Version: unspecified → Trunk
> and never call nsStreamLoader::OnStartRequest, only calling
> nsStreamLoader::OnStopRequest 

This would be a bug!  OnStartRequest is guaranteed to be called after AsyncOpen by the nsIChannel API.
I have no idea how to write tests for this.. But I can certainly confirm using steps from comment 12.  Looks like a regression from bug 491818.
Blocks: 491818
Status: UNCONFIRMED → NEW
Ever confirmed: true
Flags: in-testsuite?
Created attachment 441528 [details] [diff] [review]
Fix

I assume we need this on all the branches too, right?
Assignee: nobody → bzbarsky
Status: NEW → ASSIGNED
Attachment #441528 - Flags: review?(jduell.mcbugs)
Attachment #441528 - Flags: review?(jduell.mcbugs) → review+
Comment on attachment 441528 [details] [diff] [review]
Fix

D'oh!  Yup, totally my code and my fault.  Thanks to all for tracking it down.  And yes, this should be applied to all branches.
blocking1.9.1: --- → ?
blocking1.9.2: --- → ?
blocking2.0: --- → ?
status1.9.1: --- → ?
status1.9.2: --- → ?
Keywords: regression
OS: Windows Server 2003 → All
Hardware: x86_64 → All
Summary: HTTP CONNECT does not propertly handle 302 error → HTTP CONNECT does not properly handle 302 error
Drivers, this seems to be a regression from bug 491818, which in turn was a regression from bug 479880, which was an sg:high bug. It's a one line fix.
(In reply to comment #16)
> I have no idea how to write tests for this..

I guess httpd.js should be augmented to allow CONNECT requests.
blocking1.9.1: ? → needed
blocking1.9.2: ? → needed
status1.9.1: ? → wanted
status1.9.2: ? → wanted
Pushed http://hg.mozilla.org/mozilla-central/rev/d237da454ab7
Status: ASSIGNED → RESOLVED
Last Resolved: 7 years ago
Resolution: --- → FIXED
Comment on attachment 441528 [details] [diff] [review]
Fix

Requesting approvals for all affected branches.
Attachment #441528 - Flags: approval1.9.2.5?
Attachment #441528 - Flags: approval1.9.2.4?
Attachment #441528 - Flags: approval1.9.1.11?
Attachment #441528 - Flags: approval1.9.1.10?
Attachment #441528 - Flags: approval1.9.0.19?
Attachment #441528 - Flags: approval1.8.1.next?
Target Milestone: --- → mozilla1.9.3a5
Comment on attachment 441528 [details] [diff] [review]
Fix

a=beltzner for 1.9.1 and 1.9.2 default (not the relbranches, though) which map to the upcoming 1.9.2.5 and 1.9.1.11

Not sure to handle the request for 1.9.0.19 or 1.8.1.next at this time.
Attachment #441528 - Flags: approval1.9.2.4?
Attachment #441528 - Flags: approval1.9.2.4+
Attachment #441528 - Flags: approval1.9.1.11?
Attachment #441528 - Flags: approval1.9.1.11+
Attachment #441528 - Flags: approval1.9.1.10?
Attachment #441528 - Flags: approval1.9.1.10-
Comment on attachment 441528 [details] [diff] [review]
Fix

oops - setting flags appropriately
Attachment #441528 - Flags: approval1.9.2.5?
Attachment #441528 - Flags: approval1.9.2.5+
Attachment #441528 - Flags: approval1.9.2.4-
Attachment #441528 - Flags: approval1.9.2.4+
Depends on: 564081
Pushed:
 http://hg.mozilla.org/releases/mozilla-1.9.2/rev/a84d87dc5f1f
 http://hg.mozilla.org/releases/mozilla-1.9.1/rev/b1b05fd77e73
status1.9.1: wanted → .11-fixed
status1.9.2: wanted → .5-fixed
Attachment #441528 - Flags: approval1.9.0.19? → approval1.9.0.next?
Attachment #441528 - Flags: approval1.9.0.next?
Attachment #441528 - Flags: approval1.9.0.next?

Updated

7 years ago
Duplicate of this bug: 492459

Comment 27

7 years ago
Thank you, bz! (See bug 492459)

My problem is fixed (so VERIFIED as far as I'm concerned).

Comment 28

7 years ago
I have the impression that this bug is not completely fixed.
For example if I block etracker.com by my proxy (privoxy 3.0.16) , I cannot any longer access www.kreditkarte.at.
Firefox will wait forever for code.etracker.com

I am using Firefox 3.5.2 on Windows XP and Firefox 3.6.6 on Windows Vista.
Well, 3.5.2 would certainly not have this fix (and is at least 9 security updates out of date).  3.5.11 should.

For some reason the 1.9.2 repo is not showing the push from comment 25 at all.  But in any case, I _think_ it would have landed best-case in 1.9.2.7....
Looks like this actually landed on the 1.9.2 branch as http://hg.mozilla.org/releases/mozilla-1.9.2/rev/ba8960ab9acd

I still suspect that it'll be in 1.9.2.7, but I'm totally lost in our branch stuff now.

Comment 31

7 years ago
Tested also on 3.5.10. 
Also here https://www.kreditkarte.at cannot be accessed if etracker.com blocked via privoxy.
> Tested also on 3.5.10. 

_Please_ read comment 29.  The fix is in 3.5.11.  It's NOT in any earlier versions.  What made you think it was?

Comment 33

7 years ago
Is firefox 3.6.6 supposed to have this fix? It doesn't seem to.

Comment 34

7 years ago
Think I know why my proxy returns 405 errors rather than 302 errors.
> Is firefox 3.6.6 supposed to have this fix?

Michael, please read the bug.  I answered that question once already...

Comment 36

7 years ago
Boris, when did you answer that? I can't find any comment regarding 3.6.6.

Comment 37

7 years ago
bz refers to comments 29 & 30. 1.9.2.7 is a Gecko version corresponding to Firefox 3.6.7. You can get a build for testing from http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/3.6.7-candidates/build2/

Comment 38

7 years ago
Thanks, Nickolay.

Just a note: Normal users don't know the version numbers of the engine and which engine version is in which browser version. So they are only interested in the browser version.
Heiko, my apologies.  I was sure the 3.6/1.9.2 discussion included the Firefox version numbers, not just the Gecko ones... looks like I was wrong.
Comment on attachment 441528 [details] [diff] [review]
Fix

Approved for 1.9.0.20, a=dveditz
Attachment #441528 - Flags: approval1.9.0.next? → approval1.9.0.next+
Boris, do you mind if I go ahead and check this in for you on 1.9.0 when I'm doing all the patches for which I requested approval?
Fine by me.
Thanks!

Checking in netwerk/protocol/http/src/nsHttpChannel.cpp;
/cvsroot/mozilla/netwerk/protocol/http/src/nsHttpChannel.cpp,v  <--  nsHttpChannel.cpp
new revision: 1.339; previous revision: 1.338
done
Keywords: fixed1.9.0.20
blocking2.0: ? → betaN+
You need to log in before you can comment on or make changes to this bug.