如何让SQL Server像MySQL一样拥有慢查询日志（Slow Query Log慢日志）

SQL Server一直以来被人诟病的一个问题是缺少了像MySQL的慢日志功能，程序员和运维无法知道数据库过去历史的慢查询语句。

因为SQLServer默认是不捕获过去历史的长时间阻塞的SQL语句，导致大家都认为SQL Server没有历史慢日志功能

其实SQLServer提供了扩展事件让用户自己去捕获过去历史的长时间阻塞的SQL语句，但是因为不是默认出厂配置并且设置扩展事件对初级用户有一定难度，这里可以说不得不是一个遗憾，希望后续版本的SQL Server可以默认设置好慢日志的相关扩展事件，用初级用户也可以快速上手。

话不多说，这个文章主要讲述设置慢日志的扩展事件的步骤，并且把慢日志提供第三方程序读取以提供报表功能。

扩展事件介绍

SQL Server 扩展事件（Extended Events，简称 XE）是从 SQL Server 2008 开始引入的一种轻量级、高度可定制的事件处理系统，
旨在帮助数据库管理员和开发人员更好地监控、调试和优化 SQL Server 的性能。
扩展事件可以用于捕获和分析 SQL Server 内部发生的各种事件，以便识别和解决性能瓶颈和问题。

扩展事件优点包括轻量级、统一事件处理框架和集成性。事件设计对系统性能影响最小，确保在高负载环境下也能稳定运行。
扩展事件可以与 SQL Server Profiler 和 SQL Server Audit 结合使用，为用户提供全面的诊断和监控工具。

实验步骤

创建环境所需的数据库和表

--窗口1
--建表

USE testdb
GO

CREATE TABLE Account(id INT, name NVARCHAR(200))


INSERT INTO [dbo].[Account]
SELECT 1,'Lucy'
UNION ALL
SELECT 2,'Tom'
UNION ALL
SELECT 3,'Marry'

--查询
SELECT * FROM [dbo].[Account]

创建扩展事件

输入扩展事件名称

不要使用模版

事件库搜索block，选择blocked_process_report

确认事件

选择你需要的字段

这里选择client_app_name、client_hostname、database_id、database_name、plan_handle、query_hash、request_id、session_id、sql_text字段

当然你可以勾选自己想要的字段，这里只是抛砖引玉

续

直接下一步

这里需要注意的是，扩展事件日志不能全量保存，所以用户需要考虑好保留多长时间的扩展事件，假设一天可以产生的扩展事件大小为1GB，那么每个扩展事件文件大小1GB，最多5个扩展事件文件意味着你不能查询到5天之前的数据

比如你不能查询到前面第8天的扩展事件，扩展事件是滚动利用的。

扩展事件创建情况预览

小提示：你可以点击script生成这个扩展事件的create脚本，那么其他服务器就不用这样用界面去创建这么繁琐了。

生成出来的扩展事件

CREATE EVENT SESSION [slowquerylog]
ON SERVER
    ADD EVENT sqlserver.blocked_process_report
    (ACTION
     (
         sqlserver.client_app_name,
         sqlserver.client_hostname,
         sqlserver.database_id,
         sqlserver.database_name,
         sqlserver.plan_handle,
         sqlserver.query_hash,
         sqlserver.request_id,
         sqlserver.session_id,
         sqlserver.sql_text
     )
    )
    ADD TARGET package0.event_file
    (SET filename = N'E:\DBExtentEvent\slowquerylog.xel')
WITH
(
    STARTUP_STATE = ON
);
GO

完成

你可以勾选

a.扩展事件创建完成之后立刻启动

b.查看实时捕获的数据

立刻启动扩展事件

一定要设置locked process threshold，否则无办法捕获慢SQL语句，这个选项类似于MySQL的long_query_time参数

locked process threshold是SQL Server2005推出的一个选项，下面设置阻塞10秒就会记录

--窗口2
--locked process threshold是SQL Server2005推出的一个选项

--设置阻塞进程阈值
sp_configure 'show advanced options', 1 ;  
GO  
RECONFIGURE ;  
GO  
sp_configure 'blocked process threshold', 10 ;   --10秒
GO  
RECONFIGURE ;  
GO

执行一个update语句，不要commit

--窗口3
USE testdb;
GO

BEGIN tran
update Account
set name ='Test'
where ID = 2

--commit

查询数据

-- 窗口4
USE testdb;
GO

-- 这个查询会被窗口3中的事务阻塞
SELECT * FROM Account
WHERE ID = 2

执行完毕之后，你可以看到扩展事件已经记录下来了

双击查看详细的会话里面的语句

可以很清楚的看到谁是被blocked的语句，谁是主动blocking的语句也就是源头

同时可以看到扩展事件已经记录到xel文件

使用其他编程语言制作慢查询日志报表

微软提供了使用 SQL Server Management Studio (SSMS) 和 T-SQL 查询扩展事件 XEL 文件内容的 API。

我们可以使用 sys.fn_xe_file_target_read_file 函数来读取 XEL 文件中的内容。
然后，你可以将这些数据导出为其他编程语言可以处理的格式

SQL语句

-- 查询扩展事件 XEL 文件内容
SELECT 
    event_data.value('(event/@name)[1]', 'VARCHAR(50)') AS event_name,
    event_data.value('(event/@timestamp)[1]', 'DATETIME2') AS event_timestamp,
    event_data.value('(event/data[@name="duration"]/value)[1]', 'INT') AS duration,
    event_data.value('(event/action[@name="client_app_name"]/value)[1]', 'VARCHAR(255)') AS client_app_name,
    event_data.value('(event/action[@name="client_hostname"]/value)[1]', 'VARCHAR(255)') AS client_hostname,
    event_data.value('(event/action[@name="database_name"]/value)[1]', 'VARCHAR(255)') AS database_name,
    event_data.value('(event/action[@name="sql_text"]/value)[1]', 'VARCHAR(MAX)') AS sql_text
FROM 
    sys.fn_xe_file_target_read_file('E:\DBExtentEvent\slowquerylog*.xel', NULL, NULL, NULL) AS t
CROSS APPLY 
    t.event_data.nodes('event') AS XEvent(event_data);

使用 Python 读取 XEL 文件内容
使用 pandas 库和pyodbc驱动程序从 SQL Server 导出数据并在 Python 中进行处理。
以下是一个示例脚本

import pyodbc
import pandas as pd

# 设置数据库连接
conn = pyodbc.connect(
    'DRIVER={SQL Server};'
    'SERVER=your_server_name;'
    'DATABASE=your_database_name;'
    'UID=your_username;'
    'PWD=your_password'
)

# 查询 XEL 文件内容
query = """
SELECT 
    event_data.value('(event/@name)[1]', 'VARCHAR(50)') AS event_name,
    event_data.value('(event/@timestamp)[1]', 'DATETIME2') AS event_timestamp,
    event_data.value('(event/data[@name="duration"]/value)[1]', 'INT') AS duration,
    event_data.value('(event/action[@name="client_app_name"]/value)[1]', 'VARCHAR(255)') AS client_app_name,
    event_data.value('(event/action[@name="client_hostname"]/value)[1]', 'VARCHAR(255)') AS client_hostname,
    event_data.value('(event/action[@name="database_name"]/value)[1]', 'VARCHAR(255)') AS database_name,
    event_data.value('(event/action[@name="sql_text"]/value)[1]', 'VARCHAR(MAX)') AS sql_text
FROM 
    sys.fn_xe_file_target_read_file('E:\DBExtentEvent\slowquerylog*.xel', NULL, NULL, NULL) AS t
CROSS APPLY 
    t.event_data.nodes('event') AS XEvent(event_data);
"""

# 使用 pandas 读取数据
df = pd.read_sql(query, conn)

# 关闭数据库连接
conn.close()

# 显示数据
print(df)

# 将数据保存为 CSV 文件
df.to_csv('slowquerylog.csv', index=False)

这里的一个问题是，你不能直接读取XEL文件，本身XEL文件是一个二进制文件，必须挂接到在线SQL Server实例（任何SQL Server实例都可以，不一定是生产库的那一台SQL Server实例，只要是XEL文件所在的机器）

另外一个方法是使用 PowerShell 中的 Microsoft.SqlServer.XEvent.Linq.QueryableXEventData 类直接解析 XEL 文件，不用挂接到SQL Server实例

直接读取 XEL 文件的内容，然后导出CSV文件，让其他编程语言处理

Step 1: 创建 PowerShell 脚本 ReadXELFile.ps1

# 加载所需的程序集
Add-Type -Path "C:\Program Files\Microsoft SQL Server\140\SDK\Assemblies\Microsoft.SqlServer.XEvent.Linq.dll"

# 定义XEL文件路径
$xelFilePath = "E:\DBExtentEvent\slowquerylog*.xel"

# 创建XEventData对象
$events = New-Object Microsoft.SqlServer.XEvent.Linq.QueryableXEventData($xelFilePath)

# 初始化一个空数组来存储事件数据
$eventDataList = @()

# 遍历每个事件并提取所需的字段
foreach ($event in $events) {
    $eventData = New-Object PSObject -Property @{
        EventName      = $event.Name
        Timestamp      = $event.Timestamp
        Duration       = $event.Fields["duration"].Value
        ClientAppName  = $event.Actions["client_app_name"].Value
        ClientHostname = $event.Actions["client_hostname"].Value
        DatabaseName   = $event.Actions["database_name"].Value
        SqlText        = $event.Actions["sql_text"].Value
    }
    $eventDataList += $eventData
}

# 将事件数据导出为CSV文件
$eventDataList | Export-Csv -Path "E:\DBExtentEvent\slowquerylog.csv" -NoTypeInformation

Step 2: Python 脚本 ReadCSVFile.py读取导出的 CSV 文件

import pandas as pd

# 定义CSV文件路径
csv_file_path = "E:\\DBExtentEvent\\slowquerylog.csv"

# 使用pandas读取CSV文件
df = pd.read_csv(csv_file_path)

# 显示数据
print(df)

这个方法需要使用PowerShell ，对于PowerShell 不熟悉的朋友也是一个问题

实现简单审计

虽然SQL Server自带审计功能，但有时候捕捉某些SQL比较困难，我们借助扩展事件更加精准捕捉有问题的SQL语句

有一个场景是，系统用户反馈某个功能的数据每隔几天就会被“恢复”一次，这个恢复操作由一个更新语句所触发，由于不定时发生，所以很难捕捉实际情况。项目负责人遍历整个代码之后发现代码没有包含这个更新语句，怀疑某个版本升级过程完整更新导致在服务器的某个服务中残留代码。要完成这个工作，全面捕捉所有DML语句是不现实的，非常高的QPS加上不定期执行会带来困难。

这时候可以使用扩展事件来处理这个问题

在测试数据库下创建一个test表（只有一个ID字段，这里不演示了），然后创建一个扩展事件来监控SQL文本为update test的语句，把捕捉结果存储在文件里面，执行更新语句后，查询结果

--创建事件会话
IF EXISTS (SELECT * FROM sys.server_event_sessions WHERE name = 'CaptureSQL')
-- 如果已有则删除事件会话
DROP EVENT SESSION [CaptureSQL] ON SERVER
GO
-- 创建名为CaptureSQL的事件会话
CREATE EVENT SESSION [CaptureSQL] ON SERVER
-- 添加sql_statement_starting和sql_statement_completed的跟踪，并且对sql_text列进行筛选，同时为了减少开销，还指定了数据库名
-- 在Action中通常添加我们需要跟踪的内容
ADD EVENT sqlserver.sql_statement_starting(
    ACTION(sqlserver.client_app_name, sqlserver.client_connection_id,
    sqlserver.client_hostname, sqlserver.client_pid, sqlserver.database_id,
    sqlserver.nt_username, sqlserver.sql_text, sqlserver.username)
    WHERE ((sql_text like '%update&test%') AND ([sqlserver].[database_name]=(N'AdventureWorks2016')))  --关键这一句，捕捉update test语句
),
ADD EVENT sqlserver.sql_statement_completed(
    ACTION(sqlserver.client_app_name, sqlserver.client_connection_id,
    sqlserver.client_hostname, sqlserver.client_pid, sqlserver.database_id,
    sqlserver.nt_username, sqlserver.sql_text, sqlserver.username)
    WHERE ((sql_text like '%update&test%')) AND ([sqlserver].[database_name]=(N'AdventureWorks2016'))
)
-- 把会话数据保存到文件中以便日后查看
ADD TARGET package0.event_file(
    SET filename=N'E:\SQLData\CaptureSQL.xel',
    METADATAFILE = N'E:\SQLData\CaptureSQL.xem'
)
WITH (STARTUP_STATE=ON) -- 指定随着服务器启动而启用，服务器宕机后能自动继续运行
GO
-- 创建完后启用会话，因为默认会话是不开启的
ALTER EVENT SESSION [CaptureSQL] ON SERVER STATE = START;
GO




查询结果
;WITH ee_data AS
(
    SELECT data = CONVERT(XML, event_data)
    FROM sys.fn_xe_file_target_read_file(
        N'E:\SQLData\CaptureSQL.xel', -- 注意替换实际路径
        N'E:\SQLData\CaptureSQL.xem', -- 注意替换实际路径
        NULL, NULL
    )
),
tab AS
(
    SELECT
        [host] = data.value('(/event/action[@name="client_hostname"]/value)[1]', 'nvarchar(400)'),
        app_name = data.value('(/event/action[@name="client_app_name"]/value)[1]', 'nvarchar(400)'),
        username = data.value('(/event/action[@name="username"]/value)[1]', 'nvarchar(400)'),
        [object_name] = data.value('(/event/data[@name="object_name"]/value)[1]', 'nvarchar(250)'),
        [timestamp] = data.value('(/event/@timestamp)[1]', 'datetime2'),
        [statement] = data.value('(/event/action[@name="sql_text"]/value)[1]', 'nvarchar(400)'),
        [DBName] = DB_Name(data.value('(/event/action[@name="database_id"]/value)[1]', 'nvarchar(400)')),
        [ClientPid] = data.value('(/event/action[@name="client_pid"]/value)[1]', 'nvarchar(400)')
    FROM ee_data
)
SELECT DISTINCT [host], app_name, username, MAX([timestamp]) as last_executed,
    [object_name], [statement], [DBName], ClientPid
FROM tab
GROUP BY [host], app_name, username, [object_name], [statement], [DBName], ClientPid;

创建完毕之后，我们可以使用简单的UPDATE TEST SETID=1语句可触发事件。

通过这种简单的审计方法，让捕捉SQL语句更加简单

总结

本文介绍了利用【SQL Server的扩展事件】捕获慢查询语句的功能，也就是我们常说的开源数据库的慢日志

另外，一定要设置“blocked process threshold”参数，否则设置了扩展事件也没有效果

总体来说，SQL Server作为一个企业级数据库，确实不像MySQL这种开源数据库简单直接

需要设置比较繁琐的扩展事件，对新手用户不太友好，门槛比较高，但是因为扩展事件功能非常强大

除了捕获慢查询语句还可以捕获死锁，索引缺失等性能问题，所以这个是在所难免的

参考文章

https://www.sqlshack.com/using-sql-server-extended-events-to-monitor-query-performance/

https://learn.microsoft.com/en-us/troubleshoot/sql/database-engine/performance/troubleshoot-slow-running-queries

https://erikdarling.com/monitoring-sql-server-for-query-timeouts-with-extended-events/

https://sqlmaestros.com/free-sql-video-troubleshoot-slow-running-query-sql-server-extended-events-wait-stats/

本文版权归作者所有，未经作者同意不得转载。