我們發布博文雲計算之路:用阿里雲 vs Azure的對比測試揭開烏雲的面紗之后,阿里雲產品、技術相關負責人趕到了上海,和我們一起尋找問題的真正原因。不管是哪個層面的原因,找出問題的真正原因並解決問題才是最重要的。
經過一天的努力,針對“CPU波動”與“請求執行時間長”這兩個問題有了重要突破。
CPU問題
對於“阿里雲 vs Azure的對比測試”中發現的CPU占用100%問題(對應於訪問高峰期CPU大幅波動問題),發現竟然與磁盤IO有關,這個磁盤IO是因為內存頁面交換文件。
阿里雲虛擬機中的頁面交換文件設置是Windows系統的默認設置——在系統盤上,見下圖:
Azure虛擬機中的頁面交換文件放在了速度非常快的Temporary Storage上。
Azure的Temporary Storage磁盤IO性能要比阿里雲的系統盤快好幾倍。
雖然虛擬機的可用內存綽綽有余,但在高並發的情況下,會產生大量內存分配的操作,有可能造成Windows進行了頁面文件交換的操作。
於是,我們在阿里雲虛擬機上禁用了頁面交換文件,如下圖:
壓測顯示CPU竟然有了完全不一樣表現,CPU占用率不再是一條100%的直線,波動也很穩健。
我們現在已經把所有Web服務器的頁面交換文件禁用,看今天訪問高峰期的CPU表現。
請求執行時間長(Request Execution Time)問題
在故障期間大家訪問速度網站奇慢的時候,對應的服務器端的表現就是超長的請求執行時間。
昨天,我們在故障期間用DebugDiag(Debug Diagnostic Tool)抓取了w3wp進程的dump文件。
通過DebugDiag的分析報告發現很多處理請求的線程發生了阻塞:
然后通過windbg進一步分析,找到阻塞發生的具體地點。
使用的windbg命令是:
.symfix c:\websymbols
.reload
loadby sos clr
~* e !clrstack
得到的結果是:
System.Threading.ReaderWriterLock.AcquireReaderLockInternal(Int32)
System.Configuration.Internal.InternalConfigRoot.AcquireHierarchyLockForRead()
System.Configuration.Internal.InternalConfigRoot.GetConfigRecord(System.String)
System.Configuration.Internal.InternalConfigRoot.GetUniqueConfigRecord(System.String)
System.Web.CachedPathData.Init(System.Web.CachedPathData)
System.Web.CachedPathData.GetConfigPathData(System.String)
System.Web.CachedPathData.GetConfigPathData(System.String)
System.Web.CachedPathData.GetConfigPathData(System.String)
System.Web.HttpContext.GetFilePathData()
System.Web.HttpContext.SetImpersonationEnabled()
System.Web.HttpRuntime.ProcessRequestNotificationPrivate(System.Web.Hosting.IIS7WorkerRequest, System.Web.HttpContext)
System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr, IntPtr, IntPtr, Int32)
System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr, IntPtr, IntPtr, Int32)
DomainNeutralILStubClass.IL_STUB_ReversePInvoke(Int64, Int64, Int64, Int32)
[ContextTransitionFrame: 0000000031ddef58]
線程阻塞是發生在ASP.NET Runtime讀取web.config相關配置信息,申請讀操作鎖的時候,而且申請超時時間是-1。也就是說如果申請不到讀操作鎖,線程就一直在這兒等待。
從這里可以看出,在故障期間請求根本還沒有到達應用程序的處理代碼。也不應該是ASP.NET的bug,如果ASP.NET出這么大的問題,微軟就沒法在IT界混了。
我們猜測某種特殊情況造成了線程在這個地方申請讀操作鎖時發生了死鎖(deadlock)。
根據我們的進一步分析,死鎖可能發生在System.Configuration.Internal.InternalConfigRoot.GetConfigRecord()中,請看精簡后的IL反編譯出來的代碼:
// System.Configuration.Internal.InternalConfigRoot public IInternalConfigRecord GetConfigRecord(string configPath) { try { this.AcquireHierarchyLockForRead(); //... this.hlFindConfigRecord(parts, out num, out baseConfigurationRecord); //... } finally { this.ReleaseHierarchyLockForRead(); } try { this.AcquireHierarchyLockForWrite(); //... this.hlFindConfigRecord(parts, out num2, out baseConfigurationRecord2); //... baseConfigurationRecord3 = (BaseConfigurationRecord)RuntimeConfigurationRecord.Create(this, baseConfigurationRecord2, text); baseConfigurationRecord2.hlAddChild(text2, baseConfigurationRecord3); //.. } } finally { this.ReleaseHierarchyLockForWrite(); } return result; }
如果某個線程在AcquireHierarchyLockForWrite()之后,一直不ReleaseHierarchyLockForWrite(),其他線程都會在AcquireHierarchyLockForRead()時阻塞。
而在AcquireHierarchyLockForWrite()之后,代碼中有讀取配置文件的磁盤IO操作,在System.Configuration.BaseConfigurationRecord中的InitConfigFromFile()中可以看到。
看到有磁盤IO操作,就讓人想到了阿里雲。連CPU波動問題都可能是磁盤IO引起的,這個地方直接涉及文件操作,怎么可能不讓人懷疑是磁盤IO問題引起的。
於是,我們大膽假設了一下,可能還是磁盤IO問題引起的。
然后想辦法避開這個問題進行驗證。我們想到了一個辦法,用內存虛擬出一塊硬盤,將網站文件放在這塊RamDisk上,這樣就不會涉及磁盤IO操作。如果這樣做了之后,故障消失,就能鎖定問題的原因。
現在網站文件已經在RamDisk上,今天訪問高峰就是驗證的時刻。
參考資料:
ASP.NET Case Study: Deadlock waiting in GetToSTA
Debugging a classic ReaderWriterLock deadlock with SOSex.dll