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

Posted lonelyxmas

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了通过SQL Server的扩展事件来跟踪SQL语句在运行时,时间都消耗到哪儿了?相关的知识,希望对你有一定的参考价值。

原文:通过SQL Server的扩展事件来跟踪SQL语句在运行时,时间都消耗到哪儿了?

问题就是,一个很简单的语句,在不同的服务器上执行,所需要的时间相差很大,特别提到在性能差的服务器上反而快,在性能好的服务器上反而慢,他想知道这是为什么?

 

对这个问题,我的回答是:

 

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


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

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

2SQL 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,要改过来。

  1. -- *** Change the Session ID values as per your need ***
  2. -- Check for existing session
  3. IF EXISTS(SELECT * FROM sys.server_event_sessions WHERE name=‘Waits_of_Particular_Session‘)
  4. DROP EVENT session Waits_of_Particular_Session ON SERVER;
  5. GO
  6. -- Create a session and add events and actions
  7. CREATE EVENT SESSION Waits_of_Particular_Session
  8. ON SERVER
  9. ADD EVENT sqlserver.sql_statement_starting
  10. (
  11. ACTION (sqlserver.session_id,
  12. sqlserver.sql_text,
  13. sqlserver.plan_handle)
  14. WHERE
  15. sqlserver.session_id > 52 AND sqlserver.session_id < 54
  16. ),
  17. ADD EVENT sqlos.wait_info
  18. (
  19. ACTION (sqlserver.session_id,
  20. sqlserver.sql_text,
  21. sqlserver.plan_handle)
  22. WHERE
  23. sqlserver.session_id > 52 AND sqlserver.session_id < 54
  24. ),
  25. ADD EVENT sqlos.wait_info_external
  26. (
  27. ACTION (sqlserver.session_id,
  28. sqlserver.sql_text,
  29. sqlserver.plan_handle)
  30. WHERE
  31. sqlserver.session_id > 52 AND sqlserver.session_id < 54
  32. ),
  33. ADD EVENT sqlserver.sql_statement_completed
  34. (
  35. ACTION (sqlserver.session_id,
  36. sqlserver.sql_text,
  37. sqlserver.plan_handle)
  38. WHERE
  39. sqlserver.session_id > 52 AND sqlserver.session_id < 54
  40. )
  41. ADD TARGET package0.asynchronous_file_target
  42. (SET filename=N‘C:TempWaits_of_Particular_Session.xel‘)
  43. WITH (MAX_DISPATCH_LATENCY = 5 SECONDS, EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS, TRACK_CAUSALITY=ON)
  44. GO
  45. -- Start the Session
  46. ALTER EVENT SESSION Waits_of_Particular_Session ON SERVER
  47. STATE = START
  48. GO
  49. -- Run the query from the SPID
  50. -- Code to stop the session once the query execution completes
  51. ALTER EVENT SESSION Waits_of_Particular_Session ON SERVER
  52. STATE = STOP
  53. GO


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


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

  1. -- Parse the XML to show wait details
  2. SELECT
  3. event_xml.value(‘(./@name)‘, ‘varchar(1000)‘) as Event_Name,
  4. event_xml.value(‘(./data[@name="wait_type"]/text)[1]‘, ‘nvarchar(max)‘) as Wait_Type,
  5. event_xml.value(‘(./data[@name="duration"]/value)[1]‘, ‘int‘) as Duration,
  6. event_xml.value(‘(./data[@name="opcode"]/text)[1]‘, ‘varchar(100)‘) as Operation,
  7. event_xml.value(‘(./action[@name="session_id"]/value)[1]‘, ‘int‘) as SPID,
  8. event_xml.value(‘(./action[@name="sql_text"]/value)[1]‘, ‘nvarchar(max)‘) as TSQLQuery,
  9. event_xml.value(‘(./action[@name="plan_handle"]/value)[1]‘, ‘nvarchar(max)‘) as PlanHandle
  10. FROM
  11. (SELECT CAST(event_data AS XML) xml_event_data FROM sys.fn_xe_file_target_read_file(‘C:TempWaits_of_Particular_Session*.xel‘, ‘C:TempWaits_of_Particular_Session*.xem‘, NULL, NULL)) AS event_table
  12. CROSS APPLY xml_event_data.nodes(‘//event‘) n (event_xml)
  13. WHERE
  14. event_xml.value(‘(./@name)‘, ‘varchar(1000)‘) IN (‘wait_info‘,‘wait_info_external‘)
  15. -- Code to drop the session
  16. DROP EVENT SESSION Waits_of_Particular_Session ON SERVER;

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


发布了416 篇原创文章 · 获赞 135 · 访问量 94万+

以上是关于通过SQL Server的扩展事件来跟踪SQL语句在运行时,时间都消耗到哪儿了?的主要内容,如果未能解决你的问题,请参考以下文章

如何查看SQL Server2000执行过的SQL语句

如何跟踪SQL SERVER 正在执行的语句

sql server profiler 是啥文件

如何用sqlserver 2000事件查探器查询sql

如何诊断SQL数据?

如何使用SQL Server Profiler跟踪数据库