【监控实践】【3.1】sql server利用trace实现阻塞跟踪和慢查询跟踪
原文:https://blog.csdn.net/kk185800961/article/details/49252037
分享个SQLServer profiler 的一个技巧吧。很早用过,忘记总结了,现在再用时记录下来。
当启用 SQLServer profiler 跟踪sql语句的时候,是非常方便的,同时也可以按照各个维度筛选跟踪。但是对于长时间跟踪,一直打开着profiler界面不是很好。
dbcc help('?') --查看dbcc 所有命令,常规下只有32个常用的 dbcc TRACEON(2588) --指定了2588标记的话,你就可以看到未公开的dbcc命令了,同时你也可以看到各种命令参数的提示了。很多dbcc命令需要开启它才能使用,比如ind,page等 dbcc help('checkdb') --帮助命令,使用其来查看命令用法,开启了上面的2588就可以用ind(查看堆表/索引组织表的数据也信息)了 dbcc TRACEON(3604) -- 指定标记,使得dbcc page的结果可以在客户端上显示出来
有一个技巧是可以把profiler 的跟踪设置导出成sql 脚本,脚本可以在后台执行。以跟踪慢查询为例。
【堵塞跟踪】
设置阻塞阈值
EXEC sp_configure 'show advanced options',1 RECONFIGURE WITH OVERRIDE; GO exec sp_configure 'blocked process threshold (s)',2 --设置阈值为2秒 RECONFIGURE WITH OVERRIDE; GO EXEC sp_configure 'show advanced options',0 RECONFIGURE WITH OVERRIDE; GO
模拟阻塞
1. 首先打开profiler 跟踪堵塞语句,事件选择 Blocked process report ,再把其他的事件都去掉。
2. 分别执行以下语句,模拟堵塞情况。
--[查询窗口1],更新一行记录,等待20秒钟 BEGIN TRAN UPDATE dbo.AAA SET Title='KK' WAITFOR DELAY '00:00:20' COMMIT TRAN
--同时再打开[查询窗口2],更新同一行记录(将被堵塞)
UPDATE dbo.AAA SET Title='KK'
3. 几秒钟后,profiler 捕获到了堵塞信息。
4. 查看XML格式的堵塞信息。<blocked-process> 块是被堵塞的信息,<blocking-process> 为堵塞其他进程的信息。
<blocked-process-report> <blocked-process> <process id="process271931c8" taskpriority="0" logused="0" waitresource="KEY: 13:72057595528151040 (f2008a1296d8)" waittime="9313" ownerId="923979" transactionname="UPDATE" lasttranstarted="2015-10-19T16:54:36.753" XDES="0x53bec08" lockMode="U" schedulerid="1" kpid="7712" status="suspended" spid="55" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2015-10-19T16:54:36.753" lastbatchcompleted="2015-10-19T16:33:12.240" clientapp="Microsoft SQL Server Management Studio - 查询" hostname="kk" hostpid="4204" loginname="kk\Administrator" isolationlevel="read committed (2)" xactid="923979" currentdb="13" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200"> <executionStack> <frame line="1" stmtstart="36" sqlhandle="0x020000005733991f90e1d1e1f620bc49ef0224e73cc0dc81"/> <frame line="1" sqlhandle="0x020000008d15b82d9936449bac7b1e417abd9ca11e87c9b3"/> </executionStack> <inputbuf> UPDATE dbo.AAA SET Title='KK' </inputbuf> </process> </blocked-process> <blocking-process> <process status="suspended" waittime="10501" spid="69" sbid="0" ecid="0" priority="0" trancount="1" lastbatchstarted="2015-10-19T16:54:35.563" lastbatchcompleted="2015-10-19T16:43:28.033" lastattention="2015-10-19T15:37:32.157" clientapp="Microsoft SQL Server Management Studio - 查询" hostname="kk" hostpid="4204" loginname="kk\Administrator" isolationlevel="read committed (2)" xactid="923974" currentdb="13" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200"> <executionStack> <frame line="3" stmtstart="102" stmtend="152" sqlhandle="0x020000006a0d703b95612db79d614f608d92db0ec58bcfb3"/> </executionStack> <inputbuf> BEGIN TRAN UPDATE dbo.AAA SET Title='KK' WAITFOR DELAY '00:00:20' COMMIT TRAN </inputbuf> </process> </blocking-process> </blocked-process-report>
但是这样跟踪的确不方便,可以试试以下这种方法。
使用t-sql构建阻塞跟踪
1. 在当前 profiler 设置中导出SQL 脚本
2. 更改了创建跟踪(sp_trace_create)一些跟踪信息。最终脚本如下
-- Create a Queue declare @rc int declare @traceid int --跟踪分配的编号 declare @options int --TRACE_FILE_ROLLOVER=2/SHUTDOWN_ON_ERROR=4/TRACE_PRODUCE_BLACKBOX=8 declare @tracefile nvarchar(500)--跟踪文件的存储路径 declare @maxfilesize bigint --跟踪文件的大小,单位是mb,默认5mb declare @endtime datetime --停止跟踪的日期和时间,为NULL则表示一直跟踪 declare @filecount int --跟踪文件的数量,其值大于1,TRACE_FILE_ROLLOVER=2 时有效 set @options = 2 set @tracefile = N'E:\BlockedTraceResult\BlockedTraceName' set @maxfilesize = 20 set @endtime = DATEADD(D,1,GETDATE()) set @filecount = 5 -- exec @rc = sp_trace_create @TraceID output, 0, N'InsertFileNameHere', @maxfilesize, NULL exec @rc = sp_trace_Create @TraceID output,@options,@tracefile,@maxfilesize,@endtime,@filecount if (@rc != 0) goto error -- Client side File and Table cannot be scripted -- Set the events declare @on bit set @on = 1 exec sp_trace_setevent @TraceID, 137, 3, @on exec sp_trace_setevent @TraceID, 137, 15, @on exec sp_trace_setevent @TraceID, 137, 51, @on exec sp_trace_setevent @TraceID, 137, 4, @on exec sp_trace_setevent @TraceID, 137, 24, @on exec sp_trace_setevent @TraceID, 137, 32, @on exec sp_trace_setevent @TraceID, 137, 60, @on exec sp_trace_setevent @TraceID, 137, 64, @on exec sp_trace_setevent @TraceID, 137, 1, @on exec sp_trace_setevent @TraceID, 137, 13, @on exec sp_trace_setevent @TraceID, 137, 41, @on exec sp_trace_setevent @TraceID, 137, 22, @on exec sp_trace_setevent @TraceID, 137, 26, @on -- Set the Filters declare @intfilter int declare @bigintfilter bigint -- Set the trace status to start exec sp_trace_setstatus @TraceID, 1 -- display trace id for future references select TraceID=@TraceID goto finish error: select ErrorCode=@rc finish: go
3. 执行上面的脚本,跟踪即可在后台运行,跟踪记录记录在文件中。
4. 要查看跟踪内容,可以双击跟踪文件以 profiler 打开查看。或者可以用sql 语句查看其跟踪设置和跟踪记录内容。
select * from sys.traces select * from ::fn_trace_getinfo(0) select * from ::fn_trace_gettable('E:\BlockedTraceResult\BlockedTraceName.trc',default) select ServerName,EventClass,StartTime,TextData,CONVERT(XML,TextData) XMLTextData from ::fn_trace_gettable('E:\BlockedTraceResult\BlockedTraceName.trc',default)
5. 停止、启用和删除跟踪
select id,status from sys.traces
-- exec sp_trace_setstatus id,num exec sp_trace_setstatus 3,0 --停止跟踪 exec sp_trace_setstatus 3,1 --启动跟踪 exec sp_trace_setstatus 3,2 --删除跟踪
6. 堵塞时间设置(多少秒才算是堵塞)
--开启高级选项
EXEC sp_configure 'show advanced options',1; RECONFIGURE WITH OVERRIDE;
-- 查看堵塞时间(单位:秒) exec sp_configure N'blocked process threshold (s)' -- 设置堵塞时间 exec sp_configure N'blocked process threshold (s)',5 reconfigure 注意: 这里跟踪的只是堵塞,如果一个语句执行30秒,虽然执行时间较长,但是没有堵塞其他语句,也是跟踪不到的。所以有的慢查询是会漏掉的。 如果设置5秒捕获堵塞,同一个查询如果堵塞了10秒,将会跟踪到2次相同的信息,也就是每5秒捕获一次。
【慢查询跟踪】
【慢查询GUI实现】
(1)新建模板
(2)修改事件,跟踪执行时间超过3秒的SQL和SP
同样步骤,跟踪慢查询只要 跟踪存储过程或者TSQL的完成情况,如下图所示,跟踪 RPC:Complited 和 SQL:BacthComplited ,只有跟踪 Complited 才有时间字段,starting 是没有时间的,所以starting 没必要跟踪了。
(3)测试
BEGIN TRAN SELECT top(10) * FROM db_tank..sys_users_detail WAITFOR DELAY '00:00:05' ROLLBACK TRAN
获得了正确的跟踪捕获
(4)导出跟踪成SQL脚本
【脚本操作】
/****************************************************/ /* Created by: SQL Server Profiler 2005 */ /* Date: 2019/10/15 10:55:19 */ /****************************************************/ -- Create a Queue declare @rc int declare @TraceID int declare @maxfilesize bigint set @maxfilesize = 1024 -- Please replace the text InsertFileNameHere, with an appropriate -- filename prefixed by a path, e.g., c:\MyFolder\MyTrace. The .trc extension -- will be appended to the filename automatically. If you are writing from -- remote server to local drive, please use UNC path and make sure server has -- write access to your network share
--这里一定要修改下面的文件保存路径
exec @rc = sp_trace_create @TraceID output, 0, N'd:\dba_tools\slow_query1', @maxfilesize, NULL if (@rc != 0) goto error -- Client side File and Table cannot be scripted -- Set the events declare @on bit set @on = 1 exec sp_trace_setevent @TraceID, 10, 15, @on exec sp_trace_setevent @TraceID, 10, 16, @on exec sp_trace_setevent @TraceID, 10, 9, @on exec sp_trace_setevent @TraceID, 10, 17, @on exec sp_trace_setevent @TraceID, 10, 2, @on exec sp_trace_setevent @TraceID, 10, 10, @on exec sp_trace_setevent @TraceID, 10, 18, @on exec sp_trace_setevent @TraceID, 10, 11, @on exec sp_trace_setevent @TraceID, 10, 12, @on exec sp_trace_setevent @TraceID, 10, 13, @on exec sp_trace_setevent @TraceID, 10, 6, @on exec sp_trace_setevent @TraceID, 10, 14, @on exec sp_trace_setevent @TraceID, 12, 15, @on exec sp_trace_setevent @TraceID, 12, 16, @on exec sp_trace_setevent @TraceID, 12, 1, @on exec sp_trace_setevent @TraceID, 12, 9, @on exec sp_trace_setevent @TraceID, 12, 17, @on exec sp_trace_setevent @TraceID, 12, 6, @on exec sp_trace_setevent @TraceID, 12, 10, @on exec sp_trace_setevent @TraceID, 12, 14, @on exec sp_trace_setevent @TraceID, 12, 18, @on exec sp_trace_setevent @TraceID, 12, 11, @on exec sp_trace_setevent @TraceID, 12, 12, @on exec sp_trace_setevent @TraceID, 12, 13, @on -- Set the Filters declare @intfilter int declare @bigintfilter bigint exec sp_trace_setfilter @TraceID, 10, 0, 7, N'SQL Server Profiler - ebdab0ad-8e05-468b-bead-4f62c9899565' set @bigintfilter = 3000000 exec sp_trace_setfilter @TraceID, 13, 0, 4, @bigintfilter -- Set the trace status to start exec sp_trace_setstatus @TraceID, 1 -- display trace id for future references select TraceID=@TraceID goto finish error: select ErrorCode=@rc finish: go
--------------
-- 测试跟踪
-- 测试跟踪,设置事务执行大于3秒钟:
BEGIN TRAN
SELECT top(10) * FROM db_tank..sys_users_detail
WAITFOR DELAY '00:00:05'
ROLLBACK TRAN
-- 查看
select ServerName,EventClass,StartTime,TextData,CONVERT(XML,TextData) XMLTextData
from ::fn_trace_gettable('d:\dba_tools\slow_query1.trc',default)
select * from fn_trace_gettable('d:\dba_tools\slow_query1.trc',default)
自定义修改
declare @rc int declare @traceid int --跟踪分配的编号 declare @options int --TRACE_FILE_ROLLOVER=2/SHUTDOWN_ON_ERROR=4/TRACE_PRODUCE_BLACKBOX=8 declare @tracefile nvarchar(500)--跟踪文件的存储路径 declare @maxfilesize bigint --跟踪文件的大小,单位是mb,默认5mb declare @endtime datetime --停止跟踪的日期和时间,为NULL则表示一直跟踪 declare @filecount int --跟踪文件的数量,其值大于1,TRACE_FILE_ROLLOVER=2 时有效 set @options = 2 set @tracefile = N'E:\SlowQueryTraceResult\SlowTraceName' set @maxfilesize = 20 set @endtime = NULL --无结束时间 set @filecount = 5 exec @rc = sp_trace_Create @TraceID output,@options,@tracefile,@maxfilesize,@endtime,@filecount if (@rc != 0) goto error -- Client side File and Table cannot be scripted -- Set the events declare @on bit set @on = 1 exec sp_trace_setevent @TraceID, 10, 15, @on exec sp_trace_setevent @TraceID, 10, 16, @on exec sp_trace_setevent @TraceID, 10, 1, @on exec sp_trace_setevent @TraceID, 10, 17, @on exec sp_trace_setevent @TraceID, 10, 18, @on exec sp_trace_setevent @TraceID, 10, 12, @on exec sp_trace_setevent @TraceID, 10, 13, @on exec sp_trace_setevent @TraceID, 10, 6, @on exec sp_trace_setevent @TraceID, 10, 14, @on exec sp_trace_setevent @TraceID, 12, 15, @on exec sp_trace_setevent @TraceID, 12, 16, @on exec sp_trace_setevent @TraceID, 12, 1, @on exec sp_trace_setevent @TraceID, 12, 17, @on exec sp_trace_setevent @TraceID, 12, 6, @on exec sp_trace_setevent @TraceID, 12, 14, @on exec sp_trace_setevent @TraceID, 12, 18, @on exec sp_trace_setevent @TraceID, 12, 12, @on exec sp_trace_setevent @TraceID, 12, 13, @on -- Set the Filters declare @intfilter int declare @bigintfilter bigint set @bigintfilter = 3000000 exec sp_trace_setfilter @TraceID, 13, 0, 4, @bigintfilter -- Set the trace status to start exec sp_trace_setstatus @TraceID, 1 -- display trace id for future references select TraceID=@TraceID goto finish error: select ErrorCode=@rc finish: go
如何查阅跟踪信息?
--如何查看跟踪? select * from master.sys.traces --以表格情况从文件中查询跟踪结果: select ServerName,EventClass,StartTime,TextData,CONVERT(XML,TextData) XMLTextData from ::fn_trace_gettable('E:\SlowQueryTraceResult\SlowTraceName.trc',default) --查看 select * from sys.traces 查看ID是多少,假设我们这里设定的跟踪ID是2 --删除 exec sp_trace_setstatus 2, 0 --第二个参数,0表示暂停,1表示启用 exec sp_trace_setstatus 2, 2 --第二个参数,2表示彻底关闭、删除
如何重启实例后自动启动?
注意,跟踪重启实例后会关闭,可以把上面的代码运行后再生成一个存储过程(比如我们就叫:sp_slow_query_trace),然后运行开机自启代码,如下:
EXEC sp_procoption 'sp_slow_query_trace','STARTUP','ON' print 'ok' GO
注意:
与堵塞一样,如果一条语句可能执行不到1秒钟,但是资源被其他进程占用了,导致这条语句等待了10秒,这条语句也同样被输出。
跟踪的语句只有执行完成才能跟踪到,正在执行的语句是无法跟踪到的。
对于当前正在执行的,可以用系统 DMV 视图查看,如 master.dbo.sysprocesses 或者 sys.dm_exec_requests 等。