|
TimingEvents
Timing events.
Timers provide a great help in troubleshooting network problems. All values are reported in milliseconds (ms). These timers should be used in conjunction with the session termination flags. In TCP mode with option tcplog set on the frontend, 3 control points are reported under the form "Tw/Tc/Tt", and in HTTP mode, 5 control points are reported under the form "Tq/Tw/Tc/Tr/Tt": TqTotal time to get the client request (HTTP mode only). It's the time elapsed between the moment the client connection was accepted and the moment the proxy received the last HTTP header. The value "-1" indicates that the end of headers (empty line) has never been seen. This happens when the client closes prematurely or times out. TwTotal time spent in the queues waiting for a connection slot. It accounts for backend queue as well as the server queues, and depends on the queue size, and the time needed for the server to complete previous requests. The value "-1" means that the request was killed before reaching the queue, which is generally what happens with invalid or denied requests. TcTotal time to establish the TCP connection to the server. It's the time elapsed between the moment the proxy sent the connection request, and the moment it was acknowledged by the server, or between the TCP SYN packet and the matching SYN/ACK packet in return. The value "-1" means that the connection never established. TrServer response time (HTTP mode only). It's the time elapsed between the moment the TCP connection was established to the server and the moment the server sent its complete response headers. It purely shows its request processing time, without the network overhead due to the data transmission. It is worth noting that when the client has data to send to the server, for instance during a POST request, the time already runs, and this can distort apparent response time. For this reason, it's generally wise not to trust too much this field for POST requests initiated from clients behind an untrusted network. A value of "-1" here means that the last the response header (empty line) was never seen, most likely because the server timeout stroke before the server managed to process the request. TtTotal session duration time, between the moment the proxy accepted it and the moment both ends were closed. The exception is when the logasap option is specified. In this case, it only equals (Tq+Tw+Tc+Tr), and is prefixed with a '+' sign. From this field, we can deduce "Td", the data transmission time, by substracting other timers when valid: Td = Tt - (Tq + Tw + Tc + Tr) Timers with "-1" values have to be excluded from this equation. In TCP mode, "Tq" and "Tr" have to be excluded too. Note that "Tt" can never be negative. These timers provide precious indications on trouble causes. Since the TCP protocol defines retransmit delays of 3, 6, 12... seconds, we know for sure that timers close to multiples of 3s are nearly always related to lost packets due to network problems (wires, negotiation, congestion). Moreover, if "Tt" is close to a timeout value specified in the configuration, it often means that a session has been aborted on timeout. Most common cases:
Other noticeable HTTP log cases ('xx' means any value to be ignored): Tq/Tw/Tc/Tr/+TtThe option logasap is present on the frontend and the log was emitted before the data phase. All the timers are valid except "Tt" which is shorter than reality. -1/xx/xx/xx/TtThe client was not able to send a complete request in time or it aborted too early. Check the session termination flags then timeout http-request and timeout client settings. Tq/-1/xx/xx/TtIt was not possible to process the request, maybe because servers were out of order, because the request was invalid or forbidden by ACL rules. Check the session termination flags. Tq/Tw/-1/xx/TtThe connection could not establish on the server. Either it actively refused it or it timed out after Tt-(Tq+Tw) ms. Check the session termination flags, then check the timeout connect setting. Note that the tarpit action might return similar-looking patterns, with "Tw" equal to the time the client connection was maintained open. Tq/Tw/Tc/-1/TtThe server has accepted the connection but did not return a complete response in time, or it closed its connexion unexpectedly after Tt-(Tq+Tw+Tc) ms. Check the session termination flags, then check the timeout server setting. | |