背景
ADOをつかってSQL Serverに接続している環境下では、「コマンドタイムアウトを1秒に設定しても1秒でタイムアウトしない」という挙動になる場合があります。
これは、ADOの場合はクライアントアプリケーション側が何らかの結果やメッセージを受取るたびに経過時間が0にリセットされる、という挙動をとるためです。
したがって、SSMSで実行した際の↓のようなメッセージを受け取った場合でも、経過時間が途中でリセットされます。そのため場合によってはアプリ側で設定したタイムアウト秒数を超えて実行し続ける場合があります。
これを解消させるために使う手段として、「set nocount on」オプションを付与する、というものがあります。
このオプションを付与してクエリを実行することでメッセージが出なくなります。
今回は、この挙動について調べてみました。
調査
WEBサーバーとDB間での通信をキャプチャするためにWiresharkを使用します。
WEBサーバーとDBサーバーが別サーバーに存在する場合は「イーサネット」を選択します。
実験①
以下のストアドプロシージャを、VBScript側のコマンドタイムアウト2秒で実行してみます。
updateの度に「〇行処理されました」がクライアントに送信され、最後まで実行され続けるのではと予想しました。
create PROCEDURE [dbo].[Test]
AS
BEGIN
update Table set RegistDT = getdate() where Column1 = 1
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
waitfor delay '00:00:01'
END
ストアド実行用プログラム
<package>
<job>
<script language="VBScript">
OPTION EXPLICIT
dim oConn
set oConn = CreateObject("ADODB.Connection")
oConn.Open(sDSN)
Const sDSN = "Connection String"
Dim oCmd, oRS
Set oCmd = CreateObject("ADODB.Command")
set oCmd.ActiveConnection = oConn
oCmd.CommandType = 4
oCmd.CommandTimeOut = 2
oCmd.CommandText = "Test"
WScript.Echo Now & "/ start"
Set oRS = oCmd.Execute()
WScript.Echo Now & "/ end"
</script>
</job>
</package>
実行結果です。予想に反し、途中でResponseが返ってきておらず、コマンドタイムアウトの設定値である2秒後にタイムアウトしていました。(NWキャプチャにおける「Attention」に相当)
実験②
RAISERRORを使って強制的に途中でメッセージを返すように修正して実験してみます。
create PROCEDURE [dbo].[Test]
AS
BEGIN
update Table set RegistDT = getdate() where Column1 = 1
RAISERROR(N'test', 0, 0, 0) WITH NOWAIT
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
RAISERROR(N'test', 0, 0, 0) WITH NOWAIT
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
RAISERROR(N'test', 0, 0, 0) WITH NOWAIT
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
RAISERROR(N'test', 0, 0, 0) WITH NOWAIT
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
RAISERROR(N'test', 0, 0, 0) WITH NOWAIT
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
RAISERROR(N'test', 0, 0, 0) WITH NOWAIT
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
RAISERROR(N'test', 0, 0, 0) WITH NOWAIT
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
RAISERROR(N'test', 0, 0, 0) WITH NOWAIT
waitfor delay '00:00:01'
update Table set RegistDT = getdate() where Column1 = 1
RAISERROR(N'test', 0, 0, 0) WITH NOWAIT
waitfor delay '00:00:01'
END
同じプログラムを使ってストアドを実行したところ、コマンドタイムアウトは2秒に設定していたのですが、約10秒間かかって最後まで実行されました。NWキャプチャをみると、定期的にResponse(Not last buffer)を受け取っていることが分かります。今回はクライアントに都度メッセージが送信されていたため、このような挙動となりました。
実験② - ado.netでの実験
今まではadoで実験していましたが、ado.netではどうなるのかも確認してみました。
Clear-Host
$con = New-Object System.Data.SqlClient.SqlConnection("Connection String")
$con.Open()
try{
$cmd= $con.CreateCommand()
$cmd.CommandType = [System.Data.CommandType]::StoredProcedure
$cmd.CommandText = "Test"
$cmd.CommandTimeout = 2
$cmd.ExecuteNonQuery()
$con.Close()
$con.Dispose()
}catch{
Write-Host $_.Exception
}
Write-Host "End."
powershellで実行すると、ado.netでクエリ実行されます。
結果としては、2秒でタイムアウトしました。設定したコマンドタイムアウト値が効いているようです。
途中でレスポンスも返ってきてはいます。ado.netだと、途中でレスポンスが返ってくることでタイムアウト時間が伸びるといった挙動は無い模様です。
実験②では強制的に途中でレスポンス返すようにしていますが、実際のストアドプロシージャではそのような記述はありません。
応答をバッファリングしている可能性があるため、大量にメッセージを出力させる方式で再度実験してみました。
実験③
以下のように、ストアドプロシージャをループさせて大量にメッセージを返すように書き換えました。
alter PROCEDURE [dbo].[Test2]
AS
BEGIN
declare @cnt int
set @cnt = 0
while (1=1)
begin
update Table set RegistDT = getdate() where Column1 = 1
set @cnt = @cnt + 1
if @cnt > 10000
begin
waitfor delay '00:00:01'
set @cnt = 0
end
end
END
大量にメッセージを返すようにしていると、定期的に応答が返ってくる模様です。やはり応答はある程度バッファリングされているようでした。また、それに伴いコマンドタイムアウトの設定値以上の時間で実行され続けていました。
続いて、ストアドにset nocount onを付与して再度実行してみると、コマンドタイムアウトの設定値である2秒でタイムアウトしました。
alter PROCEDURE [dbo].[Test2]
AS
BEGIN
set nocount on
declare @cnt int
set @cnt = 0
while (1=1)
begin
update Table set RegistDT = getdate() where Column1 = 1
set @cnt = @cnt + 1
if @cnt > 10000
begin
waitfor delay '00:00:01'
set @cnt = 0
end
end
END
今回はプログラム側で設定した2秒でタイムアウトし、Response (Not last buffer)も送られていないことが確認できました。
まとめ
set nocount onを付与することで途中のメッセージを送られない状態にすることは、意図した時間でタイムアウトを発生させるのに有効な手段であると確認できました。
ただし、print debugや、通常のレコードセットのSELCET等で途中のレスポンスが返されると、その場合でもタイムアウト時間以上実行され続ける可能性はあるため、どんなストアドでもset nocount onつけておけばOKというわけでもない点には注意が必要です。
もう少し複雑なストアドの場合
別のプロシージャを実行した場合、そちらにもset nocount onは必要なのかについて調べました。
1.呼び出し元
create procedure proc1
as
set nocount off
set xact_abort on
begin distributed tran
declare @cnt int = 1
while(@cnt <= 10000)
begin
exec [sub].subdb.dbo.proc2 @cnt
set @cnt += 1
end
commit tran
2.リモート側
create procedure proc2
@cnt int
as
set nocount on
update table set column = 1 where column = @cnt
実験結果
結論
リモート側ではSET NOCOUNT ON/OFFはどちらでもいい。
重要なのは、呼び出し元でSET NOCOUNT ONしていること。
まとめ
NWキャプチャを使用し、様々なケースでDBからクライアントへとメッセージが送られる挙動を確認ました。
これにより、設定した秒数でタイムアウトさせるために必要なオプションの設定方法や設定時の挙動の違いについて理解を深めることができました。