Haproxy

如何查找和修復 Pound 和 HAProxy 的問題

  • November 12, 2012

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),則會超出此超時時間,呵呵!

改變了這一點,現在已經修復了。

引用自:https://serverfault.com/questions/447776