2

We are running nginx/1.9.10 as a frontend server with multiple application server as upstream. We are using plain http, mostly https and switched to http/2 in the last weak.

We are logging like this:

 log_format custom '$host $server_port $request_time '
                   '$upstream_response_time $remote_addr '
                   '"$http2" $upstream_addr $time_iso8601 '
                   '"$request" $status $body_bytes_sent '
                   '"$http_referer" "$http_user_agent"';

We suddenly see a larger difference between $request_time and $upstream_response_time . A difference here is quite natural as the $request_time depends on the users network while the upstream_response_time does not.

So usually you should not care too much about $request_time as long as $upstream_response_time is stable.

But I still wanted to check what is happening because it strted to getting worse with http/2 So I compared average response times for https/1.1 and https/2.0

First I cecked all http/1.1 request and calculated average response_time and average upstream_time:

grep ' 443 ' access.log|grep 'HTTP/1.1'|\ 
cut -d ' ' -f 3,4 | awk '{r+=$1; u+=$2} END {print r/NR; print u/NR}'

0.0139158  # average response time for https/1.1
0.00691421 # average upstream time for https/1.1

Now I did the same with https/2.0:

grep ' 443 ' access.log|grep 'HTTP/2.0'| \
cut -d ' ' -f 3,4 | awk '{r+=$1; u+=$2} END {print r/NR; print u/NR}'
0.0828755  # average response time for https/1.1
0.00606643 # average upstream time for https/2.0

As you see the upstream time is nearly identical but the request time is slower for http/2 by factor 7! Wow! Isn't http/2 expected to be faster?

Now I checked all request which have a huge difference between these two values and nearly all of the top 500 has been a status code of 302

grep ' 443 ' access.log | grep 'HTTP/1.1' | \
awk '{ if ( $3 != $4 && $4 != "-" ) { \
  gsub(/\./,"",$3);gsub(/\./,"",$4); \
  print $3-$4,$4,$6,$9,$11,$12 }}' | \
sort -n | tail -n 10000 | grep 'POST HTTP/1.1" 302' | wc -l

9008 
# of 10000 (or 90%) request ordered by difference between 
# response and request time have status code 302  

So 90% of all requests with the highest difference between response and upstream time are status code 302. This is strange

On http/2 it is even worse:

grep ' 443 ' access.log | grep 'HTTP/2.0' | \
awk '{ if ( $3 != $4 && $4 != "-" ) { \
  gsub(/\./,"",$3);gsub(/\./,"",$4); \
  print $3-$4,$4,$6,$9,$11,$12 }}' | \
sort -n | tail -n 10000 | grep 'POST HTTP/2.0" 302' | wc -l

9790
# of 10000 (or 98%) request ordered by difference between 
# response and request time have status code 302  

So here are 98% of these request are 302 status.

Why does http/2 appear to be slower than http/1.1? Why are so many 302 status codes involved in requests were upstream and response time differ extremly (in HTTP/1.1 and HTTP/2.0)?

  • There's a type in your http/2 stats block - it says 1.1. Can you also average the request sizes for both request types? What kind of information is being served, whole web pages with lots of inline resources? HTTP/2 should in theory be faster if a lot of resources are downloaded over one connection. Are your users close to you (low ping), far away (high ping) or some of both? How many resources are being downloaded in each http2 session? Does it vary by client (Chrome/IE/etc)? You'll probably have to solve this one yourself since HTTP2 is new, but this is interesting, happy to provide ideas. – Tim Feb 20 '16 at 3:49
  • Also, I suggest doing real world tests with your web browser. Do 10 runs with HTTP2 enabled, and ten with HTTP2 disabled. It could just be that Nginx logging is incorrect. I could have a look at my server logs, but it's behind a CDN which supports HTTP2 so I doubt I'd have much useful data to work from. – Tim Feb 20 '16 at 19:05
0

I liked the quest very much, and I analyzed it.

I took these resources mostly: [https://www.nginx.com/blog/nginx-1-9-5/ ] [https://www.nginx.com/blog/http2-module-nginx/ ] [https://blog.cloudflare.com/introducing-http2/ ] [https://http2.github.io/faq/ ] and this PDF

You probable downloaded nginx/1.9.10 from Nginx.org http://nginx.org/en/download.html. Please confirm. Have you built it from source? Have you tried the nginx/1.9.12?

As you may see in CloudFlare article when measured Average Page Load time HTTP/2 is clearly the winner (at least for their web site).

Access via HTTP Protocol Version    Average Page Load time
HTTP 1.x                            9.07 sec.
SPDY/3.1                            7.06 sec.
HTTP/2                              4.27 sec. 

However, when tracking average response time, please check out the second article from Nginx.org I set as a reference where it reads:

The next key point of HTTP/2 is multiplexing. Instead of sending and receiving responses and requests as separate streams of data over multiple connections, HTTP/2 multiplexes them over one stream of bytes or one stream of data. It slices data for different requests and for different responses, and each slice has its own identification and its size field, which is there so the endpoint can determine which data belongs to which request.

The disadvantage here is that since each chunk of data has its own identification, its own fields, there's some metadata that transfers in addition to the actual data. So, it has some overhead.

http/2 socket

The other problems may be related to your nginx setup, for instance inside the server block.

  • 1
    This doesn't look like an answer, it looks like a description of HTTP2. – Tim Mar 6 '16 at 3:06

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.