如何统计多条静态SELECT语句的执行耗时？

问题原因 #

mssql-cli默认仅捕获SQL查询的结果集，PRINT语句的输出属于数据库消息流，不会被写入到-o参数指定的输出文件中，这就是你看不到时间戳和耗时信息的原因。

解决办法 #

方法1：将PRINT输出改为SELECT语句输出

把原本用PRINT输出的时间信息改成SELECT查询，这样就能和其他查询结果一起被捕获到输出文件里。修改后的SQL脚本如下：

declare @StartTime DateTime = GETDATE()
SELECT '开始时间: ' + CONVERT(varchar, @StartTime, 121) AS 执行时间信息
select * from <table1> where PK_ID='<value_1>'
select * from <table1> where PK_ID='<value_2>'
select * from <table2> where PK_ID='<value_3>'
select * from <table2> where PK_ID='<value_4>'
select * from <table3> where PK_ID='<value_5>'
declare @endTime DateTime = GETDATE()
SELECT '总耗时: ' + CONVERT(varchar, DATEDIFF(ms, @StartTime, @endTime)) + ' 毫秒' AS 执行时间信息;

这里用DATEDIFF计算毫秒级耗时，比直接计算时间差的格式更清晰，也避免了ISNULL的多余处理（因为@StartTime和@endTime不可能为NULL）。

方法2：修改命令重定向所有输出

mssql-cli会把PRINT的消息输出到标准错误流（stderr），查询结果输出到标准输出（stdout）。你可以通过重定向把两者合并到同一个文件中，命令修改为：

mssql-cli -i /tmp/query.sql > /tmp/query_output 2>&1

这种方式会把消息和结果混合输出到文件里，需要自行区分内容。

方法3：使用sqlcmd替代mssql-cli

sqlcmd对消息和结果的捕获支持更灵活，通过-r 1参数可以把消息输出到标准输出，从而和查询结果一起写入文件。示例命令：

sqlcmd -S <你的数据库服务器> -U <用户名> -P <密码> -i /tmp/query.sql -o /tmp/query_output -r 1

额外建议：统计单条语句耗时 #

如果需要统计每条SELECT语句的单独耗时，而不是总耗时，可以在每条语句前后添加时间记录：

declare @StartTime DateTime, @EndTime DateTime

SET @StartTime = GETDATE()
SELECT '查询table1 value_1开始时间: ' + CONVERT(varchar, @StartTime, 121) AS 执行日志
select * from <table1> where PK_ID='<value_1>'
SET @EndTime = GETDATE()
SELECT '查询table1 value_1耗时: ' + CONVERT(varchar, DATEDIFF(ms, @StartTime, @EndTime)) + ' 毫秒' AS 执行日志

-- 其他查询语句重复上述时间记录逻辑

内容的提问来源于stack exchange，提问作者spark101