Правильное ведение журнала имеет первостепенное значение и должно иметь место при любом серьезном применении. Написание журналов тривиально и уже успешно выполнено парой библиотек с открытым исходным кодом. Но это только первый шаг в успешной регистрации приложений. Гораздо более сложной задачей является наличие надлежащих метрик, которые надлежащим образом объединяют соответствующую информацию и предоставляют необходимую контекстную информацию для возможности воспроизведения проблем. Это единственный способ предотвратить затопление ненужными отходами.
Хотя я хотел бы немного углубиться в концепцию правильного ведения журнала и агрегирования информации, этот пост просто предназначен для доказательства конкретного случая, который у меня был, — правильного включения контекстной информации в записи журнала. В частности, у моего коллеги по работе недавно возникла странная проблема получения исключения «Недостаточные привилегии» в его производственной среде. Это появилось время от времени и не было действительно воспроизводимо. Будучи связанным с выполнением какого-либо запроса, в этом случае было бы очень полезно узнать, какой тип запроса был выполнен Entity Framework (в нашем случае) для базовой базы данных Oracle, что в итоге привело к упомянутому исключению.
Непосредственный подход, который мне пришёл в голову, заключается в том, чтобы каким-то образом зацепить профилировщик между Entity Framework и БД, отследить и запомнить все выполненные SQL-запросы, чтобы потом — позже — иметь возможность вынимать их в случае возникновения исключения. Это сделало бы особенно простым включение оператора SQL в сообщение журнала в качестве контекстной информации для подобных исключений.
МиниПрофилер в помощь
Я сделал быстрый поиск в Google по поводу перехвата операторов Entity Framework против БД, нашел некоторые вещи, но они казались довольно сложными в настройке, поскольку требовалось обернуть класс EntityContext и т. Д.
Это было, когда MiniProfiler пришла мне в голову. Мы используем его для живого профилирования нашего приложения во время его разработки (нужно написать в блоге о том, как я настроил это для одностраничных приложений JS). Приятной особенностью MiniProfiler является то, что он также отслеживает запросы SQL, их время выполнения, есть ли у вас повторяющиеся запросы, и даже показывает отформатированный оператор SQL . Это было именно то, что мне было нужно, поэтому я начал смотреть на источник MiniProfiler, чтобы понять, где я могу подключиться.
Установка и регистрация MiniProfiler
Установка MniProfiler довольно проста. Просто зайдите в NuGet и установите нужные вам пакеты .
Не забудьте правильно инициализировать его для отслеживания запросов Entity Framework (если это то, что вы используете)
MiniProfiler.Settings.SqlFormatter =
new StackExchange.Profiling.SqlFormatters.InlineFormatter();
MiniProfilerEF.Initialize();
и затем вызвать MiniProfiler.Start()и MiniProfiler.Stop()в событиях начала и конца запроса соответственно. Обратите внимание, что такие настройки уже должны быть включены в пакет MVC3 NuGet и должны быть настроены.
Опрос логов MiniProfiler
MiniProfiler имеет очень продуманную конструкцию. Все начинается с вызоваMiniProfiler.Current
var profiling = MiniProfiler.Current;
if(profiling != null)
{
}
который возвращает текущий запущенный профилировщик (или ноль, если его нет) для текущего HttpContext. Что меня особенно заинтересовало, так это понять, какие из профилирований действительно содержат связанные с SQL вещи. Это можно получить с помощью соответствующего HasSqlTimingsсвойства
var profiling = MiniProfiler.Current;
if(profiling != null && profiling.HasSqlTimings)
{
}
Затем, вызывая соответствующий GetSqlTimings() метод, возвращает список SqlTimingобъектов, содержащих — помимо другой информации, относящейся к синхронизации, — все «тайминги», связанные с выполнением оператора SQL.
var profiling = MiniProfiler.Current;
if(profiling != null && profiling.HasSqlTimings)
{
var timings = profiling.GetSqlTimings();
}
Наконец, FormattedCommandStringвозвращает отформатированную версию выполненного оператора SQL, которую вы должны иметь возможность непосредственно выполнять в вашей БД.
Итак, я заканчиваю тем, что получил очень простой кусок кода, который выглядел примерно так:
private string CollectExecutedQueries()
{
var stringbuilder = new StringBuilder();
var profiling = MiniProfiler.Current;
if (profiling != null && profiling.HasSqlTimings)
{
var timings = profiling.GetSqlTimings();
foreach (var timing in timings)
{
stringbuilder.AppendLine(Environment.NewLine + "----START QUERY----");
stringbuilder.AppendLine(timing.FormattedCommandString);
stringbuilder.AppendLine("----END QUERY----");
}
}
if (stringbuilder.Length > 0)
{
return Environment.NewLine + Environment.NewLine + "EXECUTED QUERIES: " + Environment.NewLine + stringbuilder.ToString();
}
else return "";
}
Пожалуйста, не принимайте этот код как есть . Я просто собираюсь пересмотреть это и опубликовать его в производстве. Это покажет, действительно ли это было так просто или нужно улучшить. Но первые тесты многообещающие и, похоже, работают правильно.
Вывод
Что впечатляет, так это простота, с которой MiniProfiler позволяет вам перехватывать команды SQL, отправленные в БД, и невероятное понимание, которое вы получаете. Считывание выполненной команды SQL на самом деле является очень простым случаем использования того, что предлагает MiniProfiler. Я мог бы представить сценарии отправки автоматических журналов предупреждений при наличии дублированных или медленных запросов в вашей производственной среде.