Диагностика производительности

Статья
09/12/2023

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

Определение медленных команд базы данных с помощью ведения журнала

В конце дня EF подготавливает и выполняет команды, которые будут выполняться в базе данных; с реляционной базой данных это означает выполнение инструкций SQL с помощью API базы данных ADO.NET. Если определенный запрос занимает слишком много времени (например, из-за отсутствия индекса), это можно увидеть, проверяя журналы выполнения команд и наблюдая, сколько времени они на самом деле занимает.

EF упрощает запись времени выполнения команд с помощью простого ведения журнала или Microsoft.Extensions.Logging:

Простое ведение журнала
Microsoft.Extensions.Logging

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
{
    optionsBuilder
        .UseSqlServer(@"Server=(localdb)\mssqllocaldb;Database=Blogging;Trusted_Connection=True")
        .LogTo(Console.WriteLine, LogLevel.Information);
}

private static ILoggerFactory ContextLoggerFactory
    => LoggerFactory.Create(b => b.AddConsole().AddFilter("", LogLevel.Information));

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
{
    optionsBuilder
        .UseSqlServer(@"Server=(localdb)\mssqllocaldb;Database=Blogging;Trusted_Connection=True")
        .UseLoggerFactory(ContextLoggerFactory);
}

Если уровень ведения журнала установлен LogLevel.Informationна уровне, EF выдает сообщение журнала для каждого выполнения команды с течением времени:

info: 06/12/2020 09:12:36.117 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command)
      Executed DbCommand (4ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT [b].[Id], [b].[Name]
      FROM [Blogs] AS [b]
      WHERE [b].[Name] = N'foo'

Указанная выше команда заняла 4 миллисекунда. Если определенная команда занимает больше, чем ожидалось, вы нашли возможный преступник для проблемы с производительностью и теперь можете сосредоточиться на ней, чтобы понять, почему она работает медленно. Ведение журнала команд также может выявить случаи, когда выполняются непредвиденные циклы баз данных; Это будет отображаться в виде нескольких команд, где ожидается только один.

Предупреждение

Ведение журнала выполнения команд в рабочей среде обычно является плохой идеей. Само ведение журнала замедляет работу приложения и может быстро создавать огромные файлы журналов, которые могут заполнить диск сервера. Рекомендуется хранить ведение журнала только в течение короткого промежутка времени для сбора данных - при тщательном мониторинге приложения - или для записи данных ведения журнала в предварительной системе.

Сопоставление команд базы данных с запросами LINQ

Одна из проблем с ведением журнала выполнения команд заключается в том, что иногда трудно сопоставить запросы SQL и запросы LINQ: команды SQL, выполняемые EF, могут выглядеть очень иначе от запросов LINQ, из которых они были созданы. Чтобы помочь с этой проблемой, может потребоваться использовать функцию тегов запросов EF, которая позволяет внедрить небольшой комментарий в SQL-запрос:

var myLocation = new Point(1, 2);
var nearestPeople = (from f in context.People.TagWith("This is my spatial query!")
                     orderby f.Location.Distance(myLocation) descending
                     select f).Take(5).ToList();

Тег отображается в журналах:

-- This is my spatial query!

SELECT TOP(@__p_1) [p].[Id], [p].[Location]
FROM [People] AS [p]
ORDER BY [p].[Location].STDistance(@__myLocation_0) DESC

Часто стоит пометить основные запросы приложения таким образом, чтобы журналы выполнения команд были более удобочитаемыми.

Другие интерфейсы для записи данных о производительности

Существуют различные варианты функции ведения журнала EF для записи времени выполнения команд, которые могут быть более мощными. Базы данных обычно используют собственные средства трассировки и анализа производительности, которые обычно предоставляют гораздо более широкие сведения о конкретной базе данных за пределами простого времени выполнения; Фактические настройки, возможности и использование значительно различаются в разных базах данных.

Например, SQL Server Management Studio — это мощный клиент, который может подключаться к экземпляру SQL Server и предоставлять ценные сведения об управлении и производительности. Это выходит за рамки область этого раздела, чтобы перейти к деталям, но две возможности, которые стоит упоминание это монитор действий, который предоставляет динамическую панель мониторинга действий сервера (включая самые дорогие запросы), а также функцию расширенных событий (XEvent), которая позволяет определить произвольные сеансы отслеживания данных, которые можно настроить в соответствии с вашими потребностями. Документация по SQL Server по мониторингу содержит дополнительные сведения об этих функциях, а также о других функциях.

Другой подход к сбору данных о производительности заключается в том, чтобы автоматически собирать сведения, создаваемые EF или драйвером базы данных через DiagnosticSource интерфейс, а затем анализировать эти данные или отображать их на панели мониторинга. Если вы используете Azure, то приложение Azure Аналитика обеспечивает такой мощный мониторинг вне поля, интегрируя производительность базы данных и время выполнения запросов в анализе того, как быстро выполняются веб-запросы. Дополнительные сведения об этом доступны в руководстве по производительности приложений Аналитика и на странице аналитики SQL Azure.

Проверка планов выполнения запросов

После указания проблемного запроса, требующего оптимизации, следующий шаг обычно анализирует план выполнения запроса. Когда базы данных получают инструкцию SQL, обычно они создают план выполнения этого плана; Иногда требуется сложное принятие решений на основе определенных индексов, объем данных, существующих в таблицах и т. д. (кстати, сам план обычно должен кэшироваться на сервере для оптимальной производительности). Реляционные базы данных обычно предоставляют пользователям способ просмотра плана запроса, а также вычисляемой стоимости для различных частей запроса; это бесценно для улучшения запросов.

Сведения о начале работы с SQL Server см. в документации по планам выполнения запросов. Типичный рабочий процесс анализа — использовать SQL Server Management Studio, вставляя SQL медленного запроса, определяемого одним из указанных выше средств, и создавая графический план выполнения:

Display a SQL Server execution plan

Хотя планы выполнения могут показаться сложными вначале, стоит потратить немного времени на знакомство с ними. Особенно важно отметить затраты, связанные с каждым узлом плана, и определить, как индексы используются (или нет) в различных узлах.

Хотя приведенные выше сведения относятся к SQL Server, другие базы данных обычно предоставляют те же средства с аналогичной визуализацией.

Важно!

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

Счетчики событий

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

Дополнительные сведения см. на выделенной странице счетчиков событий EF.

Тестирование с помощью EF Core

В конце дня иногда необходимо знать, является ли определенный способ написания или выполнения запроса быстрее, чем другой. Важно никогда не предполагать или спекулировать ответ, и это очень легко собрать быстрый тест, чтобы получить ответ. При написании тестов настоятельно рекомендуется использовать общеизвестную библиотеку BenchmarkDotNet , которая обрабатывает множество ошибок, с которыми сталкиваются пользователи при попытке написать собственные тесты: вы выполнили некоторые итерации прогрева? Сколько итераций на самом деле выполняет ваш тест, и почему? Давайте рассмотрим, как выглядит тест с EF Core.

Совет

Полный проект теста для источника ниже доступен здесь. Рекомендуется скопировать его и использовать его в качестве шаблона для собственных тестов.

В качестве простого сценария теста давайте сравним следующие различные методы вычисления среднего рейтинга всех блогов в нашей базе данных:

Загрузите все сущности, суммируете их отдельные рейтинги и вычисляет среднее значение.
Так же, как и выше, используйте только запрос без отслеживания. Это должно быть быстрее, так как разрешение удостоверений не выполняется, и сущности не моментальные снимки для целей отслеживания изменений.
Избегайте загрузки всех экземпляров сущностей блога, проецируя только ранжирование. Сохраняет нас от передачи других ненужных столбцов типа сущности Блога.
Вычислите среднее значение в базе данных, сделав его частью запроса. Это должен быть самый быстрый способ, так как все вычисляется в базе данных, и только результат передается клиенту.

При использовании BenchmarkDotNet код, который необходимо проверить как простой метод , как модульный тест, и BenchmarkDotNet автоматически запускает каждый метод для достаточного количества итераций, надежно измеряя, сколько времени занимает и сколько памяти выделено. Ниже приведены различные методы (полный код теста можно увидеть здесь):

[Benchmark]
public double LoadEntities()
{
    var sum = 0;
    var count = 0;
    using var ctx = new BloggingContext();
    foreach (var blog in ctx.Blogs)
    {
        sum += blog.Rating;
        count++;
    }

    return (double)sum / count;
}

[Benchmark]
public double LoadEntitiesNoTracking()
{
    var sum = 0;
    var count = 0;
    using var ctx = new BloggingContext();
    foreach (var blog in ctx.Blogs.AsNoTracking())
    {
        sum += blog.Rating;
        count++;
    }

    return (double)sum / count;
}

[Benchmark]
public double ProjectOnlyRanking()
{
    var sum = 0;
    var count = 0;
    using var ctx = new BloggingContext();
    foreach (var rating in ctx.Blogs.Select(b => b.Rating))
    {
        sum += rating;
        count++;
    }

    return (double)sum / count;
}

[Benchmark(Baseline = true)]
public double CalculateInDatabase()
{
    using var ctx = new BloggingContext();
    return ctx.Blogs.Average(b => b.Rating);
}

Ниже приведены результаты, как показано в BenchmarkDotNet:

Метод	Среднее значение	Ошибка	StdDev	Медиана	Коэффициент	Коэффициенты	0-го поколения	Поколение 1	Поколение 2	Распределено
LoadEntities	2,860,4 нас	54.31 мы	93.68 нас	2,844,5 нас	4,55	0,33	210.9375	70.3125	-	1309.56 КБ
LoadEntitiesNoTracking	1,353.0 мы	21.26 мы	18.85 нас	1,355.6 нас	2,10	0,14	87.8906	3.9063	-	540.09 КБ
ProjectOnlyRanking	910.9 мы	20.91 нас	61.65 нас	892.9 нас	1,46	0,14	41.0156	0.9766	-	252.08 КБ
CalculateInDatabase	627.1 нас	14.58 нас	42.54 нас	626.4 нас	1,00	0.00	4.8828	-	-	33.27 КБ

Примечание.

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

Одним из ограничений BenchmarkDotNet является то, что он измеряет простую, однопоточную производительность предоставляемых методов и поэтому не подходит для тестирования параллельных сценариев.