当前位置：Gxlcms > 数据库问题 > 通过SQL Server的扩展事件来跟踪SQL语句在运行时，时间都消耗到哪儿了？

通过SQL Server的扩展事件来跟踪SQL语句在运行时，时间都消耗到哪儿了？

时间：2021-07-01 10:21:17 帮助过：4人阅读

对这个问题，我的回答是：

从表面看，很难分析出为什么多台机器执行同一个简单的sql语句，速度有差异，甚至好的服务器反而花了更多的时间，而看上去相对较差的机器反而更快，这些都是表面现象。

我们可以分析一下整个SQL语句执行的大致过程：

1、语句发送到SQL Server服务器端。

2、SQL Server会找这个语句是否已经缓存在内存中，如果能找到，这样就不用重新编译，这样就会节省时间。
如果不在缓存中，那么就需要经过语法检查、语义检查、权限检查、编译，这个过程需要内存；再进行优化，生成执行计划，优化时也需要内存；然后把这个执行计划放进行缓存，这个也需要内存。

3、在执行的时候，如果所要访问的数据都在内存，也就是数据也缓存在内存中了，那么就不用从硬盘读取数据，也就是没有物理IO，只有逻辑操作，速度也会快。

4、在执行的时候，需要申请相关锁，如果所要访问的数据上已经加了锁，那么需要等待。

5、上面几点中，还有一个问题是，系统的负载，如果系统本来就很忙，那么上面的整个过程，可能任何一步，都有可能会等待一会。另外，内存和IO非常重要，如果你的系统存在内存压力，此外，磁盘经常满负荷运转，那么计算是执行一个简单的语句，也会比负载比较低时慢。

你的开发机器和你的服务器，负载是否一样。

6、非常重要的一点，语句运行完成后的结果集，通过网络发送到客户端程序，所以网络是否通畅以及速度的快慢，决定了你的语句的快慢。

对比，你的多张图片，之所以慢的原因应该不是在分析编译、执行时的cpu时间，而是执行时的占用时间，应该是花在IO上的，扫描次数和逻辑读取次数都一样，lob的逻辑读取差了2个，lob预读次数一样，很有可能就是这点差别，当然还有系统的负载，也会导致从硬盘读数据变慢。

另外，如果是直接连接远程，可能会有网络问题，如果是像你上面，直接通过远程连接登录到数据库服务器，再直接连数据库，那么应该不是网络的问题。

下面通过这个帖子所描述的方法： http://blogs.msdn.com/b/sqlsakthi/archive/2011/02/20/sql-query-slowness-troubleshooting-using-extended-events-wait-info-event.aspx

通过扩展事件来跟踪一个语句，在运行时到底把时间消耗在哪儿了，比如说是PAGEIOLATCH_EX。

1、建立扩展事件，注意下面的session_id为你要跟踪的语句的会话id，要改过来。

<code class="language-sql hljs"><ol class="hljs-ln hundred" style="width:888px"><li><span class="hljs-comment">-- *** Change the Session ID values as per your need *** </span></li><li> </li><li> </li><li> </li><li><span class="hljs-comment">-- Check for existing session</span></li><li> </li><li>IF EXISTS(<span class="hljs-keyword">SELECT</span> * <span class="hljs-keyword">FROM</span> sys.server_event_sessions <span class="hljs-keyword">WHERE</span> <span class="hljs-keyword">name</span>=<span class="hljs-string">‘Waits_of_Particular_Session‘</span>)</li><li> </li><li>  <span class="hljs-keyword">DROP</span> <span class="hljs-keyword">EVENT</span> <span class="hljs-keyword">session</span> Waits_of_Particular_Session <span class="hljs-keyword">ON</span> <span class="hljs-keyword">SERVER</span>;</li><li> </li><li>GO</li><li> </li><li> </li><li> </li><li><span class="hljs-comment">-- Create a session and add events and actions</span></li><li> </li><li><span class="hljs-keyword">CREATE</span> <span class="hljs-keyword">EVENT</span> <span class="hljs-keyword">SESSION</span> Waits_of_Particular_Session </li><li> </li><li><span class="hljs-keyword">ON</span> <span class="hljs-keyword">SERVER</span></li><li> </li><li><span class="hljs-keyword">ADD</span> <span class="hljs-keyword">EVENT</span> sqlserver.sql_statement_starting</li><li> </li><li>(</li><li> </li><li>
<span class="hljs-keyword">ACTION</span> (sqlserver.session_id,</li><li> </li><li>
sqlserver.sql_text,</li><li> </li><li>
sqlserver.plan_handle)</li><li> </li><li>
<span class="hljs-keyword">WHERE</span> </li><li> </li><li>
sqlserver.session_id > <span class="hljs-number">52</span> <span class="hljs-keyword">AND</span> sqlserver.session_id < <span class="hljs-number">54</span></li><li> </li><li>),</li><li> </li><li><span class="hljs-keyword">ADD</span> <span class="hljs-keyword">EVENT</span> sqlos.wait_info </li><li> </li><li>(</li><li> </li><li>
<span class="hljs-keyword">ACTION</span> (sqlserver.session_id,</li><li> </li><li>
sqlserver.sql_text,</li><li> </li><li>
sqlserver.plan_handle)</li><li> </li><li>
<span class="hljs-keyword">WHERE</span> </li><li> </li><li>
sqlserver.session_id > <span class="hljs-number">52</span> <span class="hljs-keyword">AND</span> sqlserver.session_id < <span class="hljs-number">54</span></li><li> </li><li>),</li><li> </li><li><span class="hljs-keyword">ADD</span> <span class="hljs-keyword">EVENT</span> sqlos.wait_info_external</li><li> </li><li>(</li><li> </li><li>
<span class="hljs-keyword">ACTION</span> (sqlserver.session_id,</li><li> </li><li>
sqlserver.sql_text,</li><li> </li><li>
sqlserver.plan_handle)</li><li> </li><li>
<span class="hljs-keyword">WHERE</span> </li><li> </li><li>
sqlserver.session_id > <span class="hljs-number">52</span> <span class="hljs-keyword">AND</span> sqlserver.session_id < <span class="hljs-number">54</span></li><li> </li><li>),</li><li> </li><li><span class="hljs-keyword">ADD</span> <span class="hljs-keyword">EVENT</span> sqlserver.sql_statement_completed</li><li> </li><li>(</li><li> </li><li>
<span class="hljs-keyword">ACTION</span> (sqlserver.session_id,</li><li> </li><li>
sqlserver.sql_text,</li><li> </li><li>
sqlserver.plan_handle)</li><li> </li><li>
<span class="hljs-keyword">WHERE</span> </li><li> </li><li>
sqlserver.session_id > <span class="hljs-number">52</span> <span class="hljs-keyword">AND</span> sqlserver.session_id < <span class="hljs-number">54</span></li><li> </li><li>)</li><li> </li><li><span class="hljs-keyword">ADD</span> TARGET package0.asynchronous_file_target</li><li> </li><li>    (<span class="hljs-keyword">SET</span> filename=N<span class="hljs-string">‘C:\Temp\Waits_of_Particular_Session.xel‘</span>)</li><li> </li><li><span class="hljs-keyword">WITH</span> (MAX_DISPATCH_LATENCY = <span class="hljs-number">5</span> SECONDS, EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS, TRACK_CAUSALITY=<span class="hljs-keyword">ON</span>)</li><li> </li><li><span class="hljs-keyword">GO</span></li><li> </li><li> </li><li> </li><li><span class="hljs-comment">-- Start the Session</span></li><li> </li><li><span class="hljs-keyword">ALTER</span> <span class="hljs-keyword">EVENT</span> <span class="hljs-keyword">SESSION</span> Waits_of_Particular_Session <span class="hljs-keyword">ON</span> <span class="hljs-keyword">SERVER</span></li><li> </li><li>STATE = <span class="hljs-keyword">START</span></li><li> </li><li><span class="hljs-keyword">GO</span></li><li> </li><li> </li><li> </li><li><span class="hljs-comment">-- Run the query from the SPID </span></li><li> </li><li> </li><li> </li><li><span class="hljs-comment">-- Code to stop the session once the query execution completes</span></li><li> </li><li><span class="hljs-keyword">ALTER</span> <span class="hljs-keyword">EVENT</span> <span class="hljs-keyword">SESSION</span> Waits_of_Particular_Session <span class="hljs-keyword">ON</span> <span class="hljs-keyword">SERVER</span></li><li> </li><li>STATE = <span class="hljs-keyword">STOP</span></li><li> </li><li><span class="hljs-keyword">GO</span></li></ol></code>

2、然后，运行你的语句：select * from dbo.ttt

3、最后，运行下面的语句，获取各类操作所消耗的时间：

<code class="language-sql hljs"><ol class="hljs-ln" style="width:1668px"><li><span class="hljs-comment">-- Parse the XML to show wait details</span></li><li> </li><li><span class="hljs-keyword">SELECT</span></li><li> </li><li>    event_xml.value(<span class="hljs-string">‘(./@name)‘</span>, <span class="hljs-string">‘varchar(1000)‘</span>) <span class="hljs-keyword">as</span> Event_Name,</li><li> </li><li>    event_xml.value(<span class="hljs-string">‘(./data[@name="wait_type"]/text)[1]‘</span>, <span class="hljs-string">‘nvarchar(max)‘</span>) <span class="hljs-keyword">as</span> Wait_Type,</li><li> </li><li>    event_xml.value(<span class="hljs-string">‘(./data[@name="duration"]/value)[1]‘</span>, <span class="hljs-string">‘int‘</span>) <span class="hljs-keyword">as</span> <span class="hljs-keyword">Duration</span>,</li><li> </li><li>    event_xml.value(<span class="hljs-string">‘(./data[@name="opcode"]/text)[1]‘</span>, <span class="hljs-string">‘varchar(100)‘</span>) <span class="hljs-keyword">as</span> Operation,</li><li> </li><li>    event_xml.value(<span class="hljs-string">‘(./action[@name="session_id"]/value)[1]‘</span>, <span class="hljs-string">‘int‘</span>) <span class="hljs-keyword">as</span> SPID,</li><li> </li><li>    event_xml.value(<span class="hljs-string">‘(./action[@name="sql_text"]/value)[1]‘</span>, <span class="hljs-string">‘nvarchar(max)‘</span>) <span class="hljs-keyword">as</span> TSQLQuery,</li><li> </li><li>    event_xml.value(<span class="hljs-string">‘(./action[@name="plan_handle"]/value)[1]‘</span>, <span class="hljs-string">‘nvarchar(max)‘</span>) <span class="hljs-keyword">as</span> PlanHandle</li><li> </li><li><span class="hljs-keyword">FROM</span>    </li><li> </li><li>
(<span class="hljs-keyword">SELECT</span> <span class="hljs-keyword">CAST</span>(event_data <span class="hljs-keyword">AS</span> <span class="hljs-keyword">XML</span>) xml_event_data <span class="hljs-keyword">FROM</span> sys.fn_xe_file_target_read_file(<span class="hljs-string">‘C:\Temp\Waits_of_Particular_Session*.xel‘</span>, <span class="hljs-string">‘C:\Temp\Waits_of_Particular_Session*.xem‘</span>, <span class="hljs-literal">NULL</span>, <span class="hljs-literal">NULL</span>)) <span class="hljs-keyword">AS</span> event_table</li><li> </li><li>
<span class="hljs-keyword">CROSS</span> <span class="hljs-keyword">APPLY</span> xml_event_data.nodes(<span class="hljs-string">‘//event‘</span>) n (event_xml)</li><li> </li><li><span class="hljs-keyword">WHERE</span>  </li><li> </li><li>
event_xml.value(<span class="hljs-string">‘(./@name)‘</span>, <span class="hljs-string">‘varchar(1000)‘</span>) <span class="hljs-keyword">IN</span> (<span class="hljs-string">‘wait_info‘</span>,<span class="hljs-string">‘wait_info_external‘</span>)   </li><li> </li><li>
</li><li> </li><li><span class="hljs-comment">-- Code to drop the session</span></li><li> </li><li><span class="hljs-keyword">DROP</span> <span class="hljs-keyword">EVENT</span> <span class="hljs-keyword">SESSION</span> Waits_of_Particular_Session <span class="hljs-keyword">ON</span> <span class="hljs-keyword">SERVER</span>;</li></ol></code>

这段监控的语句，在网友的服务器上执行，最后发现，时间主要消耗在了NETWORK_IO上，也就是网络。