SQL Server 事件探查器对于协助 DBA 优化他们的 T-SQL 代码而言是真正的不可多得的财富。但是，过度的富有（这让我想起了《一千零一夜》中的阿拉丁）可能会令人不知所措。最近，在我首次尝试弄懂客户端上按跟踪收集的大量数据时，感到了一种“孤立无助”的感觉。在该特定客户端上，联机事务处理每小时执行的事务超过四百万个。这意味着，实际上捕获“SQL Batch Completed”事件的 30 分钟跟踪将生成长达两百万行的表格。当然，不利用一些自动化操作来处理这么多的记录是不可行的，即使选择耗时最长或成本最高的事务也未必会有助于标识瓶颈。毕竟，每分钟执行数千次耗时短的事务，可能会导致性能有所下降。[订阅者可能希望重新阅读 Linchi Shea 于 2002 年 06 月为其 Perl 代码撰写的文章“Distill SQL Server Log Files”。Linchi 的 PDF 和 Perl代码均包含在本文的下载中 — 编者注。]
跟踪清理规则
我的直觉告诉我使用聚合。但是，由于执行查询中的轻微变化，不用多长时间我就发现按事务类型分组和聚合跟踪并不凑效。每个存储过程调用都具有不同的参数，并且查询都是通过不同的搜索参数和稍许不同的 WHERE 子句条件来执行。某些事务包含注释或在其他相同的代码中具有不同数量的空格、制表符或换行符。某些查询使用关键字的同义词。
为了解决大型跟踪分析的问题，我开发了一个跟踪清理进程，以除去所有跟踪记录的不太重要的细节，并允许按事务类型进行分组。例如，如果我的跟踪包含 50,000 条有关相同存储过程执行的记录（每条都带有不同的参数），那么，我的进程会按持续时间、CPU、读取和写入（所有的总计和平均数）对它们进行排列。这使我可以快速标识负责大部分整体利用的事务类型。
跟踪清理的实现要求 1) 分析所有按跟踪记录的 T-SQL 语句，以及 2) 消除变量参数，如以下示例所示。假设此处所列的三个事务均是按跟踪捕获的。
1. Proc_A123,alpha,0x0a9fff8b2. EXECUTE [Proc_A] -345, beta, null /*comment*/3. EXEC dbo.Proc_A 9876543, default -- test
虽然所有三个事务都执行存储过程 Proc_A，但是执行、参数、换行符、制表符、空格以及注释中的变化使它们看起来非常不同。我的清理算法会将它们聚合至一个事务类型存储为“Proc_A%”的报告中。
例如，为了识别这数个事务是否执行同样的存储过程，或将 INSERT 插入带有不同值的相同表格，该清理算法将执行以下操作：
| • | 消除 EXEC 和 EXECUTE 关键字。 |
| • | 将所有的换行符和制表符替换为空格。 |
| • | 将多个空格视为一个整体。 |
| • | 消除任何数字常量、十六进制的值、文字串以及 NULL 关键字。 |
| • | 移除两种类型（“double-dash”和 /*...*/）的注释。 |
| • | 移除已消除的参数间的逗号。 |
| • | 删除“dbo”所有者名称，该名称也许会用于许多对象名称之前，并在多数情况中为默认值。 |
| • | 将每个分析事务的代码减少至前 800 个。这允许我在多个长批处理的第一部分相同时，将它们视为同一事务类型（在按所述其他规则减少不太重要的元素之后）。 |
| • | 实现涉及到过程（例如 sp_cursoropen）的特殊事务清理，这会将实际的执行查询作为文字参数传递至 SQL Server。对于这些情况，我从参数中提取了实际的查询，并丢弃 sp_cursoropen“包装”。 |
这套规则从本质上减少了必须考虑的事务数量，并使得手动处理生成列表更为简单。请注意，这些规则均是以经验为依据，可能必须对其进行修改以适用于不同的。例如，在与其他客户端协同工作时，我必须向清理过程添加逻辑，以忽略名称，因为他们的具有 400 多个带有相同架构的。名称的移除允许我按存储过程名称聚合跟踪结果，而无需顾及上下文，并标识运行最慢的和成本最高的事务。特定环境中的清理也许需要更进一步的自定义。
存储过程
下载中附带的跟踪 . 代码包含三个存储过程，以用于跟踪清理和分析。存储过程 Process_Trace，其参数如表 1 所列，该过程在给定跟踪表上执行清理。它在分析了跟踪表中捕获的所有代码后查找事务类型，并创建两个附加的表格，这些表格允许将每个事务类型链接到带有完整 SQL 代码的原始跟踪记录。它假设该跟踪表至少包含以下标准列：RowNumber，带有唯一的行标识符；TextData，用于存储每个事务的完整 SQL 代码；以及 EventClass，其中包含数字跟踪事件类型，如 BOL 中所述。默认情况下，该过程仅分析类型 10 (RPC_Completed) 和 12 (TSQL_Batch_Completed) 的事件，但是，您可以将任何事件类型列表指定为参数。下载中提供了我使用的一个示例跟踪定义模板 performance.tdf。
| 表 1. 存储过程 Process_Trace 的参数。 | ||
| 参数 | 数据类型 | 说明 |
| @table | varchar(128) | 跟踪表名称。 |
| @debug | tinyint | 保留供维护。 |
| @drop | Bit | 0（默认）- 常规处理，1 - drop 总结表和索引，由同一跟踪表上该过程中的前一个执行操作创建并退出。 |
| @Event_Class_Filter | varchar(200) | 要包含在清理中的逗号分隔的跟踪事件 ID 列表。默认为 - 10,12（RPC_Completed 和 TSQL_Batch_Completed）。完整的列表可在 BOL 中找到。 |
在执行 Process_Trace 之前，需要运行端跟踪，将数据保存到，然后使用函数 fn_trace_gettable 将跟踪加载到表。（另一种方法是运行事件探查器，直接将数据捕获至表中，但是对于载重生产跟踪，不推荐使用该方法，因为客户端工作站性能可能不足，无法捕获所有的跟踪事件，并且其中某些事件可能会转义记录。）具备跟踪表后，将其作为参数传递至 Process_Trace。可以将该过程作为预备步骤来考虑，为生成报告的下一个过程编译数据。
清理上百万条跟踪记录需要花费几分钟，并生成可能仍然长达数千行的事务类型列表，可是，其中只有部分内容可能对于性能分析非常重要。为了标识该列表的瓶颈，我开发了另一个存储过程 Calculate_Most_Expensive_Transactions，该列表参数如表 2 所列。该过程通过使用原始跟踪表和由 Process_Trace 创建的附加表，来生成有关由“清理的 T-SQL 类型”使用的事务的报告。这假设原始跟踪表包含列 Duration、Reads、Writes 以及 CPU，此外还有早先罗列的 Process_Trace 需要的三列。
| 表 2. 存储过程 Calculate_Most_Expensive_Transactions 的参数。 | ||
| 参数 | 数据类型 | 说明 |
| @trace_table | varchar(128) | 跟踪表名称。 |
| @output_table | varchar(128) | 报告输出名称或用于标准输出的 NULL（默认）。 |
| @topN | Int | 仅当前 N 项中的清理类型位于至少一个级别类别中时，报告才会包含这些清理类型。默认值为 50。显示聚合在一个“All Other”行中的所有其他类型。 |
| @average_ms | Int | 报告中的列表（不是“All Other”）各个都是清理事务类型，其平均持续时间超过 @average_ms 毫秒。默认值为 1000（即，1 秒）。 |
| @debug | tinyint | 保留供维护。 |
根据具体的环境、SQL Server 资源以及应用要求，您也许会关注捕获参数的总计、平均数或最大值，以及每种事务类型的执行计数。该过程将计算所有这些值、整个跟踪表的总计和整个记录的事务混合总计成本中每种事务的成本百分比，以及按照执行计数、事务持续时间总计、总读取/写入以及总 CPU 使用来分级事务类型。为了便于计算，我让每种事务类型分别以 1 秒、多于 1 秒、2 秒、5 秒以及 10 秒执行许多次。
执行 Process_Trace 后，就可以运行 Calculate_Most_Expensive_Transactions 并用相同的跟踪表名称来命名它。（输出将显示在 Query Analyzer 的结果窗口中。）可选的参数允许将其存储在表中以用于保持和历史趋势分析，但是测试时无需此选项。
结果集可以让您按任何参数标识成本最高的事务。您可以找出什么存储过程或查询是成本最高的 I/O 用户，快速找到占用 CPU 最多的前五个事务以及标识平均执行时间最长的事务，等等。我将报告粘贴至 Microsoft Excel 中，并将其按不同的方式进行排序，以分析不同的性能方面。示例报告对于本文而言太大了，但是下载中包含了一个示例， SampleReport.xls。表 3 和 表 4 中显示了该报告的部分内容。
| 表 3. 示例跟踪报告中按使用的总 CPU资源排序的前十个事务。 | |||||
| SQL_Type | Exec_Count | Total_CPU | Average_CPU | Percent_CPU | CPU_Rank |
| getListView% | 1705 | 346890 | 203 | 11.709 | 1 |
| getNext% | 6199 | 107948 | 17 | 3.644 | 2 |
| SELECT Auc_Number, sum(Sold_Count) FROM vwAuc GROUP BY Auc_Number | 64 | 107107 | 1673 | 3.615 | 3 |
| reportView% | 66 | 71701 | 1086 | 2.42 | 4 |
| getBuyerChargeSummary% | 299 | 64048 | 214 | 2.162 | 5 |
| AssignableWorkers% | 162 | 63393 | 391 | 2.14 | 6 |
| getDocument% | 67 | 61230 | 913 | 2.067 | 7 |
| reassignItem% | 54782 | 57942 | 1 | 1.956 | 8 |
| searchLocations% | 27 | 54264 | 2009 | 1.832 | 9 |
| SELECT * from GetProcessNoteList_vw WHERE Process_ID=% | 640 | 54219 | 84 | 1.83 | 10 |
| All Other: |
|
|
| 66.625 |
|
| 表 4. 示例跟踪报告中按平均持续时间排序的前十个事务。 | ||||
| SQL_Type | Exec_Count | Total_Duration | Average_Duration | Max_Duration |
| SELECT Item_ID, Flags FROM v_DetailedPresale WHERE% | 1 | 27,546 | 27,546 | 27,546 |
| GetClosing_Approval_Listing;% | 1 | 24,046 | 24,046 | 24,046 |
| ProcessClosingqualifier% | 1 | 16,656 | 16,656 | 16,656 |
| SELECT * FROM v_Caller_Process_Provider_Association WHERE Phone_Number_%LIKE% | 2 | 26,343 | 13,171 | 25,123 |
| getIncompleteProcessDocForms% | 2 | 25,029 | 12,514 | 16,546 |
| NT_CSAUndelivered% | 2 | 24,093 | 12,046 | 17,313 |
| p_MoveBuyerPaymentDocVPRState% | 2 | 22,829 | 11,414 | 20,783 |
| AssociateSPEmployee% | 1 | 11,296 | 11,296 | 11,296 |
| SELECT retVal FROM v_Caller_Process_Provider_Association WHERE phone_number_%_Raw like% | 3 | 32,389 | 10,796 | 16,530 |
| delayedProcessClosing% | 3 | 30,562 | 10,187 | 30,530 |
| All Other: | 1,361,157 | 12,816,138 | 9 | 30,643 |
Excel 还可帮助我创建饼形图，用于说明成本最高的事务的“排行榜”，例如，请查看pro04/html/410zanevsky1_SQL04j.jpg" target="_blank">图 1 和 pro04/html/410zanevsky2_SQL04j.jpg" target="_blank">图 2 所示。它们帮助我即刻关注于妨碍性能的高执行成本的最关键事务。在多数情况下，我发现所有数千个执行的事务类型中，只有少部分负责大量的 SQL Server 利用。通过性能分析和致力于优化来缩小该列表范围。不同的可能具有不同的瓶颈。一些受制于 I/O 资源，一些受限于 CPU 功率；而对于其他，容量充足，但是平均事务持续时间让人无法接受。根据具体的环境要求，您可能会从可将至关重要区域中的问题隔离出来的基础报告中，来获得不同的报告和图表。
为了体验一番报告提供用于分析的数据，SampleReport.xls 将提供以下有关存储过程 getListView% 的信息。该过程在跟踪期间执行了 1705 次。就此数字而言，其中每次花费时间少于 1 秒的有 1498 次，需要 2 秒的有 120 次，需要 5 秒的有 67 次，需要 10 秒的有 16 次，需要超过 10 秒的有 4 次。所有执行的持续时间总计为 961 秒。所有执行组合需要耗费 360 万次页读取、733 次写入以及 347,000 个 CPU 单位（缓存页命中）。每次执行的平均持续时间稍多于 0.5 秒；它需要进行 2125 次读取（少于一次写入操作）和 203 个 CPU 单位。最长的持续时间差不多为 12 秒，单个执行中读取的最大次数是 29,000+、12 次写入以及 2235 个 CPU 单位。在所有事务中，该类型负责总执行计数百分之一的八分之一、总持续时间的 7% 以上、所有读取的 4%、写入的0.8% 以及总 CPU 利用率的 11.7%。在公认的排行榜中，该事务类型是执行计数中的 #61、持续时间总计的 #2、I/O（读取和写入）中的 #4 以及 CPU 利用中的 #1。
根据这一信息，我知道了如果我的 SQL Server 损害到 CPU 容量，那么，优化该存储过程可能会使 CPU 使用率降低达 11.7%。它还有可能将 I/O 利用率提高达 7%。如果用户抱怨缓慢的响应时间，那么我可以看到该过程会使他们在跟踪期间等待 1-12 秒 207 次。优化可能会降低此种用户等待事件的数量，从而改善他们的体验。如果没有清理和聚合，该分析的某些部分将难于进行。
请注意，由 Calculate_Most_Expensive_Transactions 生成的报告包含事务类型 ID。通过使用存储过程 Report_All_Transactions_By_SQL_ID，这些值可用于检索所有特定事务类型的原始 SQL 代码，该过程的参数如 表 5 所列。这个过程有助于分析清理事务类型，并查找实际未清理的 T-SQL 代码示例。
| 表 5. 存储过程 Report_All_Transactions_By_SQL_ID 的参数。 | ||
| 参数 | 数据类型 | 说明 |
| @Table | varchar(128) | 跟踪表名称。 |
| @SQL_ID | int | 从 Calculate_Most_Expensive_Transactions 生成的报告中清理 SQL 类型 id。 |
| @Sort | varchar(20) | 排序所依据的列名称。可能的值：StartTime、Reads、CPU（默认）、 Duration 或 spid。 |
清理算法的实现帮助我在短时间内改善了数家公司的性能，同时又只需要了解很少或无需事先了解应用和架构知识。在缩小了几个存储过程或查询的性能瓶颈范围后，我可以将重点放在对其进行分析上，例如，查找缺少的索引、可以替换为集处理的光标或另一个更为有效的算法实现。我将自己的跟踪“宝物”整齐地放在它们的“保险箱”中，不会有溢出的危险。
在以后的文章中，我将和大家分享一套完全的自动，该是我和同事围绕本文所介绍的存储过程而构建的。它使用跟踪清理和聚合，在生产上执行日常的跟踪，自动生成并发布成本最高的事务报告。
有关 Microsoft SQL Server Professional 和 Pinnacle Publishing 的详细信息，请访问其网站 http://www.pinpub.com/
