Hello, I have been struggling on this issue for some time.

I am trying to monitor the total request time in haproxy 1.7.5 HTTP logs.
My usecase is customers want to know the exact overhead of calling our service. 
Sometime we have complaints that we are adding overhead, and we know that our 
backend is fast, but we don't have the data to show the total overhead from the 
last end user point of view.

So I started saving all haproxy HTTP logs in an ELK cluster.

At this point I must say: we use http-server-close and option httplog.

What I see is the Tr and Tt seem to depend on the TCP opening timer. The 
consequence is the logged time is good only for the first http request of a tcp 
connection, i.e the request that has a NI cookie-status.

To show that, I can show the difference between querying the backend through 
haproxy using

1) CURL (no keep alive)

Jun 30 17:18:23 19/0/0/3/22 200 1993 - - --NI 567/567/0/1/0 0/0 "GET 
/website/5be174f9a9403/tag.js HTTP/1.1"
Jun 30 17:18:25 18/0/0/2/20 200 1993 - - --NI 449/449/0/1/0 0/0 "GET 
/website/5be174f9a9403/tag.js HTTP/1.1"
Jun 30 17:18:28 19/0/0/2/21 200 1993 - - --NI 605/605/0/1/0 0/0 "GET 
/website/5be174f9a9403/tag.js HTTP/1.1"

We see that there is 1 seconds between my two first curls, and that the Tr and 
Tt are similar. We see both are NI. Then there is 3 seconds between the 2 last 
curls, but the Tr and Tt is still similar.

2) Web browser (keep-alive)

Jun 30 17:14:49 190305/0/0/4/190309 304 205 - - --VN 963/963/0/0/0 0/0 "GET 
/website/5be174f9a9403/tag.js HTTP/1.1"
Jun 30 17:14:51 1940/0/0/1/1941 304 205 - - --VN 966/966/0/1/0 0/0 "GET 
/website/5be174f9a9403/tag.js HTTP/1.1"

We see the first request has crazy Tt and Tr even if it was really fast on the 
client side. This is, I guess because of the idle time on the TCP connection.
We see the second request has 2000 ms Tt / Tr, this is the time elapsed since 
the first request, plus the 'real' http response time.

Now I wonder if this is normal behaviour and what are my options.

I see:

- Disable all form of keepalive, with a big performance cost
- Monitor only the NI requests, with a risk of inconsistencies

Is there another way ? Do I understand correctly what is going on ?

Thank you

Reply via email to