2021-07-15

メモ：Google.OrTools

.NET

NuGet Gallery | Google.OrTools 9.0.9048

About OR-Tools | Google Developers
Vehicle Routing | OR-Tools | Google Developers

2021-07-14

Internal retry logic providers in SqlClient の動作確認

.NET SQL Server

SqlClient の内部再試行ロジックプロバイダー - ADO.NET Provider for SQL Server | Microsoft Docs
を試したのでログ貼っとく。

環境は

.NET 5.0
Microsoft.Data.SqlClient 3.0.0

SqlClient での構成可能な再試行ロジック構成ファイル - ADO.NET Provider for SQL Server | Microsoft Docs
構成ファイルで試してるのは、Dapper 使うと、構成ファイル位でしか SqlCommand に設定出来なさそうなので。
※SqlConnection を Wrap して DbConnection の実装をそのまま SqlConnection から返して、CreateCommand だけ、何か刺せるような自作 Connection 作るなら別だけど面倒そう。

試行回数：5回、遅延時間：3秒、最長遅延時間：10秒で

App.config

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configSections>
    <section name="SqlConfigurableRetryLogicCommand" 
             type="Microsoft.Data.SqlClient.SqlConfigurableRetryCommandSection, Microsoft.Data.SqlClient" />
    <section name="AppContextSwitchOverrides"
             type="Microsoft.Data.SqlClient.AppContextSwitchOverridesSection, Microsoft.Data.SqlClient"/>
  </configSections>
  <SqlConfigurableRetryLogicCommand retryMethod ="Create<Fixed/Incremental/Exponential/None のどれか>RetryProvider"
    numberOfTries ="5" deltaTime ="00:00:03" maxTime ="00:00:10"
    transientErrors ="<リトライするエラー番号 をカンマ区切り>"/>
  <AppContextSwitchOverrides 
    value="Switch.Microsoft.Data.SqlClient.EnableRetryLogic=true"/>
</configuration>

ログは該当の箇所のみ抜粋

Microsoft.Data.SqlClient.SqlConfigurableRetryFactory.CreateFixedRetryProvider

固定間隔なので、指定の間隔(今回は3秒)で。

<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 0).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:02.4230000' before the next retry number 1
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:1, upcoming delay:00:00:02.4230000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:02.4230000' and run the action for retry number 1.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 1).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:02.7400000' before the next retry number 2
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:2, upcoming delay:00:00:02.7400000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:02.7400000' and run the action for retry number 2.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 2).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:02.4800000' before the next retry number 3
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:3, upcoming delay:00:00:02.4800000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:02.4800000' and run the action for retry number 3.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 3).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:03.1090000' before the next retry number 4
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:4, upcoming delay:00:00:03.1090000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:03.1090000' and run the action for retry number 4.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 4).

<sc.SqlRetryLogic.TryNextInterval|INFO> Current retry (4) has reached the maximum attempts (total attempts excluding the first run = 4).
<sc.SqlRetryLogicProvider.CreateException|ERR|THROW> Exiting retry scope (exceeded the max allowed attempts = 5).
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
The number of retries has exceeded the maximum of 5 attempt(s).

Microsoft.Data.SqlClient.SqlConfigurableRetryFactory.CreateIncrementalRetryProvider

インクリメンタルなので、遅延時間ずつ増えていく感じで。
ただし、最長10秒にしてるので10秒を超えなかった。

<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 0).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:02.8490000' before the next retry number 1
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:1, upcoming delay:00:00:02.8490000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:02.8490000' and run the action for retry number 1.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 1).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:05.9310000' before the next retry number 2
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:2, upcoming delay:00:00:05.9310000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:05.9310000' and run the action for retry number 2.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 2).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:09.0170000' before the next retry number 3
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:3, upcoming delay:00:00:09.0170000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:09.0170000' and run the action for retry number 3.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 3).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:08.4747851' before the next retry number 4
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:4, upcoming delay:00:00:08.4747851, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:08.4747851' and run the action for retry number 4.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 4).

<sc.SqlRetryLogic.TryNextInterval|INFO> Current retry (4) has reached the maximum attempts (total attempts excluding the first run = 4).
<sc.SqlRetryLogicProvider.CreateException|ERR|THROW> Exiting retry scope (exceeded the max allowed attempts = 5).
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
The number of retries has exceeded the maximum of 5 attempt(s).

Microsoft.Data.SqlClient.SqlConfigurableRetryFactory.CreateExponentialRetryProvider

指数関数的に増えるらしいので、最長時間を最大値の 2分 (120秒) に変更して確認。
3(3¹)、9(3²)、27(3³)、81(3⁴) と増えるのかと思ったけど、そこまで急激じゃなかった。
まあ最長が120秒なのでそんなもんなんかな。

<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 0).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:03.4410000' before the next retry number 1
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:1, upcoming delay:00:00:03.4410000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:03.4410000' and run the action for retry number 1.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 1).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:08.2770000' before the next retry number 2
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:2, upcoming delay:00:00:08.2770000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:08.2770000' and run the action for retry number 2.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 2).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:24.9620000' before the next retry number 3
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:3, upcoming delay:00:00:24.9620000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:24.9620000' and run the action for retry number 3.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 3).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:53.4450000' before the next retry number 4
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:4, upcoming delay:00:00:53.4450000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:53.4450000' and run the action for retry number 4.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 4).

<sc.SqlRetryLogic.TryNextInterval|INFO> Current retry (4) has reached the maximum attempts (total attempts excluding the first run = 4).
<sc.SqlRetryLogicProvider.CreateException|ERR|THROW> Exiting retry scope (exceeded the max allowed attempts = 5).
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
The number of retries has exceeded the maximum of 5 attempt(s).

一応最長時間を10秒のも貼っとく。10秒前で頭打ち。

<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 0).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:03.2150000' before the next retry number 1
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:1, upcoming delay:00:00:03.2150000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:03.2150000' and run the action for retry number 1.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 1).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:09.0030000' before the next retry number 2
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:2, upcoming delay:00:00:09.0030000, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:09.0030000' and run the action for retry number 2.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 2).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:09.2335084' before the next retry number 3
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:3, upcoming delay:00:00:09.2335084, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:09.2335084' and run the action for retry number 3.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 3).

<sc.SqlRetryLogic.TryNextInterval|INFO> Next gap time will be '00:00:09.9630303' before the next retry number 4
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Running the retrying event.
<sc.SqlConfigurableRetryLogicLoader.OnRetryingEvent|INFO>: Default configurable retry logic for SqlCommand object. attempts count:4, upcoming delay:00:00:09.9630303, Last exception:<～>
<sc.SqlRetryLogicProvider.ApplyRetryingEvent|INFO> Wait '00:00:09.9630303' and run the action for retry number 4.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogicProvider.ExecuteAsync<TResult>|INFO> Found an action eligible for the retry policy (retried attempts = 4).

<sc.SqlRetryLogic.TryNextInterval|INFO> Current retry (4) has reached the maximum attempts (total attempts excluding the first run = 4).
<sc.SqlRetryLogicProvider.CreateException|ERR|THROW> Exiting retry scope (exceeded the max allowed attempts = 5).
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
The number of retries has exceeded the maximum of 5 attempt(s).

Microsoft.Data.SqlClient.SqlConfigurableRetryFactory.CreateNoneRetryProvider

None なのでリトライはしない。
ただ None の時は、Provider 生成の箇所のログが面白いので貼っとく。

<sc.SqlConfigurableRetryLogicManager.CommandProvider|INFO> Requested the CommandProvider value.
<sc.AppConfigManager.FetchConfigurationSection|INFO>: Unable to load custom `SqlConfigurableRetryLogicConnection`. Default value of `T` type returns.
<sc.AppConfigManager.FetchConfigurationSection|INFO> Successfully loaded the configurable retry logic settings from the configuration file's section 'SqlConfigurableRetryLogicCommand'.
<sc.SqlConfigurableRetryLogicLoader.CreateRetryLogicProvider|INFO> Entry point.
<sc.SqlConfigurableRetryLogicLoader.CreateRetryLogicProvider|INFO> Successfully created a SqlRetryLogicOption object to use on creating a retry logic provider from the section 'SqlConfigurableRetryLogicCommand'.
<sc.SqlConfigurableRetryLogicLoader.ResolveRetryLogicProvider|INFO> Entry point.
<sc.SqlConfigurableRetryLogicLoader.LoadType|INFO> Entry point.
<sc.SqlConfigurableRetryLogicLoader.LoadType|INFO> Couldn't resolve the requested type by ''; The internal `Microsoft.Data.SqlClient.SqlConfigurableRetryFactory` type is returned.
<sc.SqlConfigurableRetryLogicLoader.LoadType|INFO> Exit point.
<sc.SqlConfigurableRetryLogicLoader.CreateInstance|INFO> Entry point.
<sc.SqlConfigurableRetryLogicLoader.CreateInstance|INFO> The given type `SqlConfigurableRetryFactory` infers as internal `Microsoft.Data.SqlClient.SqlConfigurableRetryFactory` type.
<sc.SqlConfigurableRetryLogicLoader.CreateInstance|INFO> The `Microsoft.Data.SqlClient.SqlConfigurableRetryFactory.CreateNoneRetryProvider()` method has been discovered as the `CreateNoneRetryProvider` method name.
'netcore5.exe' (CoreCLR: clrhost): 'C:\Program Files\dotnet\shared\Microsoft.NETCore.App\5.0.7\System.Reflection.Metadata.dll' が読み込まれました。シンボルの読み込みをスキップしました。モジュールは最適化されていて、デバッグ オプションの [マイ コードのみ] 設定が有効になっています。
'netcore5.exe' (CoreCLR: clrhost): 'C:\Program Files\dotnet\shared\Microsoft.NETCore.App\5.0.7\System.Collections.Immutable.dll' が読み込まれました。シンボルの読み込みをスキップしました。モジュールは最適化されていて、デバッグ オプションの [マイ コードのみ] 設定が有効になっています。
<sc.SqlConfigurableRetryLogicLoader.CreateRetryLogicProvider|INFO> System.Exception: Exception occurred when running the `Microsoft.Data.SqlClient.SqlConfigurableRetryFactory.CreateNoneRetryProvider()` method.
 ---> System.InvalidOperationException: Failed to create SqlRetryLogicBaseProvider object because of invalid CreateNoneRetryProvider's parameters.
The function must have a paramter of type 'SqlRetryLogicOption'.
   at Microsoft.Data.SqlClient.SqlConfigurableRetryLogicLoader.PrepareParamValues(ParameterInfo[] parameterInfos, SqlRetryLogicOption option, String retryMethod)
   at Microsoft.Data.SqlClient.SqlConfigurableRetryLogicLoader.CreateInstance(Type type, String retryMethodName, SqlRetryLogicOption option)
   at Microsoft.Data.SqlClient.SqlConfigurableRetryLogicLoader.ResolveRetryLogicProvider(String configurableRetryType, String retryMethod, SqlRetryLogicOption option)
   --- End of inner exception stack trace ---
   at Microsoft.Data.SqlClient.SqlConfigurableRetryLogicLoader.ResolveRetryLogicProvider(String configurableRetryType, String retryMethod, SqlRetryLogicOption option)
   at Microsoft.Data.SqlClient.SqlConfigurableRetryLogicLoader.CreateRetryLogicProvider(String sectionName, ISqlConfigurableRetryConnectionSection configSection)
<sc.SqlConfigurableRetryLogicLoader.CreateRetryLogicProvider|INFO> Due to an exception, the default non-retriable logic will be applied.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.
<sc.SqlRetryLogic.RetryCondition|INFO> (retry condition = 'True') Avoids retry if it runs in a transaction or is skipped in the command's statement checking.

Provider 生成時に例外が出て、例外が出た時は、default の non-retriable logic を適用してる。
例外が出るのは、構成ファイルで指定するメソッドは、第一引数に SqlRetryLogicOption を受け取る必要があるけど、CreateNoneRetryProvider は引数無しだから。

https://github.com/dotnet/SqlClient/blob/a51a67453c27c81816d90e15b6100c308108840c/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/Reliability/SqlConfigurableRetryLogicLoader.cs#L162-L178

if (type == typeof(SqlConfigurableRetryFactory) || type == null)
{
    SqlClientEventSource.Log.TryTraceEvent("<sc.{0}.{1}|INFO> The given type `{2}` infers as internal `{3}` type."
                                            , TypeName, methodName, type?.Name, typeof(SqlConfigurableRetryFactory).FullName);
    MethodInfo internalMethod = typeof(SqlConfigurableRetryFactory).GetMethod(retryMethodName);
    if (internalMethod == null)
    {
        throw new InvalidOperationException($"Failed to resolve the '{retryMethodName}' method from `{typeof(SqlConfigurableRetryFactory).FullName}` type.");
    }


    SqlClientEventSource.Log.TryTraceEvent("<sc.{0}.{1}|INFO> The `{2}.{3}()` method has been discovered as the `{4}` method name."
                                            , TypeName, methodName, internalMethod.ReflectedType.FullName, internalMethod.Name, retryMethodName);
    object[] internalFuncParams = PrepareParamValues(internalMethod.GetParameters(), option, retryMethodName);
    SqlClientEventSource.Log.TryTraceEvent("<sc.{0}.{1}|INFO> Parameters are prepared to invoke the `{2}.{3}()` method."
                                            , TypeName, methodName, internalMethod.ReflectedType.FullName, internalMethod.Name);
    return internalMethod.Invoke(null, internalFuncParams);
}

https://github.com/dotnet/SqlClient/blob/a51a67453c27c81816d90e15b6100c308108840c/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/Reliability/SqlConfigurableRetryLogicLoader.cs#L215-L223

private static object[] PrepareParamValues(ParameterInfo[] parameterInfos, SqlRetryLogicOption option, string retryMethod)
{
    // The retry method must have at least one `SqlRetryLogicOption`
    if (parameterInfos.FirstOrDefault(x => x.ParameterType == typeof(SqlRetryLogicOption)) == null)
    {
        string message = $"Failed to create {nameof(SqlRetryLogicBaseProvider)} object because of invalid {retryMethod}'s parameters." +
            $"{Environment.NewLine}The function must have a paramter of type '{nameof(SqlRetryLogicOption)}'.";
        throw new InvalidOperationException(message);
    }

で、例外が発生したら、既定の動作で CreateNonRetryProvider を呼び出してる。

https://github.com/dotnet/SqlClient/blob/a51a67453c27c81816d90e15b6100c308108840c/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/Reliability/SqlConfigurableRetryLogicLoader.cs#L97-L100

SqlClientEventSource.Log.TryTraceEvent("<sc.{0}.{1}|INFO> Due to an exception, the default non-retriable logic will be applied.",
                                        TypeName, methodName);
// Return default provider if an exception occured.
return SqlConfigurableRetryFactory.CreateNoneRetryProvider();

なんで、明示的に CreateNoneRetryProvider を指定してたら、ログに例外出てるけど気にせずに。

2021-07-14

メモ：Azure SDK .NET スレッドセーフ

.NET Microsoft Azure

.NET Azure SDK Design Guidelines | Azure SDKs

✅ DO be thread-safe. All public members of the client type must be safe to call from multiple threads concurrently.

Azure SDK for .NET でのスレッドセーフ | Microsoft Docs

2021-07-08

xUnit.NET のパラレルテストと SQL Server (Local DB) で bacpac から import のメモ

.NET SQL Server

上手くいくかは未検証！

データは、if exists drop database + import bacpac で考える。
※楽だから
Local DB 前提で書いたけど、Local DB じゃなくても問題無さそう。

テスト側ではトランザクション制御出来ない前提。
Web App とかで HTTP 跨ぐようなイメージ。
メソッドのテストなら、テストで呼び出すときに、
TransactionScope で囲って Complete 呼ばないとかでトランザクション制御出来るケースが多そう。

テストの種類
- DB 使わない
- DB 使う : read only (テストデータ投入もしない。bacpac だけで完結)
- DB 使う : read write (bacpac + 個別のテストデータ or テスト中に書き換え)

xUnit.NET は何もしてないと全テストパラレルで動くはず。

DB 使わない (パラで問題なし)
DB 使う (read only) (以下の内容に気を付ければパラで問題なし)
- bacpac の import をテスト全体で1回だけ起こるようにする。
  - bacpac の import 時間削減 + 他テスト中に drop database / import bacpac が起きないように
  - C#9(.NET 5) の module initializer で良さげ
DB 使う (read write) (パラでは問題あり)
- write があるので、「他のテストと同じ database を参照している」とタイミングで問題が出そう。
  - read write があるテストは、他のテストと別の database (database 名 / 接続文字列 Initial Catalog)に変えて、bacpac を import して動かしたら他のテストとパラでも問題無い。
    - テスト対象のアプリは、HostBuilder なりなんなりで、接続文字列を差し替え出来る前提
    - 同じ database 名で動作するテストはパラだと困る。
      - XUnit.Collection でグルーピング。Collection 名を database 名したら良さげ。

まとめ

module initializer で read only で使う共通の DB を import する
write があるテストは、それぞれ XUnit.Collection + Database 名を変更して、別の Database として import して、Collection 単位でパラレルに動く

参考資料

NuGet Gallery | xunit 2.4.1
NuGet Gallery | Microsoft.SqlServer.DacFx 150.5164.1
Running Tests in Parallel > xUnit.net
Shared Context between Tests > xUnit.net
Module initializers - C# 9.0 specification proposals | Microsoft Docs
DROP DATABASE (Transact-SQL) - SQL Server | Microsoft Docs
ASP.NET Core MVC アプリのテスト | Microsoft Docs
DACExtensions/SqlTestDb.cs at 6ed437b23fdc0fb959394afd7d5aba99f64022f8 · microsoft/DACExtensions · GitHub

2021-06-22

メモ：TransactionScope の既定の分離レベルは Serializable

.NET SQL Server

公式のドキュメントを探す機会があったのでメモ。
トランザクションスコープを使用した暗黙的なトランザクションの実装 | Microsoft Docs
TransactionScope 分離レベルの設定の箇所から抜粋

既定では、トランザクションは Serializable に設定された分離レベルで実行されます。

C# のソースは

この辺か。https://t.co/VT7aH2kGWg
— Masayuki Ozawa (@Masayuki_Ozawa) 2021年6月22日

        internal static IsolationLevel DefaultIsolationLevel
        {
            get
            {
                TransactionsEtwProvider etwLog = TransactionsEtwProvider.Log;
                if (etwLog.IsEnabled())
                {
                    etwLog.MethodEnter(TraceSourceType.TraceSourceBase, "TransactionManager.get_DefaultIsolationLevel");
                    etwLog.MethodExit(TraceSourceType.TraceSourceBase, "TransactionManager.get_DefaultIsolationLevel");
                }
 
                return IsolationLevel.Serializable;
            }
        }

なんで既定が Serializable なんって疑問は、これ見たらなるほどねーって感じ。
c# - Why is System.Transactions TransactionScope default Isolationlevel Serializable - Stack Overflow

2021-06-18

.NET Core で SqlConnection の ConnectTimeout が 15未満に設定しても無視されてそう。

.NET SQL Server

.NET Framework と .NET Core で動作が違う。

SQL Server 2019 Developer Edition (サービスは止めとく)
.NET Core 5 / 3.1、.NET Framework 4.8
Microsoft.Data.SqlClient 3.0.0

なんか、.NET Core だと、既定値の 15 未満に設定しても、既定値の 15 で動いてそうな。。
実際に使う分には困らないから、ソースまで見る気ないけど issue は登録しといた。

Microsoft.Data.SqlClient 3.0.0 が出たから、RetryLogicProvier 試そうとしてて、
タイムアウト待つの面倒やなぁで、1秒に設定したら何か遅いってとこで発覚。。。

.NET 5 or 3.1

using Microsoft.Data.SqlClient;
using System;
using System.Diagnostics;

namespace ConnectTimeoutNotWorkCore
{
    class Program
    {
        static void Main(string[] args)
        {
            Console.WriteLine(typeof(Program).FullName);
            OpenError(1);
            OpenError(60);
            Console.ReadKey();
            /*
ConnectTimeoutNotWorkCore.Program
Start
Error Number:10061
16672
Done
Start
Error Number:10061
65981
Done
             */
        }
        static void OpenError(int connectTimeout)
        {
            var builder = new SqlConnectionStringBuilder()
            {
                DataSource = "localhost\\MSSQL2019",
                InitialCatalog = "master",
                IntegratedSecurity = true,
                ConnectTimeout = connectTimeout
            };
            var stopwatch = new Stopwatch();
            try
            {
                using (var conn = new SqlConnection(builder.ConnectionString))
                {
                    Console.WriteLine("Start");
                    stopwatch.Start();
                    conn.Open();
                }
            }
            catch (SqlException e)
            {
                Console.WriteLine($"Error Number:{e.Number}");
            }
            finally
            {
                stopwatch.Stop();
                Console.WriteLine(stopwatch.ElapsedMilliseconds);
                Console.WriteLine("Done");
            }
        }
    }
}

.NET Framework 4.8

using Microsoft.Data.SqlClient;
using System;
using System.Diagnostics;

namespace ConnectTimeoutNotWorkFx48
{
    class Program
    {
        static void Main(string[] args)
        {
            Console.WriteLine(typeof(Program).FullName);
            OpenError(1);
            OpenError(60);
            Console.ReadKey();
            /*
ConnectTimeoutNotWorkFx48.Program
Start
Error Number:258
1768
Done
Start
Error Number:258
60019
Done
             */
        }
        static void OpenError(int connectTimeout)
        {
            var builder = new SqlConnectionStringBuilder()
            {
                DataSource = "localhost\\MSSQL2019",
                InitialCatalog = "master",
                IntegratedSecurity = true,
                ConnectTimeout = connectTimeout
            };
            var stopwatch = new Stopwatch();
            try
            {
                using (var conn = new SqlConnection(builder.ConnectionString))
                {
                    Console.WriteLine("Start");
                    stopwatch.Start();
                    conn.Open();
                }
            }
            catch (SqlException e)
            {
                Console.WriteLine($"Error Number:{e.Number}");
            }
            finally
            {
                stopwatch.Stop();
                Console.WriteLine(stopwatch.ElapsedMilliseconds);
                Console.WriteLine("Done");
            }
        }
    }
}

github.com

2021-05-27

SqlParameter で ~char(max) の時の Size は -1

.NET SQL Server

size は -1 を渡す。
公式ドキュメントが中々見つからないのが難点…。

大きい値 (max) データの変更 - ADO.NET | Microsoft Docs
から抜粋

CREATE PROCEDURE GetDocumentSummary
(  
    @DocumentID int,  
    @DocumentSummary nvarchar(MAX) OUTPUT  
)  
AS  
SET NOCOUNT ON  
SELECT  @DocumentSummary=Convert(nvarchar(MAX), DocumentSummary)  
FROM    Production.Document  
WHERE   DocumentID=@DocumentID

SqlParameter paramSummary =
                new SqlParameter("@DocumentSummary",
                SqlDbType.NVarChar, -1);

つーわけで、nvarchar(MAX) の DocumentSummary の Size は -1 渡してます。