Статьи

Entity Framework: перехват SQL-запросов для контекстной регистрации

Правильное ведение журнала имеет первостепенное значение и должно иметь место при любом серьезном применении. Написание журналов тривиально и уже успешно выполнено парой библиотек с открытым исходным кодом. Но это только первый шаг в успешной регистрации приложений. Гораздо более сложной задачей является наличие надлежащих метрик, которые надлежащим образом объединяют соответствующую информацию и предоставляют необходимую контекстную информацию для возможности воспроизведения проблем. Это единственный способ предотвратить затопление ненужными отходами.

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