Hi, On 12.11.2012 11:55, James Bensley wrote: > Hi all, > > I am having an issue on a load-balancer running Pound and HAProxy. I > believe the error is with HAProxy but it doesn't give an error. I think its more a issue of Pound but could you share your timeout settings for pound and haproxy? > Pound sits in front of HAProxy (on the same box) to perform SSL > off-load. Requests are passed to 127.0.0.1:80 where HAProxy then > balances the requests across backend servers for a hosted ASP .NET web > app. > > A user is getting HTTP error 500 (Internal Server Error) returned to > their browser this morning and I can see it is comming from Pound. > They see no log entry in their web app (IIS) server logs, so its not > hitting the back end servers. I think the problem is possibly with > HAProxy. This problem is known in the forums. pound has a default timeout of 15s. So please adjust it by setting it e.g.
*Client 15 ConnTO 60 TimeOut 60* > Lets review the logs: > > Initialy the users (1.2.3.4) hits Pound on the load balancer: > > Nov 12 10:02:24 lb1 pound: a-website.com 1.2.3.4 - - > [12/Nov/2012:10:02:23 +0000] "POST > /eventmanagement/EditEvent.aspx?eventOid=623fc423-2329-4cab-8be5-72a97709570d > HTTP/1.1" 200 155721 > "https://a-website.com/eventmanagement/EditEvent.aspx?eventOid=623fc423-2329-4cab-8be5-72a97709570d"; > "Mozilla/5.0 (Windows NT 6.2; WOW64) AppleWebKit/537.4 (KHTML, like > Gecko) Chrome/22.0.1229.96 Safari/537.4" > > Nov 12 10:02:24 lb1 pound: a-website.com 1.2.3.4 - - > [12/Nov/2012:10:02:24 +0000] "GET > /Controls/ReferringOrganisationLogoImageHandler.ashx HTTP/1.1" 200 142 > "https://a-website.com/eventmanagement/EditEvent.aspx?eventOid=623fc423-2329-4cab-8be5-72a97709570d"; > "Mozilla/5.0 (Windows NT 6.2; WOW64) AppleWebKit/537.4 (KHTML, like > Gecko) Chrome/22.0.1229.96 Safari/537.4" > > Nov 12 10:02:24 lb1 pound: a-website.com 1.2.3.4 - - > [12/Nov/2012:10:02:24 +0000] "GET > /eventmanagement/WebCoreModule.ashx?__ac=1&__ac_wcmid=RAWCIL&__ac_lib=Radactive.WebControls.ILoad&__ac_key=RAWVCO_11&__ac_sid=fnoz2hmvirfivb2btbubbw45&__ac_cn=&__ac_cp=BVDXDWFLDWFMHDFJBOEGBDFLFOD5EEFD&__ac_fr=634883113445054092&__ac_ssid= > HTTP/1.1" 200 11206 > "https://a-website.com/eventmanagement/EditEvent.aspx?eventOid=623fc423-2329-4cab-8be5-72a97709570d"; > "Mozilla/5.0 (Windows NT 6.2; WOW64) AppleWebKit/537.4 (KHTML, like > Gecko) Chrome/22.0.1229.96 Safari/537.4" > > Nov 12 10:02:24 lb1 pound: a-website.com 1.2.3.4 - - > [12/Nov/2012:10:02:24 +0000] "GET > /eventmanagement/WebCoreModule.ashx?__ac=1&__ac_wcmid=RAWCIL&__ac_lib=Radactive.WebControls.ILoad&__ac_key=RAWCCIL_11&__ac_sid=fnoz2hmvirfivb2btbubbw45&__ac_cn=&__ac_cp=BVDXDWFLDWFMHDFJBOEGBDFLFOD5EEFD&__ac_fr=634883113445054092 > HTTP/1.1" 200 43496 > "https://a-website.com/eventmanagement/EditEvent.aspx?eventOid=623fc423-2329-4cab-8be5-72a97709570d"; > "Mozilla/5.0 (Windows NT 6.2; WOW64) AppleWebKit/537.4 (KHTML, like > Gecko) Chrome/22.0.1229.96 Safari/537.4" > > Nov 12 10:02:42 lb1 pound: (7f819fff8700) e500 for 1.2.3.4 > response error read from 127.0.0.1:80/POST > /eventmanagement/EditEvent.aspx?eventOid=623fc423-2329-4cab-8be5-72a97709570d > HTTP/1.1: Connection timed out (15.121 secs) As you see here the default timeout of 15s for pound is reached and so we are. > Above we can see the request coming in from the user at IP address > 1.2.3.4, eventually Pound returns error 500 with the message > "Connection timed out (15.121 secs)". > > Running HAProxy in debug mode, we can see the request come in; > > user@box:/var/log$ sudo /etc/init.d/haproxy restart > Restarting haproxy: haproxy[WARNING] 316/100042 (19218) : <debug> > mode incompatible with <quiet> and <daemon>. Keeping <debug> only. > Available polling systems : > sepoll : pref=400, test result OK > epoll : pref=300, test result OK > poll : pref=200, test result OK > select : pref=150, test result OK > Total: 4 (4 usable), will use sepoll. > Using sepoll() as the polling mechanism. > ....... > 00000008:iis-servers.srvrep[0008:0009]: HTTP/1.1 200 OK > 00000008:iis-servers.srvhdr[0008:0009]: Cache-Control: private > 00000008:iis-servers.srvhdr[0008:0009]: Pragma: no-cache > 00000008:iis-servers.srvhdr[0008:0009]: Content-Length: 22211 > 00000008:iis-servers.srvhdr[0008:0009]: Content-Type: text/plain; > charset=utf-8 > 00000008:iis-servers.srvhdr[0008:0009]: Server: Microsoft-IIS/7.0 > 00000008:iis-servers.srvhdr[0008:0009]: X-AspNet-Version: 2.0.50727 > 00000008:iis-servers.srvhdr[0008:0009]: X-Powered-By: ASP.NET > 00000008:iis-servers.srvhdr[0008:0009]: Date: Mon, 12 Nov 2012 10:01:25 > GMT > 00000009:iis-servers.accept(0004)=000a from [127.0.0.1:53556] > 00000009:iis-servers.clireq[000a:ffff]: GET /Logoff.aspx HTTP/1.1 > 00000009:iis-servers.clihdr[000a:ffff]: Host: a-website.com > 00000009:iis-servers.clihdr[000a:ffff]: Connection: keep-alive > 00000009:iis-servers.clihdr[000a:ffff]: User-Agent: Mozilla/5.0 > (Windows NT 6.2; WOW64) AppleWebKit/537.4 (KHTML, like Gecko) > Chrome/22.0.1229.96 Safari/537.4 > 00000009:iis-servers.clihdr[000a:ffff]: Accept: > text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 > 00000009:iis-servers.clihdr[000a:ffff]: Referer: > https://a-website.com/eventmanagement/eventmanagement.aspx > 00000009:iis-servers.clihdr[000a:ffff]: Accept-Encoding: gzip,deflate,sdch > 00000009:iis-servers.clihdr[000a:ffff]: Accept-Language: > en-GB,en;q=0.8,it;q=0.6 > 00000009:iis-servers.clihdr[000a:ffff]: Accept-Charset: > ISO-8859-1,utf-8;q=0.7,*;q=0.3 > 00000009:iis-servers.clihdr[000a:ffff]: Cookie: > ASP.NET_SessionId=fnoz2hmvirfivb2btbubbw45; apps=apps2; AuthHint=true; > __utma=190546871.552451749.1340295610.1352454675.1352711624.159; > __utmb=190546871.2.10.1352711624; __utmc=190546871; > __utmz=190546871.1349966519.143.3.utmcsr=en.wikipedia.org|utmccn=(referral)|utmcmd=referral|utmcct=/wiki/Single_transferable_vote; > Sequence=162; SessionId=80e603f9-7e73-474b-8b7c-e198b2f11218; > SecureSessionId=00000000-0000-0000-0000-000000000000; > __utma=58336506.1016936529.1332752550.1352454680.1352711626.456; > __utmb=58336506.28.10.1352711626; __utmc=58336506; > __utmz=58336506.1352711626.456.155.utmcsr=a-website.com|utmccn=(referral)|utmcmd=referral|utmcct=/ > 00000009:iis-servers.clihdr[000a:ffff]: X-SSL-cipher: RC4-SHA > SSLv3 Kx=RSA Au=RSA Enc=RC4(128) Mac=SHA1 > 00000009:iis-servers.clihdr[000a:ffff]: X-Forwarded-For: 1.2.3.4 > 00000008:iis-servers.srvcls[0008:0009] > 00000008:iis-servers.clicls[0008:0009] > 00000008:iis-servers.closed[0008:0009] > ....... > 0000000e:iis-servers.srvrep[0008:0009]: HTTP/1.1 200 OK > 0000000e:iis-servers.srvhdr[0008:0009]: Cache-Control: no-cache > 0000000e:iis-servers.srvhdr[0008:0009]: Pragma: no-cache > 0000000e:iis-servers.srvhdr[0008:0009]: Content-Length: 12805 > 0000000e:iis-servers.srvhdr[0008:0009]: Content-Type: text/html; > charset=utf-8 > 0000000e:iis-servers.srvhdr[0008:0009]: Server: Microsoft-IIS/7.0 > 0000000e:iis-servers.srvhdr[0008:0009]: X-AspNet-Version: 2.0.50727 > 0000000e:iis-servers.srvhdr[0008:0009]: X-Powered-By: ASP.NET > 0000000e:iis-servers.srvhdr[0008:0009]: Date: Mon, 12 Nov 2012 10:02:22 > GMT > 0000000f:iis-servers.accept(0004)=000c from [127.0.0.1:53609] > 0000000f:iis-servers.clireq[000c:ffff]: GET > /Controls/ReferringOrganisationLogoImageHandler.ashx HTTP/1.1 > 0000000f:iis-servers.clihdr[000c:ffff]: Host: a-website.com > 0000000f:iis-servers.clihdr[000c:ffff]: Connection: keep-alive > 0000000f:iis-servers.clihdr[000c:ffff]: User-Agent: Mozilla/5.0 > (Windows NT 6.2; WOW64) AppleWebKit/537.4 (KHTML, like Gecko) > Chrome/22.0.1229.96 Safari/537.4 > 0000000f:iis-servers.clihdr[000c:ffff]: Accept: */* > 0000000f:iis-servers.clihdr[000c:ffff]: Referer: > https://a-website.com/eventmanagement/EditEvent.aspx?eventOid=623fc423-2329-4cab-8be5-72a97709570d > 0000000f:iis-servers.clihdr[000c:ffff]: Accept-Encoding: gzip,deflate,sdch > 0000000f:iis-servers.clihdr[000c:ffff]: Accept-Language: > en-GB,en;q=0.8,it;q=0.6 > 0000000f:iis-servers.clihdr[000c:ffff]: Accept-Charset: > ISO-8859-1,utf-8;q=0.7,*;q=0.3 > 0000000f:iis-servers.clihdr[000c:ffff]: Cookie: > ASP.NET_SessionId=fnoz2hmvirfivb2btbubbw45; apps=apps2; > __utma=190546871.552451749.1340295610.1352454675.1352711624.159; > __utmb=190546871.2.10.1352711624; __utmc=190546871; > __utmz=190546871.1349966519.143.3.utmcsr=en.wikipedia.org|utmccn=(referral)|utmcmd=referral|utmcct=/wiki/Single_transferable_vote; > AuthHint=true; > __utma=58336506.1016936529.1332752550.1352454680.1352711626.456; > __utmb=58336506.33.10.1352711626; __utmc=58336506; > __utmz=58336506.1352711626.456.155.utmcsr=a-website.com|utmccn=(referral)|utmcmd=referral|utmcct=/; > SessionId=69cd415c-2f4e-4ace-b8f7-926d054f87c2; > SecureSessionId=00000000-0000-0000-0000-000000000000; Sequence=170 > 0000000f:iis-servers.clihdr[000c:ffff]: X-SSL-cipher: RC4-SHA > SSLv3 Kx=RSA Au=RSA Enc=RC4(128) Mac=SHA1 > 0000000f:iis-servers.clihdr[000c:ffff]: X-Forwarded-For: 1.2.3.4 > 0000000f:iis-servers.srvrep[000c:000d]: HTTP/1.1 200 OK > 0000000f:iis-servers.srvhdr[000c:000d]: Cache-Control: private > 0000000f:iis-servers.srvhdr[000c:000d]: Content-Length: 142 > 0000000f:iis-servers.srvhdr[000c:000d]: Content-Type: image/png > 0000000f:iis-servers.srvhdr[000c:000d]: Server: Microsoft-IIS/7.0 > 0000000f:iis-servers.srvhdr[000c:000d]: X-AspNet-Version: 2.0.50727 > 0000000f:iis-servers.srvhdr[000c:000d]: Set-Cookie: > SessionId=69cd415c-2f4e-4ace-b8f7-926d054f87c2; path=/ > 0000000f:iis-servers.srvhdr[000c:000d]: Set-Cookie: > SecureSessionId=00000000-0000-0000-0000-000000000000; path=/; secure > 0000000f:iis-servers.srvhdr[000c:000d]: X-Powered-By: ASP.NET > 0000000f:iis-servers.srvhdr[000c:000d]: Date: Mon, 12 Nov 2012 10:02:25 > GMT > 0000000e:iis-servers.srvcls[0008:0009] > 0000000e:iis-servers.clicls[0008:0009] > 0000000e:iis-servers.closed[0008:0009] > 0000000f:iis-servers.srvcls[000c:000d] > 0000000f:iis-servers.clicls[000c:000d] > 0000000f:iis-servers.closed[000c:000d] > 00000009:iis-servers.srvcls[000a:000b] > 00000009:iis-servers.clicls[000a:000b] > 00000009:iis-servers.closed[000a:000b] > > Where in the chain is the issue here? > > Many thanks, > James. > > I dont believe its haproxy but you could try to tell haproxy to send a specific page back where error 500 occour. e.g. errorfile 500 /etc/haproxy/errors/500.http cheers thomas
