Я пытаюсь повысить производительность относительно сложного запроса структуры сущностей. Используя действие DbContext.Database.Log
, я проверил вывод при выполнении моего основного интересующего запроса и заметил кое-что странное. Согласно журналу, сам запрос занимает всего ~ 10 000 мс, однако между моментом "завершения" запроса и закрытием соединения проходит более минуты. Я понятия не имею, что происходит в это время, поскольку в журнале отображается пустая строка. Вот результат:
2018-09-07 14:10:34,641 [1] INFO EntityDataRepository [jobInstanceID: 0] - -- Executing at 9/7/2018 2:10:34 PM -07:00
2018-09-07 14:10:46,421 [1] INFO EntityDataRepository [jobInstanceID: 0] - -- Completed in 11776 ms with result: SqlDataReader
2018-09-07 14:10:46,458 [1] INFO EntityDataRepository [jobInstanceID: 0] -
2018-09-07 14:11:48,667 [1] INFO EntityDataRepository [jobInstanceID: 0] - Closed connection at 9/7/2018 2:11:48 PM -07:00
Не мог бы кто-нибудь рассказать мне, что здесь происходит? См. Ниже упрощенную / общую версию кода:
(from child in entities.SelectMany(e => e.children.Where(childFilter))
join read in childReads on child.ID equals read.childID
join readType in readTypes on read.readTypeID equals readType.ID
where readFilter
select new {child, read, readType}).ToList()
@PaulAbbott Я прочитал эту статью и не понимаю, как она применима здесь, не могли бы вы уточнить? Я вижу, что эта проблема возникает только при выполнении этого большого запроса, а не более коротких запросов ранее в приложении. Если вы предлагаете время, затраченное на возврат соединения с пулом, для меня не имеет смысла, почему это займет в 10 раз больше времени, чем выполнение самого запроса (тем более, что я использую проверку подлинности Windows, и это мой единственный подключение к БД прямо сейчас).
2018-09-07 14:10:46,421 1 INFO EntityDataRepository [jobInstanceID: 0] - -- Completed in 11776 ms with result: SqlDataReader
Это означает, что SqlCommand.ExecuteReader()
завершен, и сервер начинает возвращать строки клиенту. На данный момент запрос в SQL Sever - все еще выполняющий. Возможно, он поместил в очередь все результаты запроса или только что нашел и вернул первые несколько совпадающих строк с использованием плана потокового запроса. Итак, чтобы ваш IQueryable<T>.ToList()
завершился, запрос должен завершить выполнение на сервере, результирующие строки должны быть переданы клиенту, а EF должен прочитать строки и материализовать их в экземпляры класса типа T
.
Работа на стороне клиента может быть проанализирована с помощью Профилировщик Visual Studio, счетчиков производительности или System.Diagnostics.Process.
SQL Server отслеживает статистика выполнения запроса для запросов в кэше планов и для всех запросов при использовании Магазин запросов в SQL 2016+. Статистика покажет вам истекшее время запроса, которое включает время ожидания на клиенте для чтения (и обработки) строк и всех других ожиданий, а также «рабочее время», которое представляет собой процессорное время, используемое запросом. Хранилище запросов в SQL 2017 и База данных SQL Azure также отслеживает статистику ожидания для каждого запроса, поэтому вы можете различать ожидание на клиенте (ASYNC_NETWORK_IO
) и другие ожидания, такие как чтение файла данных (PAGEIOLATCH
), ожидание блокировки (LCK_*_*
) и т. д.