やりたいこと
EntityFramework をベースで利用し、複雑なクエリはEntityFrameworkのDatabase.Connectionを使いDapperでクエリ発行している。
Dapper & EntityFramework の両方でロギングを簡単にしたいので、MiniProfilerのProfiledDbConnection を使用。
作成は以下を参照。
- Http, SQL, Redisのロギングと分析・可視化について
http://neue.cc/2013/07/30_420.html - ASP.NET MVC 5 で DI する - その2「生成の一元化」 #aspnetjp - KatsuYuzuのブログ https://katsuyuzu.hatenablog.jp/entry/2014/11/12/015957
エラーの現象
EntityFramework のConnectionを使ったDapper側のQueryは無事出力されるのだが、EntityFrameworkでQuery発行すると以下のExceptionが出る。
System.Data.Entity.Core.ProviderIncompatibleException: 'A null was returned after calling the 'get_ProviderFactory' method on a store provider instance of type 'StackExchange.Profiling.Data.ProfiledDbConnection'. The store provider might not be functioning correctly.'
結論
諦めました。英語中文色々調べ試しもしましたが、答え出ず。
結局、Dapperを使うConnectionをEFのDatabase.Connectionでなく、Dapper接続用にProfiledDbConnectionをベースにしたConnectionをメンバDbConnectionとして追加し、EFのクエリの監視はDatabase.Logを使うようにしました。
できたもの
AppDbContext.cs
/// <summary>
/// ログ出力の設定項目
/// </summary>
public struct LogSettings
{
/// <summary>
/// TopMessageの空白埋め
/// </summary>
public const int TopMessagePadding = -20;
}
public static class StringExtensions
{
/// <summary>
/// 正規表現
/// </summary>
public static string RegexReplace(this string text, string regex, string replacement, RegexOptions options = RegexOptions.None)
{
return new Regex(regex, options).Replace(text, replacement);
}
/// <summary>
/// SQL Queryの文字列を短縮化 (不要な改行、空白を除去)
/// </summary>
public static string MinifySql(this string sql)
{
return sql
.RegexReplace(@"--(.*)", @"/*$1*/") // --コメント を /*コメント*/ に変換
.RegexReplace(@"\s+", " "); // スペース、タブ、改行の連続を1つのスペースに置換
}
}
public class AppDbContext : DbContext
{
/// <summary>
/// トレース可能なDbConnection
/// </summary>
/// <remarks>
/// MiniProfiler(ProfiledDbConnection)とEntity Frameworkの組み合わせにより、以前は正常に動作していたが、ProviderIncompatibleException により動作しない。
/// クエリトレース用DbConnectionを別途用意し、Dapperではそちらを使うようにする
/// </remarks>
public DbConnection DbConnection { get; }
public AppDbContext()
: base("AppDbContext")
{
// トレース可能なDbConnection
DbConnection = new ProfiledDbConnection(
Database.Connection,
new TraceDbProfiler()
);
// 自動遅延読み込みを有効にするか デフォルト:true
// falseだと明示的にIncludeを記載する必要あり。trueだと意図しない読み込むことにより性能劣化が発生するリスクあり。
Configuration.LazyLoadingEnabled = false;
// NULL 可のカラムに対する条件で特に非効率なクエリを生成する（NULL だった場合の処理/IS NULLも行う）
// これにより、Table Scan になってしまい、性能が落ちる。
// UseDatabaseNullSemanticsのオプションをtrueにすると、NULL だった場合の処理は消え、性能は上がるが、nullはヒットしなくなる。
// NULLの検索は null をラムダ式で直接指定すると可能
// NULLでの検索は基本行わないので、UseDatabaseNullSemanticsのオプションはtrueにする。
Configuration.UseDatabaseNullSemantics = true;
// SQL のログトレースはログレベルTraceで出力する
Database.Log = x =>
{
if (!string.IsNullOrWhiteSpace(x))
{
FileLogger.Trace($"{"EF Executed.",LogSettings.TopMessagePadding}{x.MinifySql()}");
}
};
}
TraceDbProfiler.cs
/// <summary>
/// DbConnectionに割り込み、DBアクセスのロギングをする(Oracle版)
/// </summary>
public class TraceDbProfiler : IDbProfiler
{
public bool IsActive => true;
private Stopwatch stopwatch;
private string commandText;
private IEnumerable<dynamic> parameters;
/// <summary>
/// エラーの時に呼ばれる
/// </summary>
public void OnError(System.Data.IDbCommand profiledDbCommand, SqlExecuteType executeType, System.Exception exception)
{
SetCommandTexts(profiledDbCommand);
Logging(isError: true, exception: exception);
}
/// <summary>
/// コマンドが開始された時に呼ばれる(ExecuteReader、ExecuteNonQuery等)
/// </summary>
public void ExecuteStart(System.Data.IDbCommand profiledDbCommand, SqlExecuteType executeType)
{
stopwatch = Stopwatch.StartNew();
}
/// <summary>
/// コマンドが完了された時に呼ばれる
/// </summary>
public void ExecuteFinish(System.Data.IDbCommand profiledDbCommand, SqlExecuteType executeType, System.Data.Common.DbDataReader reader)
{
SetCommandTexts(profiledDbCommand);
if (executeType != SqlExecuteType.Reader)
{
Logging(isError: false);
}
}
/// <summary>
/// Readerが完了した時に呼ばれる
/// </summary>
public void ReaderFinish(System.Data.IDataReader reader)
{
Logging(isError: false);
}
/// <summary>
/// SQL、パラメータの情報をセットする
/// </summary>
private void SetCommandTexts(System.Data.IDbCommand profiledDbCommand)
{
commandText = profiledDbCommand.CommandText.MinifySql();
parameters = profiledDbCommand.Parameters.Cast<Oracle.ManagedDataAccess.Client.OracleParameter>().ToList()
.Select(x => new { Name = x.ParameterName, x.Value });
}
/// <summary>
/// ログに出力する
/// </summary>
private void Logging(bool isError, System.Exception exception = null)
{
stopwatch.Stop();
string logText = JsonConvert.SerializeObject(
new
{
Type = SqlExecuteType.Reader.ToString(),
ms = stopwatch.ElapsedMilliseconds,
Exception = exception?.Message,
Params = parameters,
Command = commandText,
},
Formatting.None, // JSONを読みやすいように整形しない
new JsonSerializerSettings
{
NullValueHandling = NullValueHandling.Ignore // nullは出力しない
}
);
logText = $"{"DB Executed.",LogSettings.TopMessagePadding}{logText}";
if (isError)
{
FileLogger.Error(logText);
}
else
{
FileLogger.Trace(logText);
}
}
}