Правильное ведение журнала имеет первостепенное значение и должно иметь место при любом серьезном применении. Написание журналов тривиально и уже успешно выполнено парой библиотек с открытым исходным кодом. Но это только первый шаг в успешной регистрации приложений. Гораздо более сложной задачей является наличие надлежащих метрик, которые надлежащим образом объединяют соответствующую информацию и предоставляют необходимую контекстную информацию для возможности воспроизведения проблем. Это единственный способ предотвратить затопление ненужными отходами.
Хотя я хотел бы немного углубиться в концепцию правильного ведения журнала и агрегирования информации, этот пост просто предназначен для доказательства конкретного случая, который у меня был, — правильного включения контекстной информации в записи журнала. В частности, у моего коллеги по работе недавно возникла странная проблема получения исключения «Недостаточные привилегии» в его производственной среде. Это появилось время от времени и не было действительно воспроизводимо. Будучи связанным с выполнением какого-либо запроса, в этом случае было бы очень полезно узнать, какой тип запроса был выполнен 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. Я мог бы представить сценарии отправки автоматических журналов предупреждений при наличии дублированных или медленных запросов в вашей производственной среде.