Haproxy
如何查找和修復 Pound 和 HAProxy 的問題
Pound 坐在 HAProxy 前面(在同一個盒子上)以執行 SSL 解除安裝。請求被傳遞到 127.0.0.1:80,HAProxy 然後在後端伺服器之間平衡託管 ASP .NET Web 應用程序的請求。
使用者今天早上收到 HTTP 錯誤 500(內部伺服器錯誤)返回到他們的瀏覽器,我可以看到它來自 Pound。他們在其 Web 應用程序 (IIS) 伺服器日誌中看不到任何日誌條目,因此它不會訪問後端伺服器。我認為問題可能出在 HAProxy 上。
讓我們回顧一下日誌:
最初,使用者(1.2.3.4)在負載均衡器上點擊磅:
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)
上面我們可以看到來自 IP 地址 1.2.3.4 的使用者的請求,最終 Pound 返回錯誤 500,並顯示消息“連接超時(15.121 秒)”。
在調試模式下執行HAProxy,我們可以看到請求進來了;
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]
問題在哪裡?
原來答案一直盯著我看:
Connection timed out (15.121 secs)
Pound 與後端通信的預設超時時間為 15 秒。如果使用者正在進行長時間查詢(例如長時間執行的 POST),則會超出此超時時間,呵呵!
改變了這一點,現在已經修復了。