Re: HAProxy - 504 Gateway Timeout error.
Willy Tarreau w at 1wt.eu writes: Hi, On Thu, Jul 14, 2011 at 10:21:56AM +, gidot wrote: Thanks Willy, I managed to fix the problem with the log. It's due to my entry in /etc/ syslogd.conf. This thread http://www.serverphorums.com/read.php? 10,127228,127867 helped me out :). Here is the excerpt of my haproxy.log. Hope someone can enlighten me if there's anything obvious from this log that can help me to troubleshoot my problem. Here's from grep'ing 504: Jul 13 20:37:57 localhost haproxy[98507]: 213.47.109.71:51261 [13/ Jul/2011:20:37:07.967] webjailfarm webjailfarm/wj01 7/0/0/-1/+50009 504 +194 - - sHVN 62/62/52/12/0 0/0 GET /main.php?location=war HTTP/1.1 (...) All of these logs indicate that the server is simply not responding within 50 seconds. As frustrating as this can be, this is something quite common when servers get overloaded or when they try to access a locked resource. The two following ones however are more concerning : Jul 13 20:41:25 localhost haproxy[98507]: 188.123.218.31:4180 [13/ Jul/2011:20:40:35.132] webjailfarm webjailfarm/wj08 2/0/0/-1/+50005 504 +194 - - sHVN 78/78/61/4/0 0/0 GET /images/gamefavicons.png HTTP/1.1 Jul 13 20:43:36 localhost haproxy[98507]: 217.246.8.81:2284 [13/ Jul/2011:20:42:46.796] webjailfarm webjailfarm/wj05 1/0/0/-1/+50003 504 +194 - - sHVN 56/56/46/0/0 0/0 GET /emptyicon.gif HTTP/1.1 I think that such resources are purely static and have no reason not to be quickly delivered. Is there any possibility that the same servers are accessed via other backend sections, or even directly without passing via haproxy ? I'm asking because what I suspect is that the server's connection limit is reached due to other activity, but the listening socket is not yet saturated, so our request lies in the server's backlog until a connection is released so that a process (or thread) can process the pending request (which did not happen in time here). And some others: Jul 13 20:38:08 localhost haproxy[98507]: 89.228.101.118:51199 [13/ Jul/2011:20:38:08.893] webjailfarm webjailfarm/wj05 0/0/-1/-1/+1 503 +212 - - SCDN 44/44/37/7/+3 0/0 POST /login.php HTTP/1.1 The connection was referencing a server which was already detected as DOWN (hence the D flag), so the health checks have noticed the event. The connection was redispatched onto another server (wj05) but the connection failed there. It could be the same thing as above, but with the backlog full, so the system is rejecting extra connections instead of queuing them. It could also be that you restarted the server and the connections were attempted while the port was not bound. Jul 13 20:38:14 localhost haproxy[98507]: 188.101.27.150:61567 [13/ Jul/2011:20:38:14.883] webjailfarm webjailfarm/wj06 13/0/1/-1/+14 502 +204 - - SHVN 53/53/47/7/0 0/0 GET /js/scriptaculous.js?load=effects,slider HTTP/1.1 The 502s normally indicate that the server broke the connection without responding. This can be the consequence of a server restart as well as it can indicate dying processes. At the moment we're still having problems with clients receiving 502 and 504 errors. It was quiet for the first few days after we have tuned the box, but since 2 days ago, they're back. If you check your stats page, you should see that your servers state are changing a lot. A server must not flap, it must have a steady state. In my opinion, the fact that they're seen down is not the cause of the problem but one of the consequences : something is blocking your servers or making them process requests slowly and at one point they can't even process health checks anymore. Requests are aborted on timeouts and checks fail, causing the server to be marked down. This is normally what happens when servers connection limit gets overflown. You may want to try to increase your MaxClients or equivalent. Be careful though, as this can imply a higher memory usage. Another solution people generally like is to split dynamic/static contents, which is called content switching. You build a farm out of a very fast and scalable server such as nginx and send the static requests there. You keep the rest on current servers, the load should drop quite a bit. Btw, I tried to run the command echo show sess | socat stdio /var/run/ haproxy/ haproxy.sock, and some entries show that it's not forwarding to any server (none). Is this normal? [/root] # echo show sess | socat stdio /var/run/haproxy/haproxy.sock 0x800fbfc00: proto=tcpv4 src=178.190.178.184:52094 fe=webjailfarm be=webjailfarm srv=none ts=02 age=46s calls=1 rq [f=501000h,l=0,an=0eh,rx=3s,wx=,ax=] rp[f=001000h,l=0,an=00h,rx=,wx=,ax=] s0= [7,18h,fd=55,ex=] s1=[0,0h,fd=-1,ex=] exp=3s (...) It is normal for connections which have not yet sent a full request. In your case, the request buffer is empty so nothing was received from the client. Until you don't see
HAProxy - 504 Gateway Timeout error.
Thanks Willy, I managed to fix the problem with the log. It's due to my entry in /etc/ syslogd.conf. This thread http://www.serverphorums.com/read.php? 10,127228,127867 helped me out :). Here is the excerpt of my haproxy.log. Hope someone can enlighten me if there's anything obvious from this log that can help me to troubleshoot my problem. Here's from grep'ing 504: Jul 13 20:37:57 localhost haproxy[98507]: 213.47.109.71:51261 [13/ Jul/2011:20:37:07.967] webjailfarm webjailfarm/wj01 7/0/0/-1/+50009 504 +194 - - sHVN 62/62/52/12/0 0/0 GET /main.php?location=war HTTP/1.1 Jul 13 20:38:08 localhost haproxy[98507]: 213.47.109.71:51265 [13/ Jul/2011:20:37:18.348] webjailfarm webjailfarm/wj01 45/0/0/-1/+50047 504 +194 - - sHVN 44/44/37/8/0 0/0 GET /main.php?location=war HTTP/1.1 Jul 13 20:40:10 localhost haproxy[98507]: 2.202.200.168:56122 [13/ Jul 13 20:41:25 localhost haproxy[98507]: 188.123.218.31:4180 [13/ Jul/2011:20:40:35.132] webjailfarm webjailfarm/wj08 2/0/0/-1/+50005 504 +194 - - sHVN 78/78/61/4/0 0/0 GET /images/gamefavicons.png HTTP/1.1 Jul 13 20:43:36 localhost haproxy[98507]: 217.246.8.81:2284 [13/ Jul/2011:20:42:46.796] webjailfarm webjailfarm/wj05 1/0/0/-1/+50003 504 +194 - - sHVN 56/56/46/0/0 0/0 GET /emptyicon.gif HTTP/1.1 Jul 13 20:44:33 localhost haproxy[98507]: 41.141.73.47:2654 [13/ Jul/2011:20:43:43.659] webjailfarm webjailfarm/wj08 21/0/1/-1/+50023 504 +194 - - sHVN 175/175/166/18/0 0/0 GET /getCSS.php?css= %2Fae1%2F68%2F4885%2E1255006208%2E104491%2Ecss HTTP/1.1 Jul 13 20:44:38 localhost haproxy[98507]: 87.160.231.110:4937 [13/ Jul/2011:20:43:48.808] webjailfarm webjailfarm/wj01 16/0/0/-1/+50017 504 +194 - - sHVN 166/166/162/27/0 0/0 GET /main.php? location=ausbildenunitid=5enforcename=yestraincount=20dotraining=yesbase template=0unitname=Drachenritter HTTP/1.1 Jul 13 20:44:42 localhost haproxy[98507]: 41.178.69.109:3476 [13/ Jul/2011:20:43:51.877] webjailfarm webjailfarm/wj04 17/0/0/-1/+50308 504 +194 - - sHVN 182/182/175/37/0 0/0 POST /main.php? location=einheitenmultiple=yesaction=eggsearchunit=2163081confirm=yes HTTP/1.1 Jul 13 20:44:44 localhost haproxy[98507]: 190.165.104.203:1659 [13/ Jul/2011:20:43:54.463] webjailfarm webjailfarm/wj03 16/0/0/-1/+50016 504 +194 - - sHVN 195/195/190/47/0 0/0 GET /main.php HTTP/1.1 Jul 13 20:44:44 localhost haproxy[98507]: 178.190.206.19:51649 [13/ Jul/2011:20:43:54.700] webjailfarm webjailfarm/wj01 11/0/0/-1/+50013 504 +194 - - sHVN 186/186/182/30/0 0/0 GET /actions.php? location=statusaction=markstatusreadcurtime=1310582637630 HTTP/1.1 And some others: Jul 13 20:38:08 localhost haproxy[98507]: 89.228.101.118:51199 [13/ Jul/2011:20:38:08.893] webjailfarm webjailfarm/wj05 0/0/-1/-1/+1 503 +212 - - SCDN 44/44/37/7/+3 0/0 POST /login.php HTTP/1.1 Jul 13 20:38:14 localhost haproxy[98507]: 188.101.27.150:61567 [13/ Jul/2011:20:38:14.883] webjailfarm webjailfarm/wj06 13/0/1/-1/+14 502 +204 - - SHVN 53/53/47/7/0 0/0 GET /js/scriptaculous.js?load=effects,slider HTTP/1.1 Jul 13 20:38:18 localhost haproxy[98507]: 89.228.65.164:49289 [13/ Jul/2011:20:38:18.818] webjailfarm webjailfarm/wj06 4/0/0/-1/+5 502 +204 - - SHVN 50/50/42/3/0 0/0 GET /js/slider.js HTTP/1.1 Jul 13 20:38:19 localhost haproxy[98507]: 2.11.13.226:2047 [13/ Jul/2011:20:38:19.221] webjailfarm webjailfarm/wj08 8/0/-1/-1/+8 503 +212 - - SCDN 51/51/41/6/+3 0/0 GET /templates/templates/fr/langfile.js HTTP/1.1 Jul 13 20:38:29 localhost haproxy[98507]: 217.247.188.220:3081 [13/ Jul/2011:20:38:29.536] webjailfarm webjailfarm/wj05 58/0/0/-1/+58 502 +204 - - SHVN 64/64/54/6/0 0/0 GET /images/de/gbg/cssgroup/standard.css HTTP/1.1 Jul 13 20:38:31 localhost haproxy[98507]: 89.186.148.213:2198 [13/ Jul/2011:20:38:31.764] webjailfarm webjailfarm/wj07 0/0/0/-1/+0 502 +204 - - SHVN 56/56/47/5/0 0/0 GET /js/scriptaculous.js?load=effects,slider HTTP/1.1 At the moment we're still having problems with clients receiving 502 and 504 errors. It was quiet for the first few days after we have tuned the box, but since 2 days ago, they're back. Btw, I tried to run the command echo show sess | socat stdio /var/run/haproxy/ haproxy.sock, and some entries show that it's not forwarding to any server (none). Is this normal? [/root] # echo show sess | socat stdio /var/run/haproxy/haproxy.sock 0x800fbfc00: proto=tcpv4 src=178.190.178.184:52094 fe=webjailfarm be=webjailfarm srv=none ts=02 age=46s calls=1 rq [f=501000h,l=0,an=0eh,rx=3s,wx=,ax=] rp[f=001000h,l=0,an=00h,rx=,wx=,ax=] s0= [7,18h,fd=55,ex=] s1=[0,0h,fd=-1,ex=] exp=3s 0x800fc2600: proto=tcpv4 src=94.222.121.57:18221 fe=webjailfarm be=webjailfarm srv=wj01 ts=08 age=37s calls=6 rq[f=4909000h,l=0,an=00h,rx=13s,wx=,ax=] rp [f=10b020h,l=0,an=00h,rx=,wx=,ax=] s0=[7,10h,fd=11,ex=] s1=[7,18h,fd=7,ex=] exp=13s 0x801a71800: proto=tcpv4 src=178.198.246.35:64612 fe=webjailfarm be=webjailfarm srv=none ts=02 age=34s calls=1 rq[f=501000h,l=0,an=0eh,rx=16s,wx=,ax=] rp [f=001000h,l=0,an=00h,rx=,wx=,ax=] s0=[7,18h,fd=44,ex=]
Re: HAProxy -
Baptiste bedis9@... writes: hi, Your maxconn seems a bit low if you have a lot of clients... Maybe you should try increasing it or at lease increase the queue timeout. As hank said, turn on http log, it will provide you very interesting information about your issue. cheers Thanks for the replies. I've enabled the httplog option under the listen section: 8--- listen webjailfarm 78.143.58.74:80 mode http option httplog option logasap log global cookie SERVERID insert nocache indirect 8--- But seems that nothing changes on the log. All I have in the log is: [8:54am] root@webm01 [/usr/local/etc] # tail -f /var/log/haproxy.log Jul 3 13:41:05 webm01 haproxy[61837]: Proxy webjailfarm started. Jul 4 06:15:15 webm01 haproxy[12884]: Proxy webjailfarm started. I have restarted syslogd as well. Is there anything else that I should do beside adding those lines? Thanks.
