726366 - spdy should support tunnel through http proxy

Status: VERIFIED FIXED

(Core :: Networking, enhancement)

Description

[Jo Hermans]

I noticed that SPDY doesn't work behind a proxyserver (with a PAC file).

I tested twice by going to https://www.spdytest.com/ : once on my home connection, and once on the company vpn, which forces the use of a proxyserver. The use of the vpn should not be important, I noticed the effect in the office too.

Note that the proxyserver is made by Bluecoat, and I don't known if this particular version is doing something with the SSL connection (some of them do). I didn't notice anything special in the logfile though.

Attachments are following.

Comment 1

[Jo Hermans]

Attachment: logfile without a proxyserver

Comment 2

[Jo Hermans]

Attachment: logfile with a proxyserver

Comment 3

[Patrick McManus [:mcmanus]]

I believe spdytest.com does not run spdy - despite its name. chrome seems to confirm this. Though there is an alternate protocol mapping. I assume its an abandoned config.

what is the failure mode that you see?

does https://www.google.com/ search work through the proxy server?

https://spdy-twitlog.indutny.com/
https://www.codecentric.de/

are also interesting spdy enabled, non-google, test cases.

I'll read the log later tonight - thanks.

Comment 4

[Jo Hermans]

Note that Google Chrome works correctly over the same setup.

Comment 5

[Jo Hermans]

I found the code that is responsible for this : see nsHttpConnection::OnSocketWritable(). When we're starting a CONNECT connection, we're never call EnsureNPNComplete(), but immediately start reading from the stream. So we're never switching to a SPDY connection.

I'll produce some more logs immediately with other servers.

Comment 6

[Jo Hermans]

Attachment: logfile to https://spdy-twitlog.indutny.com/ (wohtout proxyserver)

Comment 7

[Jo Hermans]

Attachment: logfile to https://spdy-twitlog.indutny.com/ (with proxyserver)

Comment 8

[Patrick McManus [:mcmanus]]

(In reply to Jo Hermans from comment #5)
> I found the code that is responsible for this : see
> nsHttpConnection::OnSocketWritable(). When we're starting a CONNECT
> connection, we're never call EnsureNPNComplete(), but immediately start
> reading from the stream. So we're never switching to a SPDY connection.
> 

I don't read that the way you do. in OSW we don't call EnsureNPNComplete() while the Connect/200 for setting up the tunnel through the proxy is still underway - and that's the right thing to do. NPN is part of the tunnel.

in any event - I'll read the log later. You are confirming that you can't use the other sites either, correct?

how about https:// that is not spdy related? (e.g. https://www.paypal.com/)

Comment 9

[Jo Hermans]

(In reply to Patrick McManus [:mcmanus] from comment #8)
> in any event - I'll read the log later. You are confirming that you can't
> use the other sites either, correct?

Yes, I never see the X-Firefox-Spdy header in their responses. And https://spdy-twitlog.indutny.com/ returns the "Oh, no... your browser requested this page via HTTPS" error. If I use Chrome, then it doesn't do that.

> how about https:// that is not spdy related? (e.g. https://www.paypal.com/)

Of course the proxyserver handles SSL correctly - otherwise I would be able to type this :-)

Comment 10

[Patrick McManus [:mcmanus]]

OK, I'm a little confused (still haven't read that log - that would probably help me :)).. I first read this report as some kind of interop breakage, but are you just saying you expect spdy to be used but instead the site loads fine by automatically choosing http/1?

(I really had a mental block on this - it wasn't until you said you read the Oh No bit from twitlog that I realized stuff was loading at all).

If so, that's actually by design at this stage. spdy via proxy is something we'll add, but to simplify things in the first round any use of a proxy server should mean you'll just run http/1.

http://mxr.mozilla.org/mozilla-central/source/netwerk/protocol/http/nsHttpConnection.cpp#333

Part of my confusion was the mention of spdytest.com, which as I said doesn't actually ever seem to run spdy anywhere (proxy or not, chrome or ff) despite its name. Best to leave it out of the conversation :)

If I've got this right, the right thing to do is just to change this to enhancement, which is a welcome addition because I forgot to file the bug about it.

Comment 11

[Jo Hermans]

(In reply to Patrick McManus [:mcmanus] from comment #10)
> OK, I'm a little confused (still haven't read that log - that would probably
> help me :)).. I first read this report as some kind of interop breakage, but
> are you just saying you expect spdy to be used but instead the site loads
> fine by automatically choosing http/1?

Yes. Spdy is never initiated, so the connection will be an plain old http/1 connection.

Comment 12

[Patrick McManus [:mcmanus]]

other than the removing the explicit disables for spdy-over-proxy I suspect all we need to do here is:

1] test it to the level the other proxy code is tested at (i.e. manually)
2] make sure pooling is disabled for spdy over proxy - ip address is a fuzzy concept in a proxied world.

Comment 13

[Patrick McManus [:mcmanus]]

The only thing tricky I have found here is a bug in the existing proxy tunneling logic which is irrelevant to http/1 but impacts spdy.

Right now we declare the tunnel to be established when the response headers for the CONNECT transaction are complete. We do that regardless of what the content-length of the CONNECT response might be. Realistically, CONNECT responses don't have bodies so that should be ok and for HTTP/1 it works ok.

However in spdy the server can speak first with something like a settings frame. (actually a settings frame often comes down the pipe immediately.) This means the transaction code, which is processing the CONNECT transaction, can eat up that data if the response headers don't delimit it. The typical tunnel response is simply "HTTP/1.0 200 Connection established" which means read to eof.. or in this case read until the connetion onheadersavailable() code is called.

The fix is simply to set mNoContentLength = true when the response code is 200 and there is a proxy CONNECT in progress, which reflects what we were already doing. I considered trying to honor a content length if it was already there but realistically we aren't reliably honoring it now (its racy), so better to have the determinstic behavior.

Comment 14

[Patrick McManus [:mcmanus]]

Attachment: patch 0

Comment 15

[Honza Bambas (:mayhemer)]

Comment on attachment 620406 [details] [diff] [review]
patch 0

Review of attachment 620406 [details] [diff] [review]:
-----------------------------------------------------------------

Are there tests for this?

::: netwerk/protocol/http/nsHttpTransaction.cpp
@@ +1230,5 @@
> +        if (mResponseHead->Status() == 200 &&
> +            mConnection->IsProxyConnectInProgress()) {
> +            // successful CONNECTs do not have response bodies
> +            mNoContent = true;
> +        }

Add this to the switch above like

case 200:
  // successful CONNECTs do not have response bodies
  if (!..->IsProxy...)
     break; 
case 204:
case 205:
...

Stick the things together..

Comment 16

[Patrick McManus [:mcmanus]]

(In reply to Honza Bambas (:mayhemer) from comment #15)
> Comment on attachment 620406 [details] [diff] [review]
> patch 0
> 
> Review of attachment 620406 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Are there tests for this?
> 
> ::: netwerk/protocol/http/nsHttpTransaction.cpp
> @@ +1230,5 @@
> > +        if (mResponseHead->Status() == 200 &&
> > +            mConnection->IsProxyConnectInProgress()) {
> > +            // successful CONNECTs do not have response bodies
> > +            mNoContent = true;
> > +        }
> 
> Add this to the switch above like
> 
> case 200:
>   // successful CONNECTs do not have response bodies
>   if (!..->IsProxy...)
>      break; 
>

nope. That would add that code for 101 (which does not have a break), which I didn't want to do.

Comment 17

[Honza Bambas (:mayhemer)]

(In reply to Patrick McManus [:mcmanus] from comment #16)
> nope. That would add that code for 101 (which does not have a break), which
> I didn't want to do.

Ha!  Right.

Comment 18

[Patrick McManus [:mcmanus]]

(In reply to Honza Bambas (:mayhemer) from comment #15)
> Comment on attachment 620406 [details] [diff] [review]
> patch 0
> 
> Review of attachment 620406 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Are there tests for this?
> 

no - the spdy tests are xpcshell based and they don't have the ssltunnel proxy (mochi only). 

otoh there really is almost no code here that isn't tested by the existing CONNECT stuff in mochi. That one (200 && proxyconnectinprogress()) check being the exception.

I hand tested it with squid, of course.

Comment 19

[Patrick McManus [:mcmanus]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/7fc170b6f470

Comment 20

[Ryan VanderMeulen [:RyanVM]]

http://hg.mozilla.org/mozilla-central/rev/7fc170b6f470

Comment 21

[Jo Hermans]

I just did a quick test, and I can see that Spdy is indeed used over the proxy-server. But I noticed that the first request doesn't work (you get a '200 Connection Established' result, but nothing more), you have to press reload first. I don't have time now, but I'll debug more later this evening.

Comment 22

[Patrick McManus [:mcmanus]]

weird. maybe related to auth. does your proxy authenticate, and if so - how?

Comment 23

[Patrick McManus [:mcmanus]]

(In reply to Jo Hermans from comment #21)
> I just did a quick test, and I can see that Spdy is indeed used over the
> proxy-server. But I noticed that the first request doesn't work (you get a
> '200 Connection Established' result, but nothing more), you have to press
> reload first. I don't have time now, but I'll debug more later this evening.

I can't repro.. so some debug info would be good. http log plus wireshark would be ideal.

Comment 24

[Jo Hermans]

Attachment: logfiles with a proxyserver

Comment 25

[Jo Hermans]

Attachment: logfiles without a proxyserver

Comment 26

[Jo Hermans]

I created 2 logfiles (1 with a proxyserver, one without) like this :

- start a copy of firefox, using the default homepage (with Google searchbox)
- open the web console
- type something in the Google search box. Since all Google traffic is now passed over SSL, it will automatically negotiate a SPDY connection (also confirmed in the web console)
- in case of a proxy server, you see a blank page and 2 URL's in the web console. You have to press the reload button before you see something.

The zip files contain a wireshark pcap file, the http-logfile and a copy of what was visible in the webconsole. Note that the files with a proxyserver are taken inside my company's network (using a VPN), and it first has to load a PAC file. The proxyserver does not use any authentication at all.

Google is also redirected to google.co.uk (normally google.fr or google.be would have been used, but that sometimes changes depending on the VPN). The logfiles without a proxyserver are run in the network of my ISP, and always go to google.be.

Comment 27

[Jo Hermans]

Note that all further connection request work correctly, until the SPDY connection is closed after the idle timeout. The next connection attempt will have the same problem.

The 2 webconsole files show the difference between the 2 attempts. The one with a proxyserver, has 2 URL's that seem to do nothing, and an error message :

[21:57:15.831] GET https://www.google.com/search?q=benelux%20blues%20scene&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:en-US:unofficial&client=firefox-nightly&source=hp&channel=np [HTTP/1.1 200 Connection established 2391ms]
[21:57:18.240] GET https://www.google.co.uk/search?q=benelux%20blues%20scene&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:en-US:unofficial&client=firefox-nightly&source=hp&channel=np [HTTP/1.1 200 Connection established 1984ms]
[21:57:20.265] The character encoding of the plain text document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the file needs to be declared in the transfer protocol or file needs to use a byte order mark as an encoding signature. @ https://www.google.co.uk/search?q=benelux%20blues%20scene&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:en-US:unofficial&client=firefox-nightly&source=hp&channel=np

Comment 28

[Patrick McManus [:mcmanus]]

I can reproduce this just by going to https://www.google.co.uk/ through a squid proxy via spdy. my local google doesn't do it.

there is clearly a settings frame from the server being read as an http/1 response which is causing the error. (its being interpeted as a http/0.9 response)

according to the cap we have negotiated spdy, but ff doesn't realize it. Its possible this isn't a proxy bug at all, but rather a general NPN one that is only showing up here.

Comment 29

[Patrick McManus [:mcmanus]]

this turns out to be complicated to describe, but easy to fix. bear with me. (worth mentioning first, this is just a problem with proxy tunneling spdy, so no regressions.)

All SSL handshaking is meant to be driven out of nsHttpConnection::EnsureNPN() with a series of write("", 0) calls.

The 0 byte write only actually does anything if there have been no bytes written down the pipe yet. If that's ok it triggers the ssl handshake code, if plaintext has been written then it just returns NS_OK. On normal (i.e. non tunneled) SSL transactions, the SSL handshake is the first thing. however when there is a CONNECT/200-Connection-Established preamble EnsureNPN() doesn't actually make the SSL handshake happen. That's a bug but it was covered up.

Given that, why do proxied non-spdy connections work ok? The answer is that the handshake is coincidentally driven to completion through the I/O read calls being done to read the 200-Connection-Established while IsProxyConnectInProgress() was true. IsProxyConnectInProgress() covered the period from sending a CONNECT through SSL handshake completion when a proxy tunnel was in use.

this worked fine for http/1, but for spdy it presents a problem. If one of these reads happen after the 200-Established and after the SSL has actually finished handshaking it can consume SPDY data without realizing that we have negotiated spdy. (remember that checking is all done on the write path). This doesn't actually present a problem in practice for HTTP/1 because that is always a read after write protocol and the data there would be http and interpreted as http anyhow.

Step 1 is to make the IsProxyConnectInProgress() window cover only the CONNECT->200-Established period, not the ssl handshake. That will stop us from reading without an active transaction having been sent and misconstruing the data as the wrong protocol.
Step 2 is to allow 0 byte writes at any time so EnsureNPN() can drive the ssl handshake as expected. [*]
Step 3 is to remove the mProxyConnectInProgress variable and replace it with !!mProxyConnectStream because their lifetimes are now the same due to step 1.


[*] when writing EnsureNPN() I had to change nsSocketTransport2.cpp to allow 0 byte writes at all and out of conservatism I limited them to the beginning of the stream. That was too conservative - but there isn't a specific problem with allowing them at any point that I was trying to avoid.

Comment 30

[Patrick McManus [:mcmanus]]

Jo - can you try out a build from here and tell me if it works for you?

https://tbpl.mozilla.org/?tree=Try&rev=da457691a739

Comment 31

[Patrick McManus [:mcmanus]]

Attachment: patch part 2 v0

Comment 32

[Patrick McManus [:mcmanus]]

Attachment: patch part2 v1

try showed a failure in the case where a CONNECT generated a failed tunnel and that error did not get moved properly back to the original http channel.

For that reason I have removed the code that consolidated mProxyConnectInProgress and mProxyConnectStream - they only have the same lifetime in the event of a successful CONNECT pre-transaction. For non-200 responses to the CONNECT normal http parsing rules should continue to apply which of course means continuing to read the response to the CONNECT (which early elimination of the mProxyConnectInProgress state removed).

sent to try again - but the previously failing testcase passes now as do hand tests of spdy and non spdy through a proxy using both network acls and password acls.

https://tbpl.mozilla.org/?tree=Try&rev=03dbcb253399

Comment 33

[Jo Hermans]

(In reply to Patrick McManus [:mcmanus] from comment #30)
> Jo - can you try out a build from here and tell me if it works for you?
> 
> https://tbpl.mozilla.org/?tree=Try&rev=da457691a739

Yes, that works for me (I used the Win32 build, zip version). I don't see the blank page anymore (and the error in Web Console). X-Firefox-Spdy header is present.

Also note that I'm back redirected to the usual google.be instead of the google.co.uk that I saw yesterday. Don't know why this happened (the redirect came from Googel itself). Was this a timing issue that was only present at google.co.uk ?

Comment 34

[Patrick McManus [:mcmanus]]

(In reply to Jo Hermans from comment #33)
> (In reply to Patrick McManus [:mcmanus] from comment #30)

> google.co.uk that I saw yesterday. Don't know why this happened (the
> redirect came from Googel itself). Was this a timing issue that was only
> present at google.co.uk ?

I didn't actually try .be because I made it happen with .co.uk.. it was definitely a timing issue - so the rtt was probably impt. You can just go directly to uk or be to be thorough - the redirect itself wasn't part of the bug.

thanks!

Comment 35

[Patrick McManus [:mcmanus]]

Attachment: patch part 2 v2

a minor refinement - we can't consolidate mProxyConnectInProgress and mProxyConnectStream because in the case of tunnel setup failure (i.e. a non 200), the InProgress() state needs to continue.

Comment 36

[Patrick McManus [:mcmanus]]

https://tbpl.mozilla.org/?tree=Try&rev=425dfb62d400

Comment 37

[Patrick McManus [:mcmanus]]

Comment on attachment 623019 [details] [diff] [review]
patch part 2 v2

looks good on try

Comment 38

[Jo Hermans]

(In reply to Patrick McManus [:mcmanus] from comment #36)
> https://tbpl.mozilla.org/?tree=Try&rev=425dfb62d400

This also works for me.

When I go to <https://www.google.co.uk/> in a regular Nightly, using the proxyserver of my company, I receive the following error in the Web Console (and a blank page in the content pane):

[19:17:54.447] GET https://www.google.co.uk/ [HTTP/1.1 200 Connection established 94ms]
[19:17:54.568] The character encoding of the plain text document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the file needs to be declared in the transfer protocol or file needs to use a byte order mark as an encoding signature. @ https://www.google.co.uk/

When I try it with the build from comment 36, it works correctly.

Comment 39

[Honza Bambas (:mayhemer)]

Comment on attachment 623019 [details] [diff] [review]
patch part 2 v2

Review of attachment 623019 [details] [diff] [review]:
-----------------------------------------------------------------

r=honzab

::: netwerk/protocol/http/nsHttpConnection.cpp
@@ +873,5 @@
>                  if (NS_FAILED(rv)) // XXX need to handle this for real
>                      LOG(("ProxyStartSSL failed [rv=%x]\n", rv));
>              }
>              mCompletedProxyConnect = true;
> +            mProxyConnectInProgress = false;

Remove this from nsHttpConnection::OnSocketWritable() ?

Comment 40

[Patrick McManus [:mcmanus]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/35365a9750f3

Comment 41

[Patrick McManus [:mcmanus]]

(In reply to Honza Bambas (:mayhemer) from comment #39)

> > +            mProxyConnectInProgress = false;
> 
> Remove this from nsHttpConnection::OnSocketWritable() ?

it is still needed in the failed-to-establish tunnel path.

Comment 42

[Honza Bambas (:mayhemer)]

(In reply to Patrick McManus [:mcmanus] from comment #41)
> (In reply to Honza Bambas (:mayhemer) from comment #39)
> 
> > > +            mProxyConnectInProgress = false;
> > 
> > Remove this from nsHttpConnection::OnSocketWritable() ?
> 
> it is still needed in the failed-to-establish tunnel path.

Ah, right.

Comment 43

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/35365a9750f3

Comment 44

[Jo Hermans]

This seems to work for me now - I've accessed various Google servers and twitter.com over SPDY, while I still had the error with yesterdays's build.

Comment 45

[Patrick McManus [:mcmanus]]

thanks jo!