|
你的站點(diǎn)有被客戶投訴很慢嗎?是不是查了很多遍還是沒有完全解決?是不是數(shù)據(jù)庫(kù)沒有發(fā)現(xiàn)異常,CPU也沒有異常,內(nèi)存占用量沒有異常,GC計(jì)數(shù)沒有異常,硬盤IO也沒有異常,帶寬沒有異常,線路沒有異常,沒有丟包,但就是被投訴?而且還是陣發(fā)性的,有某個(gè)用戶投訴慢的時(shí)候,你訪問卻很快,本地又復(fù)現(xiàn)不出來?今天你訪問了博客園真是太幸運(yùn)了,也許這里就有你想要的一個(gè)答案——假如你的站點(diǎn)動(dòng)態(tài)處理了圖片或者其他原本不會(huì)動(dòng)態(tài)處理的非網(wǎng)頁(yè)資源的話。沒想到吧,這是Session惹的禍!
我們公司某個(gè)站點(diǎn)訪問量一直很大,幾年前就已經(jīng)發(fā)現(xiàn)客戶經(jīng)常投訴說很慢,而這個(gè)問題我們一直都在排查和解決。從線路問題,到數(shù)據(jù)庫(kù)連接泄露,到數(shù)據(jù)庫(kù)死鎖、索引,以及程序的優(yōu)化問題,我們都查找過,并且解決過。然而,這個(gè)問題總還是存在。比如說,在IIS日志中,就會(huì)經(jīng)常看到time-taken大于10秒鐘的訪問。而最近我們的KPI要求解決這個(gè)問題,不得已,再次踏上這趟艱難的排查之旅。
之所以說艱難,是因?yàn)檫@個(gè)現(xiàn)象在本地幾乎無法復(fù)現(xiàn),一個(gè)是這個(gè)現(xiàn)象是陣發(fā)性的,第二個(gè)是本地訪問量或者數(shù)據(jù)量不夠大。我們也嘗試過在本地加載線上服務(wù)器的數(shù)據(jù)庫(kù),然后拿服務(wù)器的IIS的Log文件重播,結(jié)果確實(shí)是偶爾發(fā)現(xiàn)IIS日志中的time-taken也會(huì)比較長(zhǎng),但是本地服務(wù)器性能不如線上服務(wù)器的,比如說IO就差很遠(yuǎn),于是總說不清楚到底是什么問題。而線上服務(wù)器也不方便用做Dump的形式查找:第一是因?yàn)榫€上一做Dump,站點(diǎn)就會(huì)在幾分鐘內(nèi)失去響應(yīng),這樣我們客服的電話就會(huì)被打爆;另一個(gè)原因還是陣發(fā)性的問題,我們不可能一直盯著性能看,然后在發(fā)生問題的瞬間做Dump。再說了,看性能也看不出來,因?yàn)槟切╉憫?yīng)時(shí)間很長(zhǎng)的訪問,其前后附近的響應(yīng)都特別的快。不可避免的,我們只能夠在代碼里面塞入一些調(diào)試和日志的代碼,以期望能夠得到一些有用的信息。
最開始的時(shí)候,我們認(rèn)為最可能的原因是數(shù)據(jù)庫(kù)阻塞,比如正好某一個(gè)訪問鎖住某個(gè)數(shù)據(jù)庫(kù)對(duì)象(比如一張表或者某幾行),如果這個(gè)時(shí)候訪問特定的頁(yè)面,可能就會(huì)比較慢。于是在數(shù)據(jù)庫(kù)層塞入了一堆代碼,這些代碼會(huì)在數(shù)據(jù)庫(kù)連接數(shù)量多,或者某個(gè)數(shù)據(jù)庫(kù)連接時(shí)間特別長(zhǎng)的時(shí)候,將所有數(shù)據(jù)庫(kù)連接的當(dāng)前訪問語(yǔ)句、連接持續(xù)總時(shí)間,以及這些連接當(dāng)前的堆棧情況都輸出到文件中。與此同時(shí),我們還打開Sql profiler對(duì)這個(gè)數(shù)據(jù)庫(kù)進(jìn)行監(jiān)視,將持續(xù)時(shí)間超過1秒鐘的都記錄下來。然而跑了一天之后,卻發(fā)現(xiàn)什么都沒有被記錄下來,但I(xiàn)IS日志中仍然在這段時(shí)間內(nèi)出現(xiàn)許多10秒以上的訪問。這個(gè)時(shí)候,我們就意識(shí)到,可能方向錯(cuò)了。
接著,我們就開始塞另外一段代碼:一個(gè)IHttpModule。這個(gè)模塊就只是截獲每一個(gè)頁(yè)面訪問的完整生命周期中的所有事件,比如BeginRequest、PreAuthenticateRequest等。同時(shí)在BeginRequest開始的時(shí)候設(shè)置一個(gè)定時(shí)器,每隔一秒鐘就會(huì)出發(fā)一個(gè)事件,來記錄本次訪問過程中,本模塊收集到的所有線程中當(dāng)前的堆棧情況。最后,在EndRequest的時(shí)候,如果訪問時(shí)間超過5秒,就將之前截獲的所有信息輸出到文件中。這一下子問題就變得非常的清晰了,比如說,下面這種輸出(片斷)就是非常典型的一個(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.
也就是說,在PostMapRequestHandler之后,AcquireRequestState之前,有一大段的等待時(shí)間。而這個(gè)報(bào)告后面的堆棧情況,則顯得很奇怪:線程7從第一次截快照的時(shí)候開始,一直到結(jié)束都是空白的!甚至在其他的一些報(bào)告中甚至?xí)l(fā)現(xiàn)這個(gè)線程已經(jīng)被分派處理其他頁(yè)面的工作了(堆棧中的調(diào)用很明顯指出是另一個(gè)ASPx頁(yè)面的代碼)。結(jié)果一Google“PostMapRequestHandler”和“AcquireRequestState”這兩個(gè)關(guān)鍵字,就找到了國(guó)外另一個(gè)有類似遭遇的受害者:
http://forums.iis.NET/t/1147300.ASPx
這個(gè)樓主是一個(gè)ASPx頁(yè)面里面有好幾個(gè)iframe,并且每一個(gè)iframe里面都是訪問同一個(gè)Web應(yīng)用下的ASPx頁(yè)面。現(xiàn)象就是iframe內(nèi)的頁(yè)面會(huì)一個(gè)個(gè)蹦出來,尤其是這些頁(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
原來,在AcquireRequestState之前,需要等待上一個(gè)同SessionId的頁(yè)面處理完畢之后,才會(huì)繼續(xù)處理當(dāng)前頁(yè)面。其根本原因是:同一個(gè)SessionId下面的Session對(duì)象不應(yīng)該被同時(shí)寫入,否則就會(huì)全亂套了,原理和多線程競(jìng)爭(zhēng)是一樣的。因此在設(shè)計(jì)上,同一個(gè)SessionId的頁(yè)面(或者IHttpHandler)就會(huì)順序執(zhí)行。
好了,到這里真相又一次大白了!(指不定還有別的問題,還會(huì)有下一次大白的時(shí)候)在我們的系統(tǒng)中,由于特殊的原因,對(duì)圖片的輸出我們會(huì)通過ASP.NET來處理,比如說加上一些合適的緩存標(biāo)記,甚至?xí)?dòng)態(tài)生成圖片輸出(令人驚訝的是,這個(gè)動(dòng)態(tài)輸出的總時(shí)間消耗甚至不到100毫秒,所以不要說動(dòng)態(tài)生成是一種不好的實(shí)施方式)。但是,由于沒有經(jīng)過特殊處理,ASP.NET底層認(rèn)為這些訪問時(shí)需要對(duì)Session進(jìn)行寫操作的,于是就在AcquireRequestState之前掛起,等待上一次同SessionId訪問結(jié)束。可想而知,圖片多了就會(huì)導(dǎo)致排隊(duì),甚至排很長(zhǎng)的隊(duì)。如果在排隊(duì)結(jié)束之前訪問下一個(gè)頁(yè)面,正好系統(tǒng)又沒有丟掉之前的隊(duì)列,則這次訪問就會(huì)變得比較漫長(zhǎng)了。那么怎么做呢? 在一次順藤摸瓜,找到了確切的說法:
http://msdn.microsoft.com/en-us/library/ms178581.ASPx
注意下面的這段話:
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.
也就是說,對(duì)于頁(yè)面,我們可以簡(jiǎn)單的在ASPx上的<% @Page %>內(nèi)設(shè)置EnableSessionState=”false”,或者EnableSessionState=”ReadOnly”,就可以減輕這種問題的癥狀。前一種設(shè)置將會(huì)禁止對(duì)Session的訪問,而后一種設(shè)置則只能允許只讀訪問(你不能夠?qū)ession進(jìn)行寫操作)。正好,我們剛才提到的IHttpHandler中,對(duì)圖片進(jìn)行處理的部分,是不需要對(duì)Session進(jìn)行寫操作的,但是卻需要讀取Session(根據(jù)狀態(tài)不同,而需要獲取一些特殊信息),因此可以采取上述的措施來解決問題。
上述參考文獻(xiàn)中,并沒有說明如何對(duì)不是Page的IHttpHandler如何設(shè)置,這里我特別說明一下。對(duì)于自定義的一個(gè)實(shí)現(xiàn)了IHttpHandler接口的類,只要同時(shí)實(shí)現(xiàn)IReadOnlySessionState,即可達(dá)到EnableSessionState="ReadOnly"的效果。同時(shí),如果沒有實(shí)現(xiàn)IRequiresSessionState,則等價(jià)于EnableSessionState=”false”的效果。
注意:本文所說的,不是說你在代碼里面有沒有用到Session,ASP.NET不會(huì)掃描你的代碼看看有沒有訪問Session,或者在你第一次訪問Session的時(shí)候才會(huì)加鎖。ASP.NET是在AcquireRequestState事件之前就首先申請(qǐng)這個(gè)鎖——只要你的頁(yè)面沒有設(shè)置EnableSessionState=”false”或EnableSessionState=”ReadOnly”,或者你的IHttpHandler實(shí)現(xiàn)了IRequiresSessionState卻沒有實(shí)現(xiàn)IReadOnlySessionState接口就會(huì)這樣。回復(fù)中有很多同學(xué)說“只要我不用Session不就行了嗎?”或者“我從來不用Session”,這么想完全是錯(cuò)誤的,只能說你沒有理解這背后的機(jī)制,甚至可能連ASP.NET生命周期都不太清楚。ASP.NET之所以在你的頁(yè)面代碼開始執(zhí)行之前就鎖定,是要保證整個(gè)環(huán)境的完整性,避免部分執(zhí)行的情況。當(dāng)然,也正如上面的一些引用中所提到的,你可以自己寫一個(gè)SessionProvider而不做任何的鎖工作,但這樣做肯定有不確定性的風(fēng)險(xiǎn),到時(shí)候只能你自己承擔(dān),并且更難復(fù)現(xiàn)和調(diào)試。
后記:
可能有不少人都知道Session是什么,也有很多人知道ASP.NET的生命周期都包含哪些,比如一搜索"PostMapRequestHandler AcquireRequestState",就會(huì)出來很多中文的頁(yè)面介紹HttpApplication類都有哪些事件,以及生命周期等等。而說到Session會(huì)造成特殊情況下站點(diǎn)性能問題的,似乎中文界我這還真是第一篇。當(dāng)然了,這個(gè)問題可能比較偏,因?yàn)橐话愦蠹叶贾粫?huì)處理ASPx頁(yè)面而不會(huì)處理圖片,甚至用ASPx頁(yè)面來動(dòng)態(tài)輸出圖片的機(jī)會(huì)都比較少,英文的似乎也只有文中提到的唯一一個(gè)同志提出來了。
不過,有一個(gè)很常見的場(chǎng)景會(huì)受這個(gè)問題的影響,那就是“驗(yàn)證碼”。如果驗(yàn)證碼生成速度很慢,同時(shí)客戶端瀏覽器選擇長(zhǎng)連接而服務(wù)器也接受長(zhǎng)連接,則可能會(huì)影響在輸出驗(yàn)證碼完畢之前訪問下一個(gè)頁(yè)面的速度。反過來,我們也經(jīng)常可以體驗(yàn)到,驗(yàn)證碼出來的速度總是特別慢,總是“蹦”出來的,尤其是當(dāng)前頁(yè)面特別復(fù)雜的時(shí)候,似乎頁(yè)面沒有加載完就總不會(huì)出現(xiàn)驗(yàn)證碼。估計(jì)我說的問題就是原因之一。
不過驗(yàn)證碼的問題還不是特別好解決,因?yàn)闉榱吮苊庑畔⑿孤兜膯栴},驗(yàn)證碼的答案通常是存在在Session里面的,而通常的設(shè)計(jì)也是一訪問驗(yàn)證碼圖片,就會(huì)將驗(yàn)證碼答案寫到Session里面。所以,很不幸,文中提到的那個(gè)解決辦法是行不通的,至少不是能夠直接行得通的。這個(gè)問題有沒有救藥?有,當(dāng)然有了。怎么救?哈,那就有勞你自己開動(dòng)腦筋了,我這里算是點(diǎn)到即止了。
NET技術(shù):你知道嗎?——ASP.NET的Session會(huì)導(dǎo)致的性能問題,轉(zhuǎn)載需保留來源!
鄭重聲明:本文版權(quán)歸原作者所有,轉(zhuǎn)載文章僅為傳播更多信息之目的,如作者信息標(biāo)記有誤,請(qǐng)第一時(shí)間聯(lián)系我們修改或刪除,多謝。