1295612 - Assertion failure: !mTunnelTransport (call before mapstreamtohttpconnection), TunnelUtils.cpp:1037

Status: RESOLVED WONTFIX

(Core :: Networking: HTTP, defect, P3)

Description

[Honza Bambas (:mayhemer)]

Attachment: log

m-c, debug, win10

on my fedora 23 box:
nghttpx -s -f'*,8443' -bx.x.x.x,80 proxy.key proxy.pem

on x.x.x.x is an http2 server (iis 10.1.10586.0), proxy.crt is added as a trusted ca for webs, ca of the http2 server is tho missing in the nss database, nor there is an exception.

proxy is set via data: PAC as an https proxy.

I can connect the server via this proxy when accessing plain http, but from the moment I first time tried to go to the https on that server, it started to fail this assert (deleted session store, caches, etc.. no help, reproducible on every start since that time)


>	xul.dll!mozilla::net::SpdyConnectTransaction::ForcePlainText() Line 1037	C++
 	xul.dll!mozilla::net::Http2Stream::MapStreamToPlainText() Line 1459	C++
 	xul.dll!mozilla::net::Http2Stream::ConvertResponseHeaders(0x0e4e15c0, {...}, {...}, 0x00000190) Line 1008	C++
 	xul.dll!mozilla::net::Http2Session::ResponseHeadersComplete() Line 1333	C++
 	xul.dll!mozilla::net::Http2Session::RecvHeaders(0x0e4e1400) Line 1276	C++
 	xul.dll!mozilla::net::Http2Session::WriteSegmentsAgain(0x0d909ae4, 0x00008000, 0x034bf3bc, 0x034bf3d3) Line 2855	C++
 	xul.dll!mozilla::net::nsHttpConnection::OnSocketReadable() Line 1782	C++
 	xul.dll!mozilla::net::nsHttpConnection::OnInputStreamReady(0x0d140420) Line 2098	C++
 	xul.dll!mozilla::net::nsSocketInputStream::OnSocketReady(NS_OK) Line 290	C++
 	xul.dll!mozilla::net::nsSocketTransport::OnSocketReady(0x0b6d1b60, 0x0001) Line 1971	C++
 	xul.dll!mozilla::net::nsSocketTransportService::DoPollIteration(0x034bf650) Line 1089	C++
 	xul.dll!mozilla::net::nsSocketTransportService::Run() Line 874	C++
 	xul.dll!nsThread::ProcessNextEvent(false, 0x034bf745) Line 1058	C++

Comment 1

[Honza Bambas (:mayhemer)]

Patrick, ping on ni?  Nick, maybe you know what's going on here?

I'd like to be able to confirm potentially highly critical bug 1293328.  But I can't because of this assertion failure, probably pointing out that there is something wrong in this code.

Comment 2

[Patrick McManus [:mcmanus]]

I believe you are on an error path from the proxy.. i.e. you are connected via h2 to the proxy and have issued a connect on some stream and that stream has produced something other than a 200.

look for 
    LOG3(("Http2Stream %p Tunnel Response code %d", this, httpResponseCode));

perhaps it is issuing a 401/3 ?

anyhow - the assert clearly can't work.

you are on the stack from responseheaderscomplete/convertresponseheaders and it is complaining about mapstreamtohttpconnection having already been called.

about 4 lines before that in responseheaderscomplete we had responseheaderscomplete/setallheadersreceived/mapstreamtohttpconnection

and indeed mapstreamtohttpconnection uses mForcePlainText in its code, so the assertion about the ordering seems right.

in general this code path expects tls in tls (connect inside h2), but you've gotten a connect error so the response code has to bypass the interior connection.

And I know I've seen this work, but I'm not quite sure how given what I'm looking at. Does it work if you disable the assert? i.e. does the right code get back to the transaction?

Comment 3

[Honza Bambas (:mayhemer)]

(In reply to Patrick McManus [:mcmanus] from comment #2)
> I believe you are on an error path from the proxy.. i.e. you are connected
> via h2 to the proxy and have issued a connect on some stream and that stream
> has produced something other than a 200.
> 
> look for 
>     LOG3(("Http2Stream %p Tunnel Response code %d", this, httpResponseCode));
> 
> perhaps it is issuing a 401/3 ?

I/nsHttp Http2Stream 19a97200 Tunnel Response code 400.  Weird.

> 
> anyhow - the assert clearly can't work.

To repeat: we must not _assert_ just when we receive an error code from a server.  If that asserts sanity state, then we can be easily broken with any crafted server.  Isn't that a really bad bug?

> 
> you are on the stack from responseheaderscomplete/convertresponseheaders and
> it is complaining about mapstreamtohttpconnection having already been called.
> 
> about 4 lines before that in responseheaderscomplete we had
> responseheaderscomplete/setallheadersreceived/mapstreamtohttpconnection
> 
> and indeed mapstreamtohttpconnection uses mForcePlainText in its code, so
> the assertion about the ordering seems right.
> 
> in general this code path expects tls in tls (connect inside h2), but you've
> gotten a connect error so the response code has to bypass the interior
> connection.
> 
> And I know I've seen this work, but I'm not quite sure how given what I'm
> looking at. Does it work if you disable the assert? i.e. does the right code
> get back to the transaction?

I had a mistake in the config command line.  The correct port for the -b arg is 443, obviously.  

When fixed as:

nghttpx -s -f'*,8443' -b'target-server,443' proxy.key proxy.pem --log-level=INFO

I can see this when going to https://target-server/ from my local build:

---

20/Sep/2016:20:13:37 +0200 PID3859 [INFO] shrpx_http2_upstream.cc:224 [UPSTREAM:0x55e314410d60] Received upstream request HEADERS stream_id=17
20/Sep/2016:20:13:37 +0200 PID3859 [INFO] shrpx_http2_upstream.cc:264 [UPSTREAM:0x55e314410d60] HTTP request headers. stream_id=17
:method: CONNECT
:authority: target-server:443
user-agent: Mozilla/5.0 (Windows NT 10.0; WOW64; rv:51.0) Gecko/20100101 Firefox/51.0

20/Sep/2016:20:13:37 +0200 PID3859 [INFO] shrpx_client_handler.cc:679 [CLIENT_HANDLER:0x55e3143f4d10] Downstream address group: 0
20/Sep/2016:20:13:37 +0200 PID3859 [INFO] shrpx_client_handler.cc:687 [CLIENT_HANDLER:0x55e3143f4d10] Downstream connection pool is empty. Create new one
20/Sep/2016:20:13:37 +0200 PID3859 [INFO] shrpx_http_downstream_connection.cc:128 [DCONN:0x55e3143ffe10] Attaching to DOWNSTREAM:0x55e31441f620
20/Sep/2016:20:13:37 +0200 PID3859 [INFO] shrpx_http_downstream_connection.cc:185 [DCONN:0x55e3143ffe10] Connecting to downstream server
20/Sep/2016:20:13:37 +0200 PID3859 [INFO] shrpx_http_downstream_connection.cc:399 [DCONN:0x55e3143ffe10] HTTP request headers. stream_id=17
CONNECT target-server:443 HTTP/1.1
Host: target-server:443
User-Agent: Mozilla/5.0 (Windows NT 10.0; WOW64; rv:51.0) Gecko/20100101 Firefox/51.0
Via: 2 nghttpx

---

and then nghttpx hangs (no more logs), wheel is spinning in Fx and page doesn't load.  assertion is removed.

'target-server' is pointing at the IIS http2 capable server.  The machine where nghttp is running resolves that name correctly, port is reachable.

netstat tells me that there is an ESTABLISHED connection from nghttp back to the server.  and so for any connection like aus.m.o, safebrowsing, detectportal.f.c etc...



Patrick, what is your way to setup nghttp as an http2 proxy?

Comment 4

[Patrick McManus [:mcmanus]]

(In reply to Honza Bambas (:mayhemer) from comment #3)\
> > anyhow - the assert clearly can't work.
> 
> To repeat: we must not _assert_ just when we receive an error code from a
> server.  If that asserts sanity state, then we can be easily broken with any
> crafted server.  Isn't that a really bad bug?

thanks :( I'm quite aware asserts are not meant to fire :) - yes, its a bug and the assert is letting us know we have a bug (which is what they are meant for :)). I'm not sure if its a bad bug or not (depends on what happens downstream) but either way bugs are made to be fixed.

> 
> 
> Patrick, what is your way to setup nghttp as an http2 proxy?


install/bin/nghttpx --conf=install/conf --log-level=INFO --http2-proxy

/opt/nghttp>cat install/conf 
# Examples:
#
frontend=0.0.0.0,3125
backend=127.0.0.1,3127
private-key-file=/opt/nghttp/install/self.key
certificate-file=/opt/nghttp/install/self.cert

Comment 5

[Patrick McManus [:mcmanus]]

it looks like 3127 in my config is an h1 proxy

Comment 6

[Firefox Bug Husbandry Bot]

Bulk change to priority: https://bugzilla.mozilla.org/show_bug.cgi?id=1399258

Comment 7

[Sylvestre Ledru [:Sylvestre]]

Moving to p3 because no activity for at least 1 year(s).
See https://github.com/mozilla/bug-handling/blob/master/policy/triage-bugzilla.md#how-do-you-triage for more information

Comment 8

[Randell Jesup [:jesup] (needinfo me)]

The code referenced in the last few frames of this stack is gone