8.5. Session state at disconnection

  1. TCP and HTTP logs provide a session termination indicator in the
  2. "termination_state" field, just before the number of active connections. It is
  3. 2-characters long in TCP mode, and is extended to 4 characters in HTTP mode,
  4. each of which has a special meaning :
  5.  
  6. - On the first character, a code reporting the first event which caused the
  7. session to terminate :
  8.  
  9. C : the TCP session was unexpectedly aborted by the client.
  10.  
  11. S : the TCP session was unexpectedly aborted by the server, or the
  12. server explicitly refused it.
  13.  
  14. P : the session was prematurely aborted by the proxy, because of a
  15. connection limit enforcement, because a DENY filter was matched,
  16. because of a security check which detected and blocked a dangerous
  17. error in server response which might have caused information leak
  18. (e.g. cacheable cookie).
  19.  
  20. L : the session was locally processed by haproxy and was not passed to
  21. a server. This is what happens for stats and redirects.
  22.  
  23. R : a resource on the proxy has been exhausted (memory, sockets, source
  24. ports, ...). Usually, this appears during the connection phase, and
  25. system logs should contain a copy of the precise error. If this
  26. happens, it must be considered as a very serious anomaly which
  27. should be fixed as soon as possible by any means.
  28.  
  29. I : an internal error was identified by the proxy during a self-check.
  30. This should NEVER happen, and you are encouraged to report any log
  31. containing this, because this would almost certainly be a bug. It
  32. would be wise to preventively restart the process after such an
  33. event too, in case it would be caused by memory corruption.
  34.  
  35. D : the session was killed by haproxy because the server was detected
  36. as down and was configured to kill all connections when going down.
  37.  
  38. U : the session was killed by haproxy on this backup server because an
  39. active server was detected as up and was configured to kill all
  40. backup connections when going up.
  41.  
  42. K : the session was actively killed by an admin operating on haproxy.
  43.  
  44. c : the client-side timeout expired while waiting for the client to
  45. send or receive data.
  46.  
  47. s : the server-side timeout expired while waiting for the server to
  48. send or receive data.
  49.  
  50. - : normal session completion, both the client and the server closed
  51. with nothing left in the buffers.
  52.  
  53. - on the second character, the TCP or HTTP session state when it was closed :
  54.  
  55. R : the proxy was waiting for a complete, valid REQUEST from the client
  56. (HTTP mode only). Nothing was sent to any server.
  57.  
  58. Q : the proxy was waiting in the QUEUE for a connection slot. This can
  59. only happen when servers have a 'maxconn' parameter set. It can
  60. also happen in the global queue after a redispatch consecutive to
  61. a failed attempt to connect to a dying server. If no redispatch is
  62. reported, then no connection attempt was made to any server.
  63.  
  64. C : the proxy was waiting for the CONNECTION to establish on the
  65. server. The server might at most have noticed a connection attempt.
  66.  
  67. H : the proxy was waiting for complete, valid response HEADERS from the
  68. server (HTTP only).
  69.  
  70. D : the session was in the DATA phase.
  71.  
  72. L : the proxy was still transmitting LAST data to the client while the
  73. server had already finished. This one is very rare as it can only
  74. happen when the client dies while receiving the last packets.
  75.  
  76. T : the request was tarpitted. It has been held open with the client
  77. during the whole "timeout tarpit" duration or until the client
  78. closed, both of which will be reported in the "Tw" timer.
  79.  
  80. - : normal session completion after end of data transfer.
  81.  
  82. - the third character tells whether the persistence cookie was provided by
  83. the client (only in HTTP mode) :
  84.  
  85. N : the client provided NO cookie. This is usually the case for new
  86. visitors, so counting the number of occurrences of this flag in the
  87. logs generally indicate a valid trend for the site frequentation.
  88.  
  89. I : the client provided an INVALID cookie matching no known server.
  90. This might be caused by a recent configuration change, mixed
  91. cookies between HTTP/HTTPS sites, persistence conditionally
  92. ignored, or an attack.
  93.  
  94. D : the client provided a cookie designating a server which was DOWN,
  95. so either "option persist" was used and the client was sent to
  96. this server, or it was not set and the client was redispatched to
  97. another server.
  98.  
  99. V : the client provided a VALID cookie, and was sent to the associated
  100. server.
  101.  
  102. E : the client provided a valid cookie, but with a last date which was
  103. older than what is allowed by the "maxidle" cookie parameter, so
  104. the cookie is consider EXPIRED and is ignored. The request will be
  105. redispatched just as if there was no cookie.
  106.  
  107. O : the client provided a valid cookie, but with a first date which was
  108. older than what is allowed by the "maxlife" cookie parameter, so
  109. the cookie is consider too OLD and is ignored. The request will be
  110. redispatched just as if there was no cookie.
  111.  
  112. U : a cookie was present but was not used to select the server because
  113. some other server selection mechanism was used instead (typically a
  114. "use-server" rule).
  115.  
  116. - : does not apply (no cookie set in configuration).
  117.  
  118. - the last character reports what operations were performed on the persistence
  119. cookie returned by the server (only in HTTP mode) :
  120.  
  121. N : NO cookie was provided by the server, and none was inserted either.
  122.  
  123. I : no cookie was provided by the server, and the proxy INSERTED one.
  124. Note that in "cookie insert" mode, if the server provides a cookie,
  125. it will still be overwritten and reported as "I" here.
  126.  
  127. U : the proxy UPDATED the last date in the cookie that was presented by
  128. the client. This can only happen in insert mode with "maxidle". It
  129. happens every time there is activity at a different date than the
  130. date indicated in the cookie. If any other change happens, such as
  131. a redispatch, then the cookie will be marked as inserted instead.
  132.  
  133. P : a cookie was PROVIDED by the server and transmitted as-is.
  134.  
  135. R : the cookie provided by the server was REWRITTEN by the proxy, which
  136. happens in "cookie rewrite" or "cookie prefix" modes.
  137.  
  138. D : the cookie provided by the server was DELETED by the proxy.
  139.  
  140. - : does not apply (no cookie set in configuration).
  141.  
  142. The combination of the two first flags gives a lot of information about what
  143. was happening when the session terminated, and why it did terminate. It can be
  144. helpful to detect server saturation, network troubles, local system resource
  145. starvation, attacks, etc...
  146.  
  147. The most common termination flags combinations are indicated below. They are
  148. alphabetically sorted, with the lowercase set just after the upper case for
  149. easier finding and understanding.
  150.  
  151. Flags Reason
  152.  
  153. -- Normal termination.
  154.  
  155. CC The client aborted before the connection could be established to the
  156. server. This can happen when haproxy tries to connect to a recently
  157. dead (or unchecked) server, and the client aborts while haproxy is
  158. waiting for the server to respond or for "timeout connect" to expire.
  159.  
  160. CD The client unexpectedly aborted during data transfer. This can be
  161. caused by a browser crash, by an intermediate equipment between the
  162. client and haproxy which decided to actively break the connection,
  163. by network routing issues between the client and haproxy, or by a
  164. keep-alive session between the server and the client terminated first
  165. by the client.
  166.  
  167. cD The client did not send nor acknowledge any data for as long as the
  168. "timeout client" delay. This is often caused by network failures on
  169. the client side, or the client simply leaving the net uncleanly.
  170.  
  171. CH The client aborted while waiting for the server to start responding.
  172. It might be the server taking too long to respond or the client
  173. clicking the 'Stop' button too fast.
  174.  
  175. cH The "timeout client" stroke while waiting for client data during a
  176. POST request. This is sometimes caused by too large TCP MSS values
  177. for PPPoE networks which cannot transport full-sized packets. It can
  178. also happen when client timeout is smaller than server timeout and
  179. the server takes too long to respond.
  180.  
  181. CQ The client aborted while its session was queued, waiting for a server
  182. with enough empty slots to accept it. It might be that either all the
  183. servers were saturated or that the assigned server was taking too
  184. long a time to respond.
  185.  
  186. CR The client aborted before sending a full HTTP request. Most likely
  187. the request was typed by hand using a telnet client, and aborted
  188. too early. The HTTP status code is likely a 400 here. Sometimes this
  189. might also be caused by an IDS killing the connection between haproxy
  190. and the client. "option http-ignore-probes" can be used to ignore
  191. connections without any data transfer.
  192.  
  193. cR The "timeout http-request" stroke before the client sent a full HTTP
  194. request. This is sometimes caused by too large TCP MSS values on the
  195. client side for PPPoE networks which cannot transport full-sized
  196. packets, or by clients sending requests by hand and not typing fast
  197. enough, or forgetting to enter the empty line at the end of the
  198. request. The HTTP status code is likely a 408 here. Note: recently,
  199. some browsers started to implement a "pre-connect" feature consisting
  200. in speculatively connecting to some recently visited web sites just
  201. in case the user would like to visit them. This results in many
  202. connections being established to web sites, which end up in 408
  203. Request Timeout if the timeout strikes first, or 400 Bad Request when
  204. the browser decides to close them first. These ones pollute the log
  205. and feed the error counters. Some versions of some browsers have even
  206. been reported to display the error code. It is possible to work
  207. around the undesirable effects of this behavior by adding "option
  208. http-ignore-probes" in the frontend, resulting in connections with
  209. zero data transfer to be totally ignored. This will definitely hide
  210. the errors of people experiencing connectivity issues though.
  211.  
  212. CT The client aborted while its session was tarpitted. It is important to
  213. check if this happens on valid requests, in order to be sure that no
  214. wrong tarpit rules have been written. If a lot of them happen, it
  215. might make sense to lower the "timeout tarpit" value to something
  216. closer to the average reported "Tw" timer, in order not to consume
  217. resources for just a few attackers.
  218.  
  219. LR The request was intercepted and locally handled by haproxy. Generally
  220. it means that this was a redirect or a stats request.
  221.  
  222. SC The server or an equipment between it and haproxy explicitly refused
  223. the TCP connection (the proxy received a TCP RST or an ICMP message
  224. in return). Under some circumstances, it can also be the network
  225. stack telling the proxy that the server is unreachable (e.g. no route,
  226. or no ARP response on local network). When this happens in HTTP mode,
  227. the status code is likely a 502 or 503 here.
  228.  
  229. sC The "timeout connect" stroke before a connection to the server could
  230. complete. When this happens in HTTP mode, the status code is likely a
  231. 503 or 504 here.
  232.  
  233. SD The connection to the server died with an error during the data
  234. transfer. This usually means that haproxy has received an RST from
  235. the server or an ICMP message from an intermediate equipment while
  236. exchanging data with the server. This can be caused by a server crash
  237. or by a network issue on an intermediate equipment.
  238.  
  239. sD The server did not send nor acknowledge any data for as long as the
  240. "timeout server" setting during the data phase. This is often caused
  241. by too short timeouts on L4 equipment before the server (firewalls,
  242. load-balancers, ...), as well as keep-alive sessions maintained
  243. between the client and the server expiring first on haproxy.
  244.  
  245. SH The server aborted before sending its full HTTP response headers, or
  246. it crashed while processing the request. Since a server aborting at
  247. this moment is very rare, it would be wise to inspect its logs to
  248. control whether it crashed and why. The logged request may indicate a
  249. small set of faulty requests, demonstrating bugs in the application.
  250. Sometimes this might also be caused by an IDS killing the connection
  251. between haproxy and the server.
  252.  
  253. sH The "timeout server" stroke before the server could return its
  254. response headers. This is the most common anomaly, indicating too
  255. long transactions, probably caused by server or database saturation.
  256. The immediate workaround consists in increasing the "timeout server"
  257. setting, but it is important to keep in mind that the user experience
  258. will suffer from these long response times. The only long term
  259. solution is to fix the application.
  260.  
  261. sQ The session spent too much time in queue and has been expired. See
  262. the "timeout queue" and "timeout connect" settings to find out how to
  263. fix this if it happens too often. If it often happens massively in
  264. short periods, it may indicate general problems on the affected
  265. servers due to I/O or database congestion, or saturation caused by
  266. external attacks.
  267.  
  268. PC The proxy refused to establish a connection to the server because the
  269. process' socket limit has been reached while attempting to connect.
  270. The global "maxconn" parameter may be increased in the configuration
  271. so that it does not happen anymore. This status is very rare and
  272. might happen when the global "ulimit-n" parameter is forced by hand.
  273.  
  274. PD The proxy blocked an incorrectly formatted chunked encoded message in
  275. a request or a response, after the server has emitted its headers. In
  276. most cases, this will indicate an invalid message from the server to
  277. the client. HAProxy supports chunk sizes of up to 2GB - 1 (2147483647
  278. bytes). Any larger size will be considered as an error.
  279.  
  280. PH The proxy blocked the server's response, because it was invalid,
  281. incomplete, dangerous (cache control), or matched a security filter.
  282. In any case, an HTTP 502 error is sent to the client. One possible
  283. cause for this error is an invalid syntax in an HTTP header name
  284. containing unauthorized characters. It is also possible but quite
  285. rare, that the proxy blocked a chunked-encoding request from the
  286. client due to an invalid syntax, before the server responded. In this
  287. case, an HTTP 400 error is sent to the client and reported in the
  288. logs.
  289.  
  290. PR The proxy blocked the client's HTTP request, either because of an
  291. invalid HTTP syntax, in which case it returned an HTTP 400 error to
  292. the client, or because a deny filter matched, in which case it
  293. returned an HTTP 403 error.
  294.  
  295. PT The proxy blocked the client's request and has tarpitted its
  296. connection before returning it a 500 server error. Nothing was sent
  297. to the server. The connection was maintained open for as long as
  298. reported by the "Tw" timer field.
  299.  
  300. RC A local resource has been exhausted (memory, sockets, source ports)
  301. preventing the connection to the server from establishing. The error
  302. logs will tell precisely what was missing. This is very rare and can
  303. only be solved by proper system tuning.
  304.  
  305. The combination of the two last flags gives a lot of information about how
  306. persistence was handled by the client, the server and by haproxy. This is very
  307. important to troubleshoot disconnections, when users complain they have to
  308. re-authenticate. The commonly encountered flags are :
  309.  
  310. -- Persistence cookie is not enabled.
  311.  
  312. NN No cookie was provided by the client, none was inserted in the
  313. response. For instance, this can be in insert mode with "postonly"
  314. set on a GET request.
  315.  
  316. II A cookie designating an invalid server was provided by the client,
  317. a valid one was inserted in the response. This typically happens when
  318. a "server" entry is removed from the configuration, since its cookie
  319. value can be presented by a client when no other server knows it.
  320.  
  321. NI No cookie was provided by the client, one was inserted in the
  322. response. This typically happens for first requests from every user
  323. in "insert" mode, which makes it an easy way to count real users.
  324.  
  325. VN A cookie was provided by the client, none was inserted in the
  326. response. This happens for most responses for which the client has
  327. already got a cookie.
  328.  
  329. VU A cookie was provided by the client, with a last visit date which is
  330. not completely up-to-date, so an updated cookie was provided in
  331. response. This can also happen if there was no date at all, or if
  332. there was a date but the "maxidle" parameter was not set, so that the
  333. cookie can be switched to unlimited time.
  334.  
  335. EI A cookie was provided by the client, with a last visit date which is
  336. too old for the "maxidle" parameter, so the cookie was ignored and a
  337. new cookie was inserted in the response.
  338.  
  339. OI A cookie was provided by the client, with a first visit date which is
  340. too old for the "maxlife" parameter, so the cookie was ignored and a
  341. new cookie was inserted in the response.
  342.  
  343. DI The server designated by the cookie was down, a new server was
  344. selected and a new cookie was emitted in the response.
  345.  
  346. VI The server designated by the cookie was not marked dead but could not
  347. be reached. A redispatch happened and selected another one, which was
  348. then advertised in the response.