8.9. Examples of logs

  1. These are real-world examples of logs accompanied with an explanation. Some of
  2. them have been made up by hand. The syslog part has been removed for better
  3. reading. Their sole purpose is to explain how to decipher them.
  4.  
  5. >>> haproxy[674]: 127.0.0.1:33318 [15/Oct/2003:08:31:57.130] px-http \
  6. px-http/srv1 6559/0/7/147/6723 200 243 - - ---- 5/3/3/1/0 0/0 \
  7. "HEAD / HTTP/1.0"
  8.  
  9. => long request (6.5s) entered by hand through 'telnet'. The server replied
  10. in 147 ms, and the session ended normally ('----')
  11.  
  12. >>> haproxy[674]: 127.0.0.1:33319 [15/Oct/2003:08:31:57.149] px-http \
  13. px-http/srv1 6559/1230/7/147/6870 200 243 - - ---- 324/239/239/99/0 \
  14. 0/9 "HEAD / HTTP/1.0"
  15.  
  16. => Idem, but the request was queued in the global queue behind 9 other
  17. requests, and waited there for 1230 ms.
  18.  
  19. >>> haproxy[674]: 127.0.0.1:33320 [15/Oct/2003:08:32:17.654] px-http \
  20. px-http/srv1 9/0/7/14/+30 200 +243 - - ---- 3/3/3/1/0 0/0 \
  21. "GET /image.iso HTTP/1.0"
  22.  
  23. => request for a long data transfer. The "logasap" option was specified, so
  24. the log was produced just before transferring data. The server replied in
  25. 14 ms, 243 bytes of headers were sent to the client, and total time from
  26. accept to first data byte is 30 ms.
  27.  
  28. >>> haproxy[674]: 127.0.0.1:33320 [15/Oct/2003:08:32:17.925] px-http \
  29. px-http/srv1 9/0/7/14/30 502 243 - - PH-- 3/2/2/0/0 0/0 \
  30. "GET /cgi-bin/bug.cgi? HTTP/1.0"
  31.  
  32. => the proxy blocked a server response either because of an "rspdeny" or
  33. "rspideny" filter, or because the response was improperly formatted and
  34. not HTTP-compliant, or because it blocked sensitive information which
  35. risked being cached. In this case, the response is replaced with a "502
  36. bad gateway". The flags ("PH--") tell us that it was haproxy who decided
  37. to return the 502 and not the server.
  38.  
  39. >>> haproxy[18113]: 127.0.0.1:34548 [15/Oct/2003:15:18:55.798] px-http \
  40. px-http/<NOSRV> -1/-1/-1/-1/8490 -1 0 - - CR-- 2/2/2/0/0 0/0 ""
  41.  
  42. => the client never completed its request and aborted itself ("C---") after
  43. 8.5s, while the proxy was waiting for the request headers ("-R--").
  44. Nothing was sent to any server.
  45.  
  46. >>> haproxy[18113]: 127.0.0.1:34549 [15/Oct/2003:15:19:06.103] px-http \
  47. px-http/<NOSRV> -1/-1/-1/-1/50001 408 0 - - cR-- 2/2/2/0/0 0/0 ""
  48.  
  49. => The client never completed its request, which was aborted by the
  50. time-out ("c---") after 50s, while the proxy was waiting for the request
  51. headers ("-R--"). Nothing was sent to any server, but the proxy could
  52. send a 408 return code to the client.
  53.  
  54. >>> haproxy[18989]: 127.0.0.1:34550 [15/Oct/2003:15:24:28.312] px-tcp \
  55. px-tcp/srv1 0/0/5007 0 cD 0/0/0/0/0 0/0
  56.  
  57. => This log was produced with "option tcplog". The client timed out after
  58. 5 seconds ("c----").
  59.  
  60. >>> haproxy[18989]: 10.0.0.1:34552 [15/Oct/2003:15:26:31.462] px-http \
  61. px-http/srv1 3183/-1/-1/-1/11215 503 0 - - SC-- 205/202/202/115/3 \
  62. 0/0 "HEAD / HTTP/1.0"
  63.  
  64. => The request took 3s to complete (probably a network problem), and the
  65. connection to the server failed ('SC--') after 4 attempts of 2 seconds
  66. (config says 'retries 3'), and no redispatch (otherwise we would have
  67. seen "/+3"). Status code 503 was returned to the client. There were 115
  68. connections on this server, 202 connections on this proxy, and 205 on
  69. the global process. It is possible that the server refused the
  70. connection because of too many already established.