实战Exchange ActiveSync日志诊断

fewrwe

在上一篇博文《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日志，生成报表等等

您可以使用该脚本处理日志以检索下面的详细信息：

• 按用户/设备 ID 列出的命中数（向服务器发送最大数量请求的用户/设备）
• 每小时/每天命中数（帮助确定用户/设备发送请求的频率，时间值以秒为单位进行输入）
• 按具有指定阈值限制的设备的命中数（此处您可以指定命中/请求的限制，即每小时/每天发送 1000 个请求的所有用户等等）
• 以 CSV 格式导出的结果
• 结果的 HTML 报告
• 用于监视的电子邮件报告（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

• 在“IIS 管理器”中，展开服务器名称，即“ExchangeServer (Contoso\Administrator)”
• 在“功能视图”中，双击“日志记录”（位于“IIS”部分）。
  
  

IIS 6

• 在“IIS 管理器”中，右键单击网站名称（大多数情况下应为“默认网站”），然后选择“属性”
• 单击“网站”选项卡。
  
  

接下来是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，那么设备或环境可能存在问题。在该情况下，应进一步调查设备和其用户的活动。”

1	.\ActiveSyncReport.ps1 -IISLog "IIS日志路径" -LogparserExec "LogParser路径" -ActiveSyncOutputFolder 输出文件夹 -MinimumHits 1000

运行完成后会生成2个文件，带Hits of 1000的，就是单独的超过1000请求的设备。当然这里没有规定日期区间，所以结果应该是3天内超过1000次请求的项目。
如果是规定某一天，则命令格式为

1	.\ActiveSyncReport.ps1 -IISLog "IIS日志路径" -LogparserExec "LogParser路径" -ActiveSyncOutputFolder 输出文件夹 -MinimumHits 1000 –Date 05-30-2015

这个文件大致是下图这样子：

日志里包含的信息有：

• 用户
  
• 用户名称
  
• 设备类型
  
• 设备 ID （通过这里可以查看IOS的User-agent对应的IOS版本http://www.enterpriseios.com/wik ... _User_Agent_Strings）
  
• 用户代理
  
• sc-bytes：仅在 IIS 日志记录中启用了此标记时才可用。
  
• cs-bytes：仅在 IIS 日志记录中启用了此标记时才可用。
  
• 所用时间（毫秒）：仅在 IIS 日志记录中启用了此标记时才可用。
  
• 请求的总数或设备 ID 的请求
  
• 所有 4xx 状态代码的总数
  
• 所有 5xx 状态代码的总数（有关详细信息，请参阅面向 IIS 6.0 的知识库：318380 以及知识库：943891）
  
• 409 状态代码：409（冲突）- 无法为请求 URI 创建集合，除非创建了一个或多个中间集合。服务器不得自动创建那些中间集合（参考资料：RFC 4918（该链接可能指向英文页面））
  
• 500 状态代码：设备发送 OPTIONS 命令后，可能会从服务器那里收到 500 响应以及“MissingCscCacheEntry”错误。当面向 Internet 的 CAS 阵列代理内部 CAS 阵列请求的相关性出现问题时，可能会发生这种情况。当面向 Internet 的阵列将请求发送到内部阵列时，CAS 服务器将首先使用 401 进行回应。在接下来的通信中，请求由内部阵列中的其他 CAS 服务器进行处理。解决该内部 CAS 阵列的相关性问题就是解决方案。
  
• 503 状态代码：由于服务器临时过载或维护问题，服务器当前无法处理请求。其含义是，这属于临时情况，一段时间后将会得到缓解。如果该可能延迟的时间已知，则会显示在重试间隔标头中。如果未给出重试间隔，客户端将按照处理 500 响应的方式处理该响应。
  
• 注释：存在 503 状态代码并不表示服务器在发生过载时必须使用该状态代码。某些服务器可能只是简单地拒绝连接。（参考资料：RFC 2616（该链接可能指向英文页面））
  
• 507 状态代码：507（存储不足）状态代码表示无法对资源执行方法，原因是服务器无法存储成功完成请求所需的表示形式。该情况被视为临时情况。如果收到此状态代码的请求是用户操作的结果，则该请求不得重复，除非由单独的用户操作提出。（参考资料：RFC 4918（该链接可能指向英文页面））
  
• 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 错误和了解代理和重定向）
  
• TooManyJobsQueued 错误：有关“TooManyJobsQueued”的详细信息，请参阅上面引用的知识库：2469722（该链接可能指向英文页面）
  
• OverBudget：预算是用户或应用程序针对特定设置可能具有的访问量。预算表示用户可以具有多少个连接或者每一分钟时间内允许用户进行多少个活动。（参考资料：TechNet 文章）
  
• 下面是一部分常见状态代码（该链接可能指向英文页面）： 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”命令后失败

更多实用的命令还有：

1	.\ActiveSyncReport.ps1 -IISLog "IIS日志路径" -LogparserExec "LogParser路径" –ActiveSyncOutputFolder 输出文件夹 –DeviceID  设备ID –Hourly

通过上面表里提取出的设备ID，来查询该设备ID每小时的访问次数

下面的命令将日志文件并报告超过 1000 次的命中。另外，其还创建结果的 HTML 报告。

1	.\ActiveSyncReport.ps1 -IISLog "IIS日志路径" –LogparserExec  "LogParser路径" –ActiveSyncOutputFolder 输出文件夹 -MinimumHits 1000 -HTMLReport

下面的命令将解析文件夹 C:\Server1_Logs 和 D:\Server2_Logs 中的所有文件，还将通过电子邮件将生成的报告发送到"user@contoso.com"。

1	.\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