淺析因Session導(dǎo)致的ASP.NET網(wǎng)站性能問(wèn)題
大家是不是有數(shù)據(jù)庫(kù)沒(méi)有發(fā)現(xiàn)異常，CPU也沒(méi)有異常，內(nèi)存占用量沒(méi)有異常，GC計(jì)數(shù)沒(méi)有異常，硬盤(pán)IO也沒(méi)有異常，帶寬沒(méi)有異常，線(xiàn)路沒(méi)有異常，沒(méi)有丟包，但就是被投訴？而且還是陣發(fā)性的，有某個(gè)用戶(hù)投訴慢的時(shí)候，你訪(fǎng)問(wèn)卻很快，本地又復(fù)現(xiàn)不出來(lái)？今天你訪(fǎng)問(wèn)了博客園真是太幸運(yùn)了，也許這里就有你想要的一個(gè)答案——假如你的站點(diǎn)動(dòng)態(tài)處理了圖片或者其他原本不會(huì)動(dòng)態(tài)處理的非網(wǎng)頁(yè)資源的話(huà)。沒(méi)想到吧，造成ASP.NET網(wǎng)站性能下降的正是Session惹的禍！
我們公司某個(gè)站點(diǎn)訪(fǎng)問(wèn)量一直很大，幾年前就已經(jīng)發(fā)現(xiàn)客戶(hù)經(jīng)常投訴說(shuō)很慢，而這個(gè)問(wèn)題我們一直都在排查和解決。從線(xiàn)路問(wèn)題，到數(shù)據(jù)庫(kù)連接泄露，到數(shù)據(jù)庫(kù)死鎖、索引，以及程序的優(yōu)化問(wèn)題，我們都查找過(guò)，并且解決過(guò)。然而，這個(gè)問(wèn)題總還是存在。比如說(shuō)，在IIS日志中，就會(huì)經(jīng)常看到time-taken大于10秒鐘的訪(fǎng)問(wèn)。而最近我們的KPI要求解決這個(gè)問(wèn)題，不得已，再次踏上這趟艱難的排查之旅。
之所以說(shuō)艱難，是因?yàn)檫@個(gè)現(xiàn)象在本地幾乎無(wú)法復(fù)現(xiàn)，一個(gè)是這個(gè)現(xiàn)象是陣發(fā)性的，第二個(gè)是本地訪(fǎng)問(wèn)量或者數(shù)據(jù)量不夠大。我們也嘗試過(guò)在本地加載線(xiàn)上服務(wù)器的數(shù)據(jù)庫(kù)，然后拿服務(wù)器的IIS的Log文件重播，結(jié)果確實(shí)是偶爾發(fā)現(xiàn)IIS日志中的time-taken也會(huì)比較長(zhǎng)，但是本地服務(wù)器性能不如線(xiàn)上服務(wù)器的，比如說(shuō)IO就差很遠(yuǎn)，于是總說(shuō)不清楚到底是什么問(wèn)題。而線(xiàn)上服務(wù)器也不方便用做Dump的形式查找：第一是因?yàn)榫€(xiàn)上一做Dump，站點(diǎn)就會(huì)在幾分鐘內(nèi)失去響應(yīng)，這樣我們客服的電話(huà)就會(huì)被打爆；另一個(gè)原因還是陣發(fā)性的問(wèn)題，我們不可能一直盯著性能看，然后在發(fā)生問(wèn)題的瞬間做Dump。再說(shuō)了，看性能也看不出來(lái)，因?yàn)槟切╉憫?yīng)時(shí)間很長(zhǎng)的訪(fǎng)問(wèn)，其前后附近的響應(yīng)都特別的快。不可避免的，我們只能夠在代碼里面塞入一些調(diào)試和日志的代碼，以期望能夠得到一些有用的信息。
最開(kāi)始的時(shí)候，我們認(rèn)為最可能的原因是數(shù)據(jù)庫(kù)阻塞，比如正好某一個(gè)訪(fǎng)問(wèn)鎖住某個(gè)數(shù)據(jù)庫(kù)對(duì)象（比如一張表或者某幾行），如果這個(gè)時(shí)候訪(fǎng)問(wèn)特定的頁(yè)面，可能就會(huì)比較慢。于是在數(shù)據(jù)庫(kù)層塞入了一堆代碼，這些代碼會(huì)在數(shù)據(jù)庫(kù)連接數(shù)量多，或者某個(gè)數(shù)據(jù)庫(kù)連接時(shí)間特別長(zhǎng)的時(shí)候，將所有數(shù)據(jù)庫(kù)連接的當(dāng)前訪(fǎng)問(wèn)語(yǔ)句、連接持續(xù)總時(shí)間，以及這些連接當(dāng)前的堆棧情況都輸出到文件中。與此同時(shí)，我們還打開(kāi)Sql profiler對(duì)這個(gè)數(shù)據(jù)庫(kù)進(jìn)行監(jiān)視，將持續(xù)時(shí)間超過(guò)1秒鐘的都記錄下來(lái)。然而跑了一天之后，卻發(fā)現(xiàn)什么都沒(méi)有被記錄下來(lái)，但I(xiàn)IS日志中仍然在這段時(shí)間內(nèi)出現(xiàn)許多10秒以上的訪(fǎng)問(wèn)。這個(gè)時(shí)候，我們就意識(shí)到，可能方向錯(cuò)了。
接著，我們就開(kāi)始塞另外一段代碼：一個(gè)IHttpModule。這個(gè)模塊就只是截獲每一個(gè)頁(yè)面訪(fǎng)問(wèn)的完整生命周期中的所有事件，比如BeginRequest、PreAuthenticateRequest等。同時(shí)在BeginRequest開(kāi)始的時(shí)候設(shè)置一個(gè)定時(shí)器，每隔一秒鐘就會(huì)出發(fā)一個(gè)事件，來(lái)記錄本次訪(fǎng)問(wèn)過(guò)程中，本模塊收集到的所有線(xiàn)程中當(dāng)前的堆棧情況。最后，在EndRequest的時(shí)候，如果訪(fǎng)問(wèn)時(shí)間超過(guò)5秒，就將之前截獲的所有信息輸出到文件中。這一下子問(wèn)題就變得非常的清晰了，比如說(shuō)，下面這種輸出（片斷）就是非常典型的一個(gè)情況：
- #Steps:
- #Fields: date time threadId stepName
- #---------------------------------------------------
- 2009-07-09 16:48:01.752 0024 BeginRequest
- 2009-07-09 16:48:01.752 0024 AuthenticateRequest
- 2009-07-09 16:48:01.752 0024 PostAuthenticateRequest
- 2009-07-09 16:48:01.752 0024 AuthorizeRequest
- 2009-07-09 16:48:01.752 0024 PostAuthorizeRequest
- 2009-07-09 16:48:01.752 0024 ResolveRequestCache
- 2009-07-09 16:48:01.752 0024 PostResolveRequestCache
- 2009-07-09 16:48:01.752 0024 PostMapRequestHandler
- 2009-07-09 16:48:06.284 0007 AcquireRequestState
- 2009-07-09 16:48:06.284 0007 PostAcquireRequestState
- 2009-07-09 16:48:06.284 0007 PreRequestHandlerExecute
- 2009-07-09 16:48:06.284 0007 EndRequest
- #---------------------------------------------------
- #End of steps.
也就是說(shuō)，在PostMapRequestHandler之后，AcquireRequestState之前，有一大段的等待時(shí)間。而這個(gè)報(bào)告后面的堆棧情況，則顯得很奇怪：線(xiàn)程7從第一次截快照的時(shí)候開(kāi)始，一直到結(jié)束都是空白的！甚至在其他的一些報(bào)告中甚至?xí)l(fā)現(xiàn)這個(gè)線(xiàn)程已經(jīng)被分派處理其他頁(yè)面的工作了（堆棧中的調(diào)用很明顯指出是另一個(gè)aspx頁(yè)面的代碼）。結(jié)果一Google“PostMapRequestHandler”和“AcquireRequestState”這兩個(gè)關(guān)鍵字，就找到了國(guó)外另一個(gè)有類(lèi)似ASP.NET網(wǎng)站性能受影響的受害者：
- http://forums.iis.net/t/1147300.aspx
這個(gè)樓主是一個(gè)aspx頁(yè)面里面有好幾個(gè)iframe，并且每一個(gè)iframe里面都是訪(fǎng)問(wèn)同一個(gè)Web應(yīng)用下的Aspx頁(yè)面。現(xiàn)象就是iframe內(nèi)的頁(yè)面會(huì)一個(gè)個(gè)蹦出來(lái)，尤其是這些頁(yè)面都比較慢的時(shí)候。和我這里截獲到的情況一樣，也是PostMapRequestHandler事件到AcquireRequestState之間有很長(zhǎng)的空白時(shí)間。順藤摸瓜，又找到了這么一個(gè)帖子：
http://www.microsoft.com/communities/newsgroups/en-us/default.aspx?dg=microsoft.public.dotnet.framework.aspnet&mid=7f56033f-caac-47c2-bd9c-95512aa14b47
原來(lái)，在A(yíng)cquireRequestState之前，需要等待上一個(gè)同SessionId的頁(yè)面處理完畢之后，才會(huì)繼續(xù)處理當(dāng)前頁(yè)面。其根本原因是：同一個(gè)SessionId下面的Session對(duì)象不應(yīng)該被同時(shí)寫(xiě)入，否則就會(huì)全亂套了，原理和多線(xiàn)程競(jìng)爭(zhēng)是一樣的。因此在設(shè)計(jì)上，同一個(gè)SessionId的頁(yè)面（或者IHttpHandler）就會(huì)順序執(zhí)行。
好了，到這里真相又一次大白了！（指不定還有別的問(wèn)題，還會(huì)有下一次大白的時(shí)候）在我們的系統(tǒng)中，由于特殊的原因，對(duì)圖片的輸出我們會(huì)通過(guò)Asp.Net來(lái)處理，比如說(shuō)加上一些合適的緩存標(biāo)記，甚至?xí)?dòng)態(tài)生成圖片輸出（令人驚訝的是，這個(gè)動(dòng)態(tài)輸出的總時(shí)間消耗甚至不到100毫秒，所以不要說(shuō)動(dòng)態(tài)生成是一種不好的實(shí)施方式）。但是，由于沒(méi)有經(jīng)過(guò)特殊處理，Asp.Net底層認(rèn)為這些訪(fǎng)問(wèn)時(shí)需要對(duì)Session進(jìn)行寫(xiě)操作的，于是就在A(yíng)cquireRequestState之前掛起，等待上一次同SessionId訪(fǎng)問(wèn)結(jié)束。可想而知，圖片多了就會(huì)導(dǎo)致排隊(duì)，甚至排很長(zhǎng)的隊(duì)。如果在排隊(duì)結(jié)束之前訪(fǎng)問(wèn)下一個(gè)頁(yè)面，正好系統(tǒng)又沒(méi)有丟掉之前的隊(duì)列，則這次訪(fǎng)問(wèn)就會(huì)變得比較漫長(zhǎng)了。那么怎么做呢？ 在一次順藤摸瓜，找到了確切的說(shuō)法：
http://msdn.microsoft.com/en-us/library/ms178581.aspx
注意下面的這段話(huà)：
Concurrent Requests and Session State
Access to ASP.NET session state is exclusive per session, which means that if two different users make concurrent requests, access to each separate session is granted concurrently. However, if two concurrent requests are made for the same session (by using the same SessionID value), the first request gets exclusive access to the session information. The second request executes only after the first request is finished. (The second session can also get access if the exclusive lock on the information is freed because the first request exceeds the lock time-out.) If theEnableSessionState value in the @ Page directive is set to ReadOnly, a request for the read-only session information does not result in an exclusive lock on the session data. However, read-only requests for session data might still have to wait for a lock set by a read-write request for session data to clear.
也就是說(shuō)，對(duì)于頁(yè)面，我們可以簡(jiǎn)單的在A(yíng)spx上的<% @Page %>內(nèi)設(shè)置EnableSessionState=”false”，或者EnableSessionState=”ReadOnly”，就可以減輕這種問(wèn)題的癥狀。前一種設(shè)置將會(huì)禁止對(duì)Session的訪(fǎng)問(wèn)，而后一種設(shè)置則只能允許只讀訪(fǎng)問(wèn)（你不能夠?qū)ession進(jìn)行寫(xiě)操作）。正好，我們剛才提到的IHttpHandler中，對(duì)圖片進(jìn)行處理的部分，是不需要對(duì)Session進(jìn)行寫(xiě)操作的，但是卻需要讀取Session（根據(jù)狀態(tài)不同，而需要獲取一些特殊信息），因此可以采取上述的措施來(lái)解決問(wèn)題。
上述參考文獻(xiàn)中，并沒(méi)有說(shuō)明如何對(duì)不是Page的IHttpHandler如何設(shè)置，這里我特別說(shuō)明一下。對(duì)于自定義的一個(gè)實(shí)現(xiàn)了IHttpHandler接口的類(lèi)，只要同時(shí)實(shí)現(xiàn)IReadOnlySessionState，即可達(dá)到EnableSessionState="ReadOnly"的效果。同時(shí)，如果沒(méi)有實(shí)現(xiàn)IRequiresSessionState，則等價(jià)于EnableSessionState=”false”的效果。
注意：本文所說(shuō)的，不是說(shuō)你在代碼里面有沒(méi)有用到Session，ASP.NET不會(huì)掃描你的代碼看看有沒(méi)有訪(fǎng)問(wèn)Session，或者在你第一次訪(fǎng)問(wèn)Session的時(shí)候才會(huì)加鎖。ASP.NET是在A(yíng)cquireRequestState事件之前就首先申請(qǐng)這個(gè)鎖——只要你的頁(yè)面沒(méi)有設(shè)置EnableSessionState=”false”或EnableSessionState=”ReadOnly”，或者你的IHttpHandler實(shí)現(xiàn)了IRequiresSessionState卻沒(méi)有實(shí)現(xiàn)IReadOnlySessionState接口就會(huì)這樣。回復(fù)中有很多同學(xué)說(shuō)“只要我不用Session不就行了嗎？”或者“我從來(lái)不用Session”，這么想完全是錯(cuò)誤的，只能說(shuō)你沒(méi)有理解這背后的機(jī)制，甚至可能連Asp.net生命周期都不太清楚。Asp.Net之所以在你的頁(yè)面代碼開(kāi)始執(zhí)行之前就鎖定，是要保證整個(gè)環(huán)境的完整性，避免部分執(zhí)行的情況。當(dāng)然，也正如上面的一些引用中所提到的，你可以自己寫(xiě)一個(gè)SessionProvider而不做任何的鎖工作，但這樣做肯定有不確定性的風(fēng)險(xiǎn)，到時(shí)候只能你自己承擔(dān)，并且更難復(fù)現(xiàn)和調(diào)試。
ASP.NET網(wǎng)站性能分析后記：
可能有不少人都知道Session是什么，也有很多人知道ASP.NET的生命周期都包含哪些，比如一搜索"PostMapRequestHandler AcquireRequestState"，就會(huì)出來(lái)很多中文的頁(yè)面介紹HttpApplication類(lèi)都有哪些事件，以及生命周期等等。而說(shuō)到Session會(huì)造成特殊情況下站點(diǎn)性能問(wèn)題的，似乎中文界我這還真是第一篇。當(dāng)然了，這個(gè)問(wèn)題可能比較偏，因?yàn)橐话愦蠹叶贾粫?huì)處理Aspx頁(yè)面而不會(huì)處理圖片，甚至用Aspx頁(yè)面來(lái)動(dòng)態(tài)輸出圖片的機(jī)會(huì)都比較少，英文的似乎也只有文中提到的唯一一個(gè)同志提出來(lái)了。
不過(guò)，有一個(gè)很常見(jiàn)的場(chǎng)景會(huì)受這個(gè)問(wèn)題的影響，那就是“驗(yàn)證碼”。如果驗(yàn)證碼生成速度很慢，同時(shí)客戶(hù)端瀏覽器選擇長(zhǎng)連接而服務(wù)器也接受長(zhǎng)連接，則可能會(huì)影響在輸出驗(yàn)證碼完畢之前訪(fǎng)問(wèn)下一個(gè)頁(yè)面的速度。反過(guò)來(lái)，我們也經(jīng)常可以體驗(yàn)到，驗(yàn)證碼出來(lái)的速度總是特別慢，總是“蹦”出來(lái)的，尤其是當(dāng)前頁(yè)面特別復(fù)雜的時(shí)候，似乎頁(yè)面沒(méi)有加載完就總不會(huì)出現(xiàn)驗(yàn)證碼。估計(jì)我說(shuō)的問(wèn)題就是原因之一。
不過(guò)驗(yàn)證碼的問(wèn)題還不是特別好解決，因?yàn)闉榱吮苊庑畔⑿孤兜膯?wèn)題，驗(yàn)證碼的答案通常是存在在Session里面的，而通常的設(shè)計(jì)也是一訪(fǎng)問(wèn)驗(yàn)證碼圖片，就會(huì)將驗(yàn)證碼答案寫(xiě)到Session里面。所以，很不幸，文中提到的那個(gè)解決辦法是行不通的，至少不是能夠直接行得通的。這個(gè)問(wèn)題有沒(méi)有救藥？有，當(dāng)然有了。怎么救？哈，那就有勞你自己開(kāi)動(dòng)腦筋了，我這里算是點(diǎn)到即止了。
【編輯推薦】
