實戰Exchange ActiveSync日誌診斷

在上一篇博文《Exchange 2007 前端 IIS 內存佔用太高》當中，咱們提到在Exchange2007時代，移動設備的EAS鏈接其實並無多少，隨着時間的推移，一些沒有及時升級的2007的郵件系統由於移動設備用戶愈來愈多，也慢慢暴露出產品自己的性能問題。

限制MSExchangeSyncAppPool進程池的內存佔用能夠臨時解決該問題，那麼當問題體如今Exchange2010或者2013上呢。該問題就不只僅是處在自己產品性能上面，而是要考慮到當下各式各樣移動設備對Exchange EAS鏈接的友好性。例如：IOS4.0、IOS 6.1都存在過下降Exchange服務器性能的問題。這些問題常常被反映爲：用EAS協議鏈接的移動設備發送的請求太多，且過於頻繁（超過默認1000隊列的限制），致使佔用服務器資源不足，引起了實際意義上的DDOS。

因此好心的支持團隊集合了各方面……呃…智慧（Powershell + LogParser + IIS日誌），弄出了這樣一個腳本。

http://blogs.technet.com/b/exchange_chs/archive/2012/02/24/exchange-activesync.aspx

腳本的做用是，經過Powershell調用LogParser分析EAS產生的IIS日誌，生成報表等等

您可使用該腳本處理日誌以檢索下面的詳細信息：

1. 按用戶/設備 ID 列出的命中數（向服務器發送最大數量請求的用戶/設備）

2. 每小時/天天命中數（幫助肯定用戶/設備發送請求的頻率，時間值以秒爲單位進行輸入）

3. 按具備指定閾值限制的設備的命中數（此處您能夠指定命中/請求的限制，即每小時/天天發送 1000 個請求的全部用戶等等）

4. 以 CSV 格式導出的結果

5. 結果的 HTML 報告

6. 用於監視的電子郵件報告（CSV/HTML 格式）

 

在使用以前，首先要保證服務器上安裝了Log Parser2.2:http://www.microsoft.com/download/en/details.aspx?id=24659

以及Powershell2.0（最低）

若是你的服務器仍是Windows Server2003 ，那麼頗有可能會由於存在PowerShell 1.0而沒法安裝2.0，升級方法是，中止全部Exchange前端服務並改成手動，卸載PowerShell 1.0 （是個更新補丁對應kb926139），重啓，安裝Powershell 2.0，再重啓，開啓全部Exchange服務。

https://technet.microsoft.com/zh-cn/library/ff354975(v=EXCHG.80).aspx

安裝好了以後，咱們還須要檢查IIS日誌是否打開（聽說默認啓用……可是）：

IIS 7

1. 在「IIS 管理器」中，展開服務器名稱，即「ExchangeServer (Contoso\Administrator)」

2. 在「功能視圖」中，雙擊「日誌記錄」（位於「IIS」部分）。

IIS 6

1. 在「IIS 管理器」中，右鍵單擊網站名稱（大多數狀況下應爲「默認網站」），而後選擇「屬性」

2. 單擊「網站」選項卡。

 

接下來是LogParser 2.2 ，下載好以後直接安裝便可。須要注意的是該工具不支持windows server 2012或更新的操做系統…

新版本添加了UI https://gallery.technet.microsoft.com/Log-Parser-Studio-cd458765

經常使用來分析一些SQL日誌之類的，我以前也用來分析受飛客（Conficker）病毒影響的客戶端引起的大量域控請求，有空的話能夠再給你們聊聊這個。

萬事具有，開始動手。

打開IIS日誌文件夾，須要注意的是若是你是剛剛纔打開IIS日誌選項，這些日誌可能不會很完整，最好是等1天左右，他纔會收集完整的日誌下來。這個很好理解，從你打開選項開始收集嘛。

這裏我設置的IIS選項裏，日誌是按照每一天來截斷的，很奇怪他截斷的時間是下午四點左右到次日下午四點左右，沒搞懂是按照什麼樣的時區機制運行。

將要分析的日誌copy出來，例如這裏咱們分析個幾天的

 

而後將腳本解壓出來

 

首先來第一條命令，以前微軟說過：「若是某個設備天天發送超過 1000 個請求，那麼咱們視其爲「高使用率」，若是命中（請求）數超過 1500，那麼設備或環境可能存在問題。在該狀況下，應進一步調查設備和其用戶的活動。」

.\ActiveSyncReport.ps1 -IISLog "IIS日誌路徑" -LogparserExec "LogParser路徑" -ActiveSyncOutputFolder 輸出文件夾 -MinimumHits 1000

運行完成後會生成2個文件，帶Hits of 1000的，就是單獨的超過1000請求的設備。固然這裏沒有規定日期區間，因此結果應該是3天內超過1000次請求的項目。

若是是規定某一天，則命令格式爲

.\ActiveSyncReport.ps1 -IISLog "IIS日誌路徑" -LogparserExec "LogParser路徑" -ActiveSyncOutputFolder 輸出文件夾 -MinimumHits 1000 –Date 05-30-2015

這個文件大體是下圖這樣子：

日誌裏包含的信息有：

1. 用戶

2. 用戶名稱

3. 設備類型

4. 設備 ID （經過這裏能夠查看IOS的User-agent對應的IOS版本http://www.enterpriseios.com/wiki/Complete_List_of_iOS_User_Agent_Strings）

5. 用戶代理

6. sc-bytes：僅在 IIS 日誌記錄中啓用了此標記時纔可用。

7. cs-bytes：僅在 IIS 日誌記錄中啓用了此標記時纔可用。

8. 所用時間（毫秒）：僅在 IIS 日誌記錄中啓用了此標記時纔可用。

9. 請求的總數或設備 ID 的請求

10. 全部 4xx 狀態代碼的總數

11. 全部 5xx 狀態代碼的總數（有關詳細信息，請參閱面向 IIS 6.0 的知識庫：318380 以及知識庫：943891）

12. 409 狀態代碼：409（衝突）- 沒法爲請求 URI 建立集合，除非建立了一個或多箇中間集合。服務器不得自動建立那些中間集合（參考資料：RFC 4918（該連接可能指向英文頁面））

13. 500 狀態代碼：設備發送 OPTIONS 命令後，可能會從服務器那裏收到 500 響應以及「MissingCscCacheEntry」錯誤。當面向 Internet 的 CAS 陣列代理內部 CAS 陣列請求的相關性出現問題時，可能會發生這種狀況。當面向 Internet 的陣列將請求發送到內部陣列時，CAS 服務器將首先使用 401 進行迴應。在接下來的通訊中，請求由內部陣列中的其餘 CAS 服務器進行處理。解決該內部 CAS 陣列的相關性問題就是解決方案。

14. 503 狀態代碼：因爲服務器臨時過載或維護問題，服務器當前沒法處理請求。其含義是，這屬於臨時狀況，一段時間後將會獲得緩解。若是該可能延遲的時間已知，則會顯示在重試間隔標頭中。若是未給出重試間隔，客戶端將按照處理 500 響應的方式處理該響應。

15. 註釋：存在 503 狀態代碼並不表示服務器在發生過載時必須使用該狀態代碼。某些服務器可能只是簡單地拒絕鏈接。（參考資料：RFC 2616（該連接可能指向英文頁面））

16. 507 狀態代碼：507（存儲不足）狀態代碼表示沒法對資源執行方法，緣由是服務器沒法存儲成功完成請求所需的表示形式。該狀況被視爲臨時狀況。若是收到此狀態代碼的請求是用戶操做的結果，則該請求不得重複，除非由單獨的用戶操做提出。（參考資料：RFC 4918（該連接可能指向英文頁面））

17. 451 狀態代碼：Exchange 2007/2010 在肯定設備應該爲 EAS 鏈接使用「更好」的 CAS 時，將 HTTP 451 響應返回給 EAS 客戶端。用於肯定「更好」CAS 的邏輯基於 Active Directory 站點以及 CAS 是否爲「面向 Internet」。若是指定了 ExternalUrl 屬性（在 Microsoft-Server-ActiveSync 虛擬目錄上），那麼該 CAS 就被視爲面向 Internet 進行 EAS 鏈接。（參考資料：TechNet 文章 Exchange ActiveSync 返回了 HTTP 451 錯誤和瞭解代理和重定向）

18. TooManyJobsQueued 錯誤：有關「TooManyJobsQueued」的詳細信息，請參閱上面引用的知識庫：2469722（該連接可能指向英文頁面）

19. OverBudget：預算是用戶或應用程序針對特定設置可能具備的訪問量。預算表示用戶能夠具備多少個鏈接或者每一分鐘時間內容許用戶進行多少個活動。（參考資料：TechNet 文章）

20. 下面是一部分常見狀態代碼（該連接可能指向英文頁面）： InvalidContent、ServerError、ServerErrorRetryLater、MailboxQuotaExceeded、DeviceIsBlockedForThisUser、AccessDenied、SyncStateNotFound、DeviceNotFullyProvisionable、DeviceNotProvisioned、ItemNotFound、UserDisabledForSync

這麼blabla一堆，最主要的就是Hits這個命中總數，也就是總請求數量，若是超過1500的話…其實我我的以爲1500這個閾值已通過時了，對於目前的Ex2010或者2013的架構來講，這個數字未免也過低了一些，畢竟硬件架構性能在提高嘛。

從這個報告裏，還有提供了更多的其餘參數，上面的列表都列出來大部分，而沒有列出的項目，則表明了一些由移動設備發起的動做，相似GetAttachment、Settings、MoveItems等等，從字面意思上就能理解。這可幫助找出更具備指導性和更高效的故障排除技術

在腳本的幫助下分析 IIS 日誌時，您應該查找一個不斷重複發送的特定命令。所發送的特定命令的頻率很重要，任何常常失敗的命令也一樣重要，應進一步對其進行研究。咱們還應該查看並比較某些命令執行之間的等待時間。通常而言，執行時間較長或形成服務器延遲響應的命令很可疑，應進一步對其進行研究。但請記住，Ping 命令是一個例外，由於其執行時間較長且也將常常出如今日誌中，但這是正常的。

若是您發現鏈接設備時連續失敗，且錯誤代碼爲 403，其表示該設備未啓用基於 EAS 的訪問。有時，移動設備用戶抱怨存在鏈接問題，而沒意識到他們實際上沒有正確輸入其憑據（能夠理解，由於在移動設備上很容易犯這種錯誤）。當查看日誌時，您能夠重點關注該用戶，而且可能會發現該用戶的設備在發出「Provision」命令後失敗

 

更多實用的命令還有：

.\ActiveSyncReport.ps1 -IISLog "IIS日誌路徑" -LogparserExec "LogParser路徑" –ActiveSyncOutputFolder 輸出文件夾 –DeviceID  設備ID –Hourly

經過上面表裏提取出的設備ID，來查詢該設備ID每小時的訪問次數

下面的命令將日誌文件並報告超過 1000 次的命中。另外，其還建立結果的 HTML 報告。

.\ActiveSyncReport.ps1 -IISLog "IIS日誌路徑" –LogparserExec  "LogParser路徑" –ActiveSyncOutputFolder 輸出文件夾 -MinimumHits 1000 -HTMLReport

下面的命令將解析文件夾 C:\Server1_Logs 和 D:\Server2_Logs 中的全部文件，還將經過電子郵件將生成的報告發送到"user@contoso.com"。

.\ActiveSyncReport.ps1 -IISLog "C:\Server1_Logs","D:\Server2_Logs" -LogparserExec "C:\Program Files (x86)\Log Parser 2.2\LogParser.exe" -ActiveSyncOutputFolder c:\EASReports -SendEmailReport -SMTPRecipient user@contoso.com –SMTPSender user2@contoso.com -SMTPServer mail.contoso.com