背景
客户反馈系统突然运行非常缓慢,持续了近20分钟的时间,通过SQL专家云定位到有人开启了Profiler导致,但是不能定位是谁开启的,请我们协助分析。
现象
登录SQL专家云,进入实时可视化页面,在活动会话中看到在11:29~11:40期间出现了大量的有资源等待的会话。
进入活动会话原始数据页面,看到几乎所有的会话都在等待,等待类型是TRACEWRITE,等待时间在100毫秒左右。
分析
通过TRACEWRITE的等待类型可以确定是有人开启了Profiler跟踪SQL语句导致的。等待现象已经在11:40消失了, 说明已经停止了跟踪。现在需要找到是谁开启的跟踪,转到慢语句页面,通过应用程序名称进行筛选。
通过特征可以确定是ID为1250的会话开启的Profiler,11:29开始,11:40结束。通过影响行数看到一共跟踪了3300多万条SQL语句,跟踪的数量太多了,这就是大量会话产生TRACEWRITE等待的原因。
进入详细信息页面就可以看到机器名和IP地址。
关于Profiler
Profiler是分析SQL Server问题的一个非常好用的工具,可以定位故障、优化性能、分析死锁等。详细参考微软官方文档:https://docs.microsoft.com/zh-cn/sql/tools/sql-server-profiler/sql-server-profiler?view=sql-server-ver16。
Profiler使用不当会造成严重的性能问题,主要有两类,第一类是跟踪到的SQL语句太多,原因是没有设置筛选条件或者筛选条件太宽泛,另外就是跟踪的事件太多,例如用SP:StmtCompleted跟踪存储过程子语句的执行,复杂的存储过程执行一次就可能产生成百上千的跟踪事件,这类现象的特征是大量会话产生TRACEWRITE的等待,很好排查;第二类是筛选条件设置不当,例如对TextData字段使用%%的模糊查询,每一个SQL语句都要进行字符串模糊查询,加重了CPU的消耗,严重时会导致CPU利用率达到100%,这类现象除了CPU利用率高外没有明显的特征,很不好排查。
所以在高并发的系统中,一定要谨慎使用Profiler,要注意以下几点
选择必要的跟踪事件,尤其对于存储过程子语句相关的跟踪事件一定要谨慎使用;
设置合适的筛选条件避免大量的跟踪。例如利用LoginName、ApplicationName、ClientProcessID、HostName、Duration等进行筛选,避免对TextData字段的模糊查找;
在数据库服务器上开启Profiler,可以避免跟踪事件通过网络传输到其他机器的时间;
使用扩展事件替代Profiler。