Total Time stat seems high on stats page

Help!
1

The total time on my stats seems a lot higher than it should be. Here, it seems to be telling me that the average request takes over 2 seconds. It seems to be much higher since I upgraded to HaProxy 1.8 (before, the total time was much lower).

Screenshot_1

I enabled my logs for a while and got results such as these:

Oct 23 11:59:42 MySiteLBNYC haproxy[25790]: CLIENT IP:36391 [23/Oct/2018:11:59:42.935] mysite~ mysite/MySite05 0/0/0/10/11 200 28119 - - --NI 567/567/0/1/0 0/0 “GET /file.php HTTP/1.1”

Oct 23 11:59:43 MySiteLBNYC haproxy[25790]: CLIENT IP:48547 [23/Oct/2018:11:59:43.281] mysite~ mysite/MySite07 0/0/0/9/9 200 28066 - - --NI 572/572/1/1/0 0/0 “GET /file.php HTTP/1.1”

Oct 23 12:00:54 MySiteLBNYC haproxy[25790]: CLIENT IP:37262 [23/Oct/2018:12:00:54.824] mysite~ mysite/MySite01 0/0/0/62/62 200 18515 - - --VN 515/515/0/1/0 0/0 “GET /file.php HTTP/1.1”

Oct 23 12:01:58 MySiteLBNYC haproxy[25790]: CLIENT IP:35693 [23/Oct/2018:12:01:58.562] mysite~ mysite/MySite08 0/0/0/71/71 200 31769 - - --VN 551/551/1/1/0 0/0 “GET /file.php HTTP/1.1”

Oct 23 12:02:45 MySiteLBNYC haproxy[25790]: CLIENT IP:56225 [23/Oct/2018:12:02:45.960] mysite~ mysite/MySite09 0/0/0/5/5 200 25056 - - --VN 522/522/0/1/0 0/0 “GET /file.php HTTP/1.1”

My config is as follows:

global
log 127.0.0.1 local0 notice
stats socket /var/run/haproxy.stat
maxconn 70000
tune.maxrewrite 16384
tune.bufsize 32768
tune.ssl.cachesize 10000000
user haproxy
group haproxy
nbproc 4
cpu-map 1 0
cpu-map 2 1
cpu-map 3 2
cpu-map 4 3

defaults
log global
mode http
maxconn 70000
option httplog
option dontlognull
option forwardfor
retries 5
option redispatch
timeout connect 25000
timeout client 25000
timeout server 25000

listen mysite
option httplog
option dontlog-normal
option dontlognull
option accept-invalid-http-request
log /dev/log local0
bind 0.0.0.0:80
bind :::80 v6only
bind :443 ssl crt /etc/ssl/mysite.com/mysite.com.pem
mode http
maxconn 70000
balance static-rr
option http-keep-alive
option forwardfor
http-request set-header X-Forwarded-Proto HTTPS_ON if { ssl_fc }
cookie SRVNAME insert
timeout connect 10s
timeout client 60s
timeout server 60s
reqidel ^X-Forwarded-For:.

redirect scheme https code 301 if !{ ssl_fc }

acl fb-img-acl hdr_dom(host) -i fb.mysite.com
use_backend varnish-backend if fb-img-acl

acl thumb-img-acl hdr_dom(host) -i thumbs.mysite.com
use_backend varnish-backend if thumb-img-acl

acl letsencrypt-acl path_beg /.well-known/acme-challenge/
use_backend letsencrypt-backend if letsencrypt-acl

server mysite01 10.136.109.25:80 cookie MS01 check
server mysite02 10.136.126.250:80 cookie MS02 check
server mysite04 10.136.127.19:80 cookie MS04 check
server mysite05 10.136.127.60:80 cookie MS05 check
server mysite06 10.136.63.133:80 cookie MS06 check

backend letsencrypt-backend
server letsencrypt 127.0.0.1:8888

backend varnish-backend
server varnish 127.0.0.1:6081

Does anyone have any idea on how to get to the bottom of this issue?

2

This is the average of the total session time of the last 1024 connections, including keep-aliving idle HTTP connections. That fact that you see high numbers is expected, that’s exactly what keep-alive does.

You can also see from your logs that timers are high … 28, 18, 31 and 25 seconds. That averaged with (I assume) non keep-alived requests will lead to that value.

1 Like
3

Hi Luka,

Thank you for your reply. Could you elaborate on what you mean when you say the timers are high?

Thanks,
Wayne

4

Sorry, I confused the response size with the response total time in the log.

5

Hi Wayne,

Did you get answer of your question ?