See multiple TCP connections when using HTTP/2 from chrome to node-http2 server

UPDATE (for anyone interested in the outcome :)

I wasn't able to figure out why next protocol negotiation between chrome and node-http2 server fails. My suspicion was self signed certificate or ALPN/NPN support issue. So I moved to golang HTTP/2 implementation. The same setup works perfectly and I see single mutliplexed TCP connection (chrome --> golang)

I have been reading about HTTP/2 and how it solves the latency issue with HTTP/1.1 with single multiplexed TCP connection per host so I decided to try it out.

The experiment

created a simple html file with references to one css, one js and couple of images.
A simple http server in Node.js which serves all these files
Used chrome to make a http request
Used tcptrack on Ubuntu (tcptrack) to track TCP connections being made to the http server.

The tcptrack window shows 4 connections established. So the browser is opening different connection for image and css/js request.

Tcp track output for http/1.1 request from chrome

I get similar output using tcpdump. For reference tcptrack command used was

tcptrack -d -i eth0 -r 3600 port 8989

and tcpdump also shows similar output

tcpdump -i eth0 -nns 0 "dst port 8989 and tcp[tcpflags] == tcp-syn"

The simple all in one http server serving these files was something like below (relevant code)

(function(){
  ...........
  var server = http.createServer(function(request, response) {
      ..........
      fs.readFile(filetoRet, function (err,data) {
      if(filePath.indexOf(".jpg") >-1){
        response.writeHead(200, {"Content-Type": "image/jpg"});
      }.....
      
      response.write(data);
      response.end();
      });

   
  });
   

  server.listen(8989);  
})()

After this I tried using http/2.

Enabled chrome flag to send http/2 request
Created a http/2 server using node-http2
The simple http server has the same code as http/1.1 except that it uses http2 server module installed in step 2.
Made the request using chrome (It needed to be an https request inline with HTTP/2 spec)
Captured tcptrack/tcpdump output

tcptrack output for http/2

So, this still shows multiple TCP connections being made. Also if I increase the number of images in the html, the number of connections increases.

So I am not sure how to read this. Is this how HTTP/2 should behave (or is this a chrome bug)? Is there a better way to visualize the HTTP/2 gains using a simple http/2 client server?

Note:I am using self signed certificate for the HTTP/2 server so chrome throws a warning before proceeding to the page and possibly those closed connections represent it but I don't think it should impact how the page and its components are requested by protocol

Thanks for everyone's patience in reading this and appreciate any suggestions.

msingh

P.S : Wireshark TCP capture is no different. Just that I found it harder to isolate the traffic in Wireshark so used tcpdump and tcptrack.

Update: update: Looking at chrome://net-internals/ the HTTP/2 request negotiation fails and it falls back to using HTTP/1.1. Don't understand the reason yet.

The chrome internal tool events show

t=879052 [st= 0] +HTTP_STREAM_JOB  [dt=19]
                  --> original_url = "https://msinghlinux.ads.com:8900/"
                  --> priority = "HIGHEST"
                  --> url = "https://msinghlinux.ads.com:8900/"
t=879052 [st= 0]   +PROXY_SERVICE  [dt=0]
t=879052 [st= 0]      PROXY_SERVICE_RESOLVED_PROXY_LIST
                      --> pac_string = "DIRECT"
t=879052 [st= 0]   -PROXY_SERVICE
t=879052 [st= 0]   +HOST_RESOLVER_IMPL_REQUEST  [dt=0]
                    --> address_family = 0
                    --> allow_cached_response = true
                    --> host = "msinghlinux.ads.com:8900"
                    --> is_speculative = false
t=879052 [st= 0]      HOST_RESOLVER_IMPL_CACHE_HIT
t=879052 [st= 0]   -HOST_RESOLVER_IMPL_REQUEST
t=879052 [st= 0]   +SOCKET_POOL  [dt=19]
t=879071 [st=19]      SOCKET_POOL_BOUND_TO_CONNECT_JOB
                      --> source_dependency = 26961 (CONNECT_JOB)
t=879071 [st=19]      SOCKET_POOL_BOUND_TO_SOCKET
                      --> source_dependency = 26967 (SOCKET)
t=879071 [st=19]   -SOCKET_POOL
t=879071 [st=19]    HTTP_STREAM_REQUEST_PROTO
                    --> next_proto_status = "negotiated"
                    --> proto = "http/1.1"
t=879071 [st=19]    HTTP_STREAM_JOB_BOUND_TO_REQUEST
                    --> source_dependency = 26910 (URL_REQUEST)
t=879071 [st=19] -HTTP_STREAM_JOB

The value of next protocol is http/1.1 (next_proto_status and proto). But it doesn't say what failed in the negotiation that caused this fallback? Can the self signed certificate be the reason?

HTTP/2 Server code

var options = {
  key: fs.readFileSync('./server.key'),
  cert: fs.readFileSync('./server.crt')
};

options.log = bunyan.createLogger(...);
require('http2').createServer(options,function(request, response) {
      .... same code as http/1.1 server


}).listen(8900);

UPDATE (for anyone interested in the outcome :)

The experiment

Recommended topics

Hot tags