...

суббота, 3 мая 2014 г.

Профайлер для Entity Framework


Приветствую!


Продолжу серию статей про программирование. На это раз я хочу поговорить о профилировании и логировании по отношению с Entity Framework-у ( далее EF) c 4-й по 6-ю версию, а также о некоторых примененных мной решениях, таких как декомпилирование .NET кода на лету, форма для обработки исключению и прочее.


Подробности под катом.



Введение



Когда я начинал изучение EF, передо мной стал вопрос в профилировании запросов которые генерирует EF. После некоторого поиска я с неудовольствием обнаружил, что штатных средств EF не предоставляет, соответственно, приходилось пользоваться, на мой взгляд, крайне неудобной в использовании программой SQL Server Profiler или купить достаточно дорогой сторонний инструмент Entity Framework Profiler 2.0, за $389.00, а я жадный.

С появлением EF версии 6, ситуация с логированием команд изменилась. Появился механизм, который позволяет добавить свой интерцептор:



//Регистрируем при старте программы свой IDbCommandInterceptor
DbInterception.Add(new LogFormatter());



public class LogFormatter : IDbCommandInterceptor
{
private readonly Stopwatch _stopwatch = new Stopwatch();
public void NonQueryExecuting(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
{
// Перезапускам таймер
_stopwatch.Restart();
}
public void NonQueryExecuted(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
{
// Останавливаем таймер
_stopwatch.Stop();
// Логируем команду
Log(command, interceptionContext);
}
public void ReaderExecuting(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
{
_stopwatch.Restart();
}
public void ReaderExecuted(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
{
_stopwatch.Stop();
Log(command, interceptionContext);
}
public void ScalarExecuting(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
{
_stopwatch.Restart();
}
public void ScalarExecuted(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
{
_stopwatch.Stop();
Log(command, interceptionContext);
}
private void Log<TResult>(DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
{
Logger.Log(command, _stopwatch.ElapsedMilliseconds, interceptionContext.Exception);
}
}



public static class Logger
{
public static void Log(DbCommand command, long elapsedMilliseconds, Exception exception)
{
// Выводим в Trace команду
Trace.WriteLine(string.Format("Command:{0}, Elapsed Milliseconds:{1}", command.CommandText, elapsedMilliseconds));
}
}




Для 4-й версии EF похожего механизма логирования я не нашел.
Мое решение



Идею написать свой профайлер, повторяющий функционал платного, я вынашивал достаточно долго. Первоначальная версия базировалась на механизме интерцепторов EF 6-й версии, но к сожалению в EF 4-й версии этот механизм не работает.

После недолгого гугления, была найдена отличная библиотека для профилировки EF в ASP MVC приложениях, под названием MiniProfiler . На его основе и было решено сделать свое приложения.
Что получилось



Система получилась максимально простой для использования и интеграции. Забрать бинарники с примером проекта можно на созданном мной сайте на wordpress-e http://ef-logger.com/

Главное окно приложения:


Использование



1. Забрать архив с бинарниками и примером проекта



2. Подключить библиотеку EFlogger.EntityFramework4.dll для EF 4-5 версии и EFlogger.EntityFramework6.dll для EF 6-й версии

3. Инициализировать профайлер путем выполнения статического метода

// Для EF 6-й версии
EFloggerFor6.Initialize();
// или для EF с 4-й по 6-ю
EFloggerFor4.Initialize();




4. Запустить приложение EFlogger.exe
API



Пример для библиотеки EFlogger.EntityFramework6.dl, в случае использования EFlogger.EntityFramework4.dl статический класс будет назваться EFloggerFor6

//Инициализация
EFloggerFor6.Initialize();

// Задает IP профалера в случаях его отличие от "127.0.0.1"
EFloggerFor6.SetProfilerClientIP(“192.168.10.50″);

// Посылает текстовое сообщение в профайлер
EFloggerFor6.WriteMessage(“Text message”);

// Стартует посылку логов профайлер (уже запущен по умолчанию после инициализации)
EFloggerFor6.StartSendToClient();

// Останавливает посылку логов профайлер
EFloggerFor6.StopSendToClient();

// Стартует логирование в файл EFlogger.log приложения
EFloggerFor6.StartSaveToLogFile();

// Останавливает логирование в файл EFlogger.log приложения
EFloggerFor6.StopSaveToLogFile();

//Очищает лог в профайлере и удаляет файл лога, если включен
EFloggerFor6.ClearLog();

// Отключает декомпиляцию кода
EFloggerFor6.DisableDecompiling();

// Добавляет сборку для игнорирования при построении Stack Trace-a
EFloggerFor6.ExcludeAssembly(“MyAssemly”);


Как это все работает



Механизм внедрения в EF 4-й версии сильно отличается от EF 6-й версии.

Штатные механизмов подмены DbProviderFactory в EF 4 отсутствуют, поэтому приходится идти на подмену штатной фабрики на свою через рефлекцию.

Сам процесс выглядит так:

// проверяем что все фабрики загруженны
DbProviderFactories.GetFactoryClasses();

// получаем тип DbProviderFactories
Type type = typeof(DbProviderFactories);

DataTable table = null;
//получаем значение DataSet статического поля _configTable или _providerTable
object setOrTable = (type.GetField("_configTable", BindingFlags.NonPublic | BindingFlags.Static) ??
type.GetField("_providerTable", BindingFlags.NonPublic | BindingFlags.Static)).GetValue(null);

var set = setOrTable as DataSet;
if (set != null)
table = set.Tables["DbProviderFactories"];

table = (DataTable)setOrTable;

// для каждой записи в DataTable подставляем свою фабрику
foreach (DataRow row in table.Rows.Cast<DataRow>().ToList())
{
DbProviderFactory factory;
try
{
factory = DbProviderFactories.GetFactory(row);
}
catch (Exception)
{
continue;
}

var profType = EFProviderUtilities.ResolveFactoryType(factory.GetType());
if (profType != null)
{
DataRow profiled = table.NewRow();
profiled["Name"] = row["Name"];
profiled["Description"] = row["Description"];
profiled["InvariantName"] = row["InvariantName"];
profiled["AssemblyQualifiedName"] = profType.AssemblyQualifiedName;
table.Rows.Remove(row);
table.Rows.Add(profiled);
}
}




Для интеграции в EF 6-й версии можно воспользоваться штатным механизмом подстановки сервисов:

DbConfiguration.Loaded += (_, a) => a.ReplaceService<DbProviderServices>((s, k) => new EFProfiledDbProviderServices());


Декомпиляция



EFlogger на лету декомпелирует код и отображает тело метода, который сгенерировал тот или иной запрос. Для этого используются библиотеки из бесплатного аналога рефлектора ILSpy. Чтобы декомпировать метод нужно его сначала найти поднявшись по Stack Trace и исключить лишние вызовы сторонних библиотек:

public static string Get(out StackFrame outStackFrame)
{
outStackFrame = null;
var frames = new StackTrace(0, true).GetFrames();
if (frames == null)
{
return "";
}

var methods = new List<string>();

// проходим по всем фреймам
foreach (StackFrame t in frames)
{
// получаем метод
var method = t.GetMethod();

// получаем сборку и проверяем нужно ли ее пропустить
var assembly = method.Module.Assembly.GetName().Name;
if (ShouldExcludeType(method) || AssembliesToExclude.Contains(assembly) ||
MethodsToExclude.Contains(method.Name))
continue;

// находим первый по стеку фрейм и считаем что именно он сгенерировал команду, если нет нужно добавить имя сборки в список на пропуск
if (outStackFrame == null)
{
outStackFrame = t;
}
methods.Add(method.DeclaringType.FullName + ":" + method.Name);
}
return string.Join("\r\n", methods);
}



private static string GetMethodBody(StackFrame stackFrame)
{
MethodBase methodBase = stackFrame.GetMethod();
return Decompiler.GetSourceCode(methodBase.Module.FullyQualifiedName, methodBase.DeclaringType.Name, methodBase.Name);
}




Decompiler


using System;
using System.IO;
using System.Linq;
using ICSharpCode.Decompiler;
using ICSharpCode.Decompiler.Ast;
using ICSharpCode.Decompiler.Ast.Transforms;
using Mono.Cecil;

namespace Common
{
public static class Decompiler
{
public static string GetSourceCode(string pathToAssembly, string className, string methodName)
{
try
{
var assemblyDefinition = AssemblyDefinition.ReadAssembly(pathToAssembly);

TypeDefinition assembleDefenition = assemblyDefinition.MainModule.Types.First(type => type.Name == className);
MethodDefinition methodDefinition = assembleDefenition.Methods.First(method => method.Name == methodName);
var output = new StringWriter();
var plainTextOutput = new PlainTextOutput(output);
DecompileMethod(methodDefinition, plainTextOutput);
return output.ToString();
}
catch (Exception exception)
{

return string.Format( "Exception in decompling. \r\n Message:{0}, \r\n Inner Exception:{1}, \r\n StackTrace:{2}",exception.Message, exception.InnerException, exception.StackTrace);
}
}

private static void DecompileMethod(MethodDefinition method, ITextOutput output)
{
AstBuilder codeDomBuilder = CreateAstBuilder(currentType: method.DeclaringType, isSingleMember: true);
if (method.IsConstructor && !method.IsStatic && !method.DeclaringType.IsValueType)
{
AddFieldsAndCtors(codeDomBuilder, method.DeclaringType, method.IsStatic);
RunTransformsAndGenerateCode(codeDomBuilder, output);
}
else
{
codeDomBuilder.AddMethod(method);
RunTransformsAndGenerateCode(codeDomBuilder, output);
}
}

private static AstBuilder CreateAstBuilder(ModuleDefinition currentModule = null, TypeDefinition currentType = null, bool isSingleMember = false)
{
if (currentModule == null)
currentModule = currentType.Module;
var settings = new DecompilerSettings();
if (isSingleMember)
{
settings = settings.Clone();
settings.UsingDeclarations = false;
}
return new AstBuilder(
new DecompilerContext(currentModule)
{
CurrentType = currentType,
Settings = settings
});
}

private static void AddFieldsAndCtors(AstBuilder codeDomBuilder, TypeDefinition declaringType, bool isStatic)
{
foreach (var field in declaringType.Fields)
{
if (field.IsStatic == isStatic)
codeDomBuilder.AddField(field);
}
foreach (var ctor in declaringType.Methods)
{
if (ctor.IsConstructor && ctor.IsStatic == isStatic)
codeDomBuilder.AddMethod(ctor);
}
}

private static void RunTransformsAndGenerateCode(AstBuilder astBuilder, ITextOutput output, IAstTransform additionalTransform = null)
{
astBuilder.GenerateCode(output);
}
}
}





Пример рабочего проекта декомпиляции на яндекс файлах: http://ift.tt/1n99UwN
Окно обработки исключительной ситуации



Никому не секрет, что приложения периодически падают, это может произойти по самым разным причинам и задача разработчика показать какое-то вменяемое окно для сообщения об ошибке.

Мой вариант формы выглядит так:


Форма предлагает пользователю добавить информацию об ошибке, шаги для воспроизведения и свой email для ответа.

При нажатии на кнопку Отправить, на почту разработчику приходить письмо со всем данными.



[STAThread]
[STAThread]
static void Main()
{
SetupLogger();
// если дебагер не подключен
if (!Debugger.IsAttached)
{
// отлавливаем все необработанные ошибки
Application.ThreadException += (sender, e) => HandleError(e.Exception);
AppDomain.CurrentDomain.UnhandledException += (sender, e) => HandleError((Exception)e.ExceptionObject);
}

Application.EnableVisualStyles();
Application.SetCompatibleTextRenderingDefault(false);
Application.Run(new MainForm());
}
private static void HandleError(Exception exception)
{
try
{
// запускаем контроллер формы обернутый try/catch на случай если в контроллере тоже произойдет ошибка
new ErrorHandlerController(exception).Run();
}
catch (Exception e)
{
MessageBox.Show("Error processing exception. Please send log file EFlogger.log to developer: " + Settings.Default.ProgrammerEmail + " \r\n Exception:" + e);
// записываем ошибку в лог файл
Logger.Error(e);
if (MessageBox.Show("Attach debugger? \n Only for developer!!!", "Debugging...", MessageBoxButtons.YesNo, MessageBoxIcon.Question) == DialogResult.Yes)
{
Debugger.Launch();
throw;
}
}
finally
{
// обязательно принудительно завершаем приложение чтобы Windows не отображала стандартное окно ошибки приложения
Environment.Exit(1);
}
}

//new ErrorHandlerController(exception).Run();
public void Run()
{

// формируем текст ошибки
string exceptionInfoText = string.Format(
"An unexpected error occurred: {0}" + Environment.NewLine +
"Time: {1} " + Environment.NewLine +
"{2}" + Environment.NewLine +
"InnerException: \n {3}" + Environment.NewLine +
"InnerException StackTrace: \n {4}" + Environment.NewLine,
_exception.Message,
DateTime.Now,
_exception,
_exception.InnerException,
_exception.InnerException != null
? _exception.InnerException.StackTrace
: string.Empty
);

// записываем ошибку с лог файл
Program.Logger.Error(exceptionInfoText);
_view.ExceptionInfoText = exceptionInfoText;

// показываем форму, вызвав метод ShowDialog, в противном случае покажется стандартное окно ошибки приложения
_view.ShowDialog();
}




Пример рабочего проекта с формой обработки ошибок можете забрать на яндекс файлах: http://ift.tt/1n99UwP
Послесловие



На случай если сайт упадет, вы можете сказать архив профайлера опять же, на яндекс файлах: http://ift.tt/1kGckzv

Уверен, багов еще много, но я постараюсь все ошибки исправлять максимально быстро. Так же, я хочу спросить совета у уважаемого хабра сообщества как поступить с этим профайлером, так с одной стороны хочется сделать бесплатный продукт, но в то же время и немного заработать. В настоящее время я думаю о том чтобы сделать профайлер полностью бесплатным для личного использования и платным для компаний, но опять же по минимальной цене баксов в 20-30. Ну или просто оставить бесплатным с кнопочной Donate.

Всем спасибо за внимание. Надеюсь этот инструмент будет полезен.


PS: По всем вопросам, баг репортам и прочее можете писать на почту: developer@ef-logger.com или st.glushak@gmail.com. Также, автор ищет подработку, ибо ипотека. Спасибо за понимание.


This entry passed through the Full-Text RSS service — if this is your content and you're reading it on someone else's site, please read the FAQ at http://ift.tt/jcXqJW.


Комментариев нет:

Отправить комментарий