Добро пожаловать в форум, Guest  >>   Войти | Регистрация | Поиск | Правила | В избранное | Подписаться
Все форумы / Microsoft SQL Server Новый топик    Ответить
 Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
Доброго времени суток!
Запускаю следующий запрос
+

checkpoint 
dbcc dropcleanbuffers
go
DBCC FREEPROCCACHE
go
set statistics io on;

declare @stTime datetime =sysdatetime()
	set nocount on
	declare @reportid int  = 6464
		declare @undefined tinyint = 0,
			@fullAssign tinyint = 2,
			@calculated tinyint = 2,
			@Top         tinyint = 1
			

	SELECT @reportID, bloc.ID, bloc.Name, bloc.Code, bloc.StatusID,0, bloc.LocalID,
	case bloc.[Type]
		when 1 then 'DAA376FB-151F-4EE0-A9ED-896EC7318CE6'
		when 2 then '5A2B421B-703F-499E-8C40-C79978593D30'
		when 3 then '28F4D25C-AE5B-4716-9AE7-7E46BF34F875'
		when 4 then '4788E770-ED67-441E-8E0B-384FD93AF565'
		when 5 then '51271579-0237-4227-A086-855344087675'
		when 6 then 'A654406D-5D43-4358-B0DD-7D09D9B4399E'
		when 7 then 'E4BFD38E-DB30-4BBD-9C33-B1C0ECDA88A5'
		when 8 then 'D2C80A24-05CF-4FA1-A508-2C503CCCDCA6'
		when 9 then 'C2AE8E0A-3196-4E60-B0FA-8D6D2A5ECF6E'
		when 10 then '432EE292-B535-4D5C-891A-8521335791B2'
		--when 11 then null -- ТрОб'а нет
		when 12 then 'DFA48023-17E4-4A57-B2E8-934DAA55E392'
		else null
	end as Smr,
	bloc.OnePrice,pos.id, 
	round(isnull(lpc_FA_C_Top.MR,0), 2) * pos.KAmount  MR,
	isnull(lpc_FA_C_Top.TZO + lpc_FA_C_Top.TZM, 0) * pos.KAmount TZ,
	isnull(lpc_FA_C_Top.FOT,0) * pos.KAmount FOT,
	isnull(lpc_FA_C_Top.EMch,0)* pos.KAmount EMCH,
	round(isnull(lpc_FA_C_Top.NR,        0), 2) * pos.KAmount NR,
	round(isnull(lpc_FA_C_Top.SP,        0), 2) * pos.KAmount SP,
    pos.Chapter,
    bloc.Number,
    pos.LNum,
    pos.OriginalID,
    bloc.OriginalOrder
	FROM [slices].[ReportLPosIDs] rlp
	JOIN [slices].[Positions] pos ON pos.ID = rlp.LPosID	
	join [slices].[BudgetLocal]  bloc ON bloc.LBudgetID = pos.LBudgetID			
	JOIN 
        slices.LBudgetPositionCosts lpc_FA_C_Top on lpc_FA_C_Top.PositionId = bloc.ID
        and lpc_FA_C_Top.AssignmentType = @fullAssign and lpc_FA_C_Top.SourceType = @calculated and lpc_FA_C_Top.LevelType = @Top			
	WHERE 
		rlp.reportID = @REPORTID
		AND	pos.StatusID & 3 = 0	
		AND (pos.StatusID & 2048 = 0 OR (pos.StatusID & 2048 > 0 AND pos.BUsageCounter = 0))
	--option(recompile)
	option(maxdop 1)
	print '3:' +  cast(datediff(millisecond, @stTime, sysdatetime()) AS nvarchar(100))

	
set statistics io off;


Время выполнения 18с
План1 (в приложении). Статистика 1:
Таблица "LBudgetPositionCosts". Число просмотров 43997, логических чтений 1741769, физических чтений 6483, упреждающих чтений 5642, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "BudgetLocal". Число просмотров 2278, логических чтений 271946, физических чтений 615, упреждающих чтений 9366, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "Positions". Число просмотров 0, логических чтений 35060, физических чтений 41, упреждающих чтений 982, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "ReportLPosIDs". Число просмотров 1, логических чтений 22, физических чтений 3, упреждающих чтений 19, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
3:17487



Запускаю его же, но с включенным option(recompile) вместо option(maxdop 1)
Время выполнения 43с
План 2. Статистика 2:
Таблица "LBudgetPositionCosts". Число просмотров 43997, логических чтений 1702468, физических чтений 4571, упреждающих чтений 7557, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "BudgetLocal". Число просмотров 2278, логических чтений 233179, физических чтений 2282, упреждающих чтений 8508, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "Positions". Число просмотров 0, логических чтений 26817, физических чтений 1023, упреждающих чтений 0, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "ReportLPosIDs". Число просмотров 1, логических чтений 22, физических чтений 5, упреждающих чтений 17, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
3:42804


К сообщению приложен файл (план1.sqlplan - 109Kb) cкачать
27 июл 15, 09:24    [17937560]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
2-ой план

К сообщению приложен файл (план2.sqlplan - 108Kb) cкачать
27 июл 15, 09:25    [17937563]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
Microsoft SQL Server 2008 R2 (SP1) - 10.50.2550.0 (X64) 
	Jun 11 2012 16:41:53 
	Copyright (c) Microsoft Corporation
	Standard Edition (64-bit) on Windows NT 6.2 <X64> (Build 9200: )

Почему это происходит?
27 июл 15, 09:27    [17937574]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Glory
Member

Откуда:
Сообщений: 104751
Шамиль Фаридович
Почему это происходит?

Потому что NestedLoops - это циклы. В плане они выглядит одинаково, а количество итераций может быть разное
27 июл 15, 09:35    [17937601]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
Glory,
за счет чего, не могли бы вы объяснить подробнее, или кинуть ссылку.
27 июл 15, 10:06    [17937724]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Glory
Member

Откуда:
Сообщений: 104751
Шамиль Фаридович
Glory,
за счет чего, не могли бы вы объяснить подробнее, или кинуть ссылку.

В смысле ?
NestedLoops - это цикл. Где для каждой записи одной набора выполняются действия над другим набором
Что для 1ой записи, что для 1 000 000 записей NestedLoops выглядит одинаково.
Но понятно, что разница во времени выполнеия будет существенной
Для этого достаточно в реальном плане посмотерть на столбец, где приведена цифра реального чила выполнений NestedLoops-а
27 июл 15, 10:14    [17937751]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
Glory,
в том то и дело, что и дело, что количество выполнений в обоих планах совпадает(в приложениях).
А вот статистики чтений почему-то отличается, и время выполнения тоже.
27 июл 15, 10:19    [17937777]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Glory
Member

Откуда:
Сообщений: 104751
Шамиль Фаридович
в том то и дело, что и дело, что количество выполнений в обоих планах совпадает(в приложениях).

Вам показалось
27 июл 15, 10:21    [17937790]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
Glory,
серьезно, и для какого цикла Number of Executions отличается?
27 июл 15, 10:35    [17937859]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Glory
Member

Откуда:
Сообщений: 104751
Шамиль Фаридович
Glory,
серьезно, и для какого цикла Number of Executions отличается?

Вы не различаете стрелочки разной толщины ?
27 июл 15, 10:40    [17937880]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
Glory,
конечно различаю, но в подсказках к ним говорится об оценочном количестве выполнений, а вы говорили про реальное.
Так вот, первый, более оптимальный план, после цикла по BudgetLocal ожидает получить 63500 строк, а второй лишь 37.
Но следующий цикл по LBudgetPositionCosts выполняется 43997 раз в обоих планах, несмотря на оценку.
Так в чем же разница? В том что Executor действует не по плану?
27 июл 15, 10:51    [17937939]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
SomewhereSomehow
Member

Откуда: Moscow
Сообщений: 2480
Блог
Шамиль Фаридович,

Добрый день.
Планы не совсем одинаковые, хоть и похожи по форме.

В случае, когда используются переменные, оптимиазтор не может использовать статистику, делает догадки и оказывается ближе к истине. В другом случае, когда есть option(recompile) вместо переменные оптимизатор подставляет константы, использует статистику и благодаря тому что либо она устаревшая, либо искаженная, либо значения точные, но из-за перемножения селективностей комплексных предикатов получается очень маленькое значение и в итоге оценка идет в одну строку.

Разная оценка приводит к разным физическим реализациям Nested Loops там где строк больше используется дополнительная оптимизация Prefetching.
Картинка с другого сайта.
То же используется в последующем соединении.
В случае, если предполагалось мало строк - такого нет.
Поскольку вы очищаете буфферы перед тестом, это, видимо, дает такую разницу.

Попробуйте в тесте, в быстром варианте, который с переменными, добавить недокументированный флаг в option(querytraceon 8744) и повторить тест - должно стать также медленно как в случае с option(recompile). Если так, то дело точно в этом.
27 июл 15, 10:54    [17937955]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
SomewhereSomehow,
с подсказкой option(maxdop 1, querytraceon 8744) время выполнения действительно немного выросло, до 21с.
Статистика 3:
Таблица "LBudgetPositionCosts". Число просмотров 43997, логических чтений 1585508, физических чтений 12125, упреждающих чтений 0, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "BudgetLocal". Число просмотров 2278, логических чтений 188599, физических чтений 9275, упреждающих чтений 1525, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "Positions". Число просмотров 0, логических чтений 26817, физических чтений 1023, упреждающих чтений 0, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "ReportLPosIDs". Число просмотров 1, логических чтений 22, физических чтений 3, упреждающих чтений 19, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
3:20581

Теперь на всех Nested Loops нет свойства WithUnorderedPrefetch = true, но запрос выполняется все равно гораздо быстрее, чем в варианте 2 (с recompile)
Попробую обновить статистику.

К сообщению приложен файл (план3.sqlplan - 109Kb) cкачать
27 июл 15, 11:24    [17938126]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
Обновил статистику, в итоге получилась переоценка возвращаемого количества строк и оптимизатор решил использовать hash match
в последнем джойне, время выполнения взлетело до 7.5 минут.
Буду накатывать сервис-паки, может они что-то дадут...
На чем остановится, оставить option(maxdop 1)?
А где гарантия, что в случае реальной надобности hash join'а (при больших входных данных) оптимизатор выберет его вместо Nested Loops?

К сообщению приложен файл (план4.sqlplan - 97Kb) cкачать
27 июл 15, 14:14    [17939391]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
SomewhereSomehow
Member

Откуда: Moscow
Сообщений: 2480
Блог
Шамиль Фаридович,

Т.е. без Prefetch время изменилось, но не в два раза. В любом случае, в приведенных первых двух планах – это самое существенное отличие, после оценок. Кроме того, перед тестом сбрасывается кэш данных, что делает Prefetch весьма существенным элементом выполнения. При условии, что ситуация повторяемая (тест делался несколько раз), условия одинаковые (т.е. если по условию теста сбрасываем кэш, то делаем это всегда, перед каждым запросом и не забываем) – то было бы интересно понять в чем дело. Для этого нужно копать глубже и начать можно с ожиданий. Собрать их, например, при помощи xEvents (вроде бы бесплатная версия Plan Explorer это умеет делать неявно, если запускать запрос из него).

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

Будете накатывать сервис паки, смотрите по ситуации, вполне может быть, что дело в каком-то баге, который поправили. Относительно оптимизатора, многие исправления по умолчанию не активны, а включаются отдельно документированным флагом 4199 https://support.microsoft.com/en-us/kb/974006. Так что если после обновления ничего не изменится, попробуйте прогнать тест еще раз, но с включенным флагом.

Касательно вопросов по новому плану, переоценка есть, хотя и не очень большая, по меркам сиквела, но в данном случае ему хватает, чтобы выбрать сканирование кластерного, вместо поиска + лукапа по некластерному. Сканируемая таблица довольно большая, ну и плюс сам тип соединения выбран такой, который требует память, на ожидание которой тоже может уйти время. Если вы убедились, что обновили статистику по всем таблицам в запросе (не только по индексам) и сделали это с полным сканированием – но это не помогло, то значит вы уперлись в ограничение модели. Можно попробовать вернуть план близко к первоначальному явно указав индекс, либо подсказкой forceseek на большой таблице LBudgetPositionCosts.

Но лучше всего вообще исключить вилку: «кластерный» или «поиск + лукап» - создав покрывающий индекс на большой таблице (это, впрочем, не всегда возможно). У вас уже есть индекс IX_PositionID (PositionID), добавьте в в него ключи ...,AssignmentType, SourceType, LevelType и плюс в INCLUDE поля, которые достаете из этой таблицы. Если это вам не подходит в виду физического дизайна, то можно подумать о том, чтобы собрать все данные запроса сначала в промежуточную временную таблицу (материализовать промежуточный результат, 43 тысячи записей не так и много, судя по плану) и потом соединить ее с LBudgetPositionCosts.

По поводу разного количества получаемых данных в зависимости от значений переменных, если у вас без option recompile, то план будет всегда один и тот же, закеширован для неизвестных значений. Если есть option recompile, то будут рекомпиляции и план может меняться, но если на таблице LBudgetPositionCosts будет покрывающий индекс и условия поиска не будут добавляться исключаться (а будут меняться только значения), то практически гарантированно, что вы будете каждый раз получать поиск по индексу и доступ к данным этой таблицы будет осуществляться быстро. В случае с временной таблицей и промежуточной материализацией - конечно, ее размер будет зависеть от кол-во полученных строк и значений параметров. В таком случае, может быть выделить какие-то крайние случаи в отдельные ветки кода.

Насчет maxdop 1 - это вы параллелизм ограничили. Зачем? С параллелизмом все еще хуже?

В любом случае, простор для маневра и экспериментов есть.
27 июл 15, 16:46    [17940596]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
SomewhereSomehow
Но, сейчас, насколько я понял, исследовать уже поздно, т.к. после обновления статистики план поменялся, и старый план без манипуляций теперь не получишь.

После наката сп3 и создания нового документа, для которого по факту нет актуальной статистики, ситуация воспроизводится для всех 3 тестов, правда с небольшими изменениями: 21, 44 и 28с.
Включение querytraceon 4199 ничего не меняет.
SomewhereSomehow
создав покрывающий индекс на большой таблице

В виду разнообразия запросов к LBudgetPositionCosts в покрывающий индекс пришлось бы включить все поля, то есть по факту
хранить в индексе всю эту немалую таблицу. Отсюда напрашивается, что давно пора сделать индекс по PositionId кластерным.
Что даст добавление в ключ индекса полей AssignmentType, SourceType, LevelType (3 поля дают в совокупности могут давать 12 разных значений, но факту используются только 8)?
Ключ станет уникальным, но длина ключа увеличится минимум на 3 байта с 8 нынешних. Сильно ли такой seek predicate лучше
чем seek predicate + predicate, учитывая что в 3 поля дают только 8 разных значений?
SomewhereSomehow
Насчет maxdop 1 - это вы параллелизм ограничили. Зачем? С параллелизмом все еще хуже?

Да с параллелизм работает медленнее.
28 июл 15, 12:14    [17944480]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
SomewhereSomehow
Member

Откуда: Moscow
Сообщений: 2480
Блог
Шамиль Фаридович,

Вопрос разделился на два.

1. Вопрос чисто из академического интереса, почему второй запрос с рекомпиляцией существенно медленнее первого, даже если в первом убрать Prefetch.

2. Вопрос практический, как уменьшить время выполнения запроса в целом.

По первому вопросу
Можете выполнить 4 теста по новой статистике (чтобы воспроизводилась ситуация описанная в самом первом сообщении):
- без option
- option(recompile)
- option(querytraceon 8744)
- option(querytraceon 8744, recompile)
Но обрамить их следующим запросом, собирающим статистики, планы и ожидания (если будете добавлять еще maxdop 1, то добавляйте во все тесты), после этого выложить результаты сюда (или прислать мне на почту) в виде – данные set statistics, планы, ожидания (не забудьте в скрипте сбора ожиданий поменять SPID)
+
if exists(select * from sys.server_event_sessions where name='QueryWaitStats')
drop event session QueryWaitStats on server;
go
create event session QueryWaitStats on server
add event sqlos.wait_info (where duration > 1 and [sqlserver].[session_id]=52), -- @@SPID instead of 52
add event sqlos.wait_info_external (where duration > 1 and [sqlserver].[session_id]=52) -- @@SPID instead of 52
add target package0.ring_buffer
with (
	event_retention_mode = allow_single_event_loss, 
	max_dispatch_latency = 5 seconds
)
go
alter event session QueryWaitStats on server state = start;
go
set statistics io, time, xml on;
go
-- ваш тест здесь
go
set statistics io, time, xml on;
go
with RingBufferData as
(
    select 
		TargetData = cast(target_data as xml)
    from 
		sys.dm_xe_session_targets st 
		JOIN sys.dm_xe_sessions s ON s.address = st.event_session_address 
    where name = 'QueryWaitStats' AND target_name = 'ring_buffer'
),
Data as
(
    select 
		[EventData] = XEventData.XEvent.query('.') 
    from 
		RingBufferData rbd
		cross apply rbd.TargetData.nodes ('RingBufferTarget/event') AS XEventData (XEvent)
),
Waits as (
select 
    [Event] = [EventData].value('(event/@name)[1]', 'varchar(50)'),
    [Timestamp] = DATEADD(hh, DATEDIFF(hh, GETUTCDATE(), CURRENT_TIMESTAMP), [EventData].value('(event/@timestamp)[1]', 'datetime2')),
    [WaitType] = [EventData].value('(event/data[@name="wait_type"]/text)[1]', 'nvarchar(4000)'),
    [Dur] = [EventData].value('(event/data[@name="duration"]/value)[1]', 'bigint')
from 
	Data
)
select 
	[Event],
	[WaitType],
	[MinTimestamp] = min([Timestamp]),
	[MaxTimestamp] = max([Timestamp]),
	[Dur] = sum([Dur])
from
	Waits
group by
	[Event],
	[WaitType]
order by
	[Dur] desc
go
alter event session QueryWaitStats on server state = stop;
go

Интересно посмотреть, что происходит.

По второму вопросу
Если сделаете кластерный по PositionID – то этому запросу будет хорошо, но посмотрите, не пострадают ли другие части системы. Если к таблице много разнообразных запросов, выиграют только те, которые имеют предикат поиска по первой колонке индекса. Ну и стандартные (для большинства систем, хотя есть исключения) заботы по выбору кластерного индекса: узкий, уникальный, статичный, монотонно растущий – нужно взвесить и учесть. Вы лучше знаете свою систему и вам виднее, что можно делать, а что нет.

С точки зрения оптимизатора и исполнителя запросов – добавлений трех полей в ключ делает поиск по индексу более точечным, даже если это всего несколько значений. Как бонус, получаете многоколоночную статистику (Multi-Column Statistics). Возможно, оптимизатор сможет ее использовать, чтобы оценки стали точнее. Если ширина ключа индекса имеет принципиальное значение, то можете не включать другие поля в ключ. Самое главное покрывающий индекс.

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

Про параллелизм интересно, можете для примера еще параллельный план привести.

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

К сообщению приложен файл. Размер - 39Kb
28 июл 15, 14:17    [17945138]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
SomewhereSomehow,

спасибо за ссылку - отличная статья!
Судя по ней (PositionId, AssignmentType...) создают идеальный ключ для кластерного индекса: узкий, уникальный, статичный, монотонно растущий. Более того, учитывая, что повторяющиеся значения CIX добавляют в ключ 4 байта он оказывается даже уже, чем индекс по PositionId ("Typ'ы" имеют тип tinyint)
После создания составного CIX время выполнения распределилось след образом: 10(без подсказок), 42(recompile), 15с(querytraceon 8744)
Как заставить выполнять с параллельным планом придумать не могу, option(maxdop 0) не помогает.
По первому вопросу тесты пришлю чуть позже.
28 июл 15, 16:28    [17946143]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
SomewhereSomehow,
результаты тестов по вашему шаблону, с добавлением в начале
checkpoint 
dbcc dropcleanbuffers
go
DBCC FREEPROCCACHE
go


К сообщению приложен файл (Тесты.zip - 44Kb) cкачать
28 июл 15, 17:49    [17946598]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
AlanDenton
Member [скрыт]

Откуда:
Сообщений: 1004
автор
Как заставить выполнять с параллельным планом придумать не могу, option(maxdop 0) не помогает.


чтобы форсировать выбор параллельного плана воспользуйтесь вот этим флагом:

OPTION (RECOMPILE, QUERYTRACEON 8649)
29 июл 15, 09:32    [17948339]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
AlanDenton
автор
Как заставить выполнять с параллельным планом придумать не могу, option(maxdop 0) не помогает.


чтобы форсировать выбор параллельного плана воспользуйтесь вот этим флагом:

OPTION (RECOMPILE, QUERYTRACEON 8649)


Спасибо:
До кучи статистика с такими подсказками:
Таблица "Worktable". Число просмотров 0, логических чтений 0, физических чтений 0, упреждающих чтений 0, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "LBudgetPositionCosts". Число просмотров 43997, логических чтений 302453, физических чтений 1953, упреждающих чтений 6608, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "BudgetLocal". Число просмотров 2278, логических чтений 228530, физических чтений 2499, упреждающих чтений 8292, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "ReportLPosIDs". Число просмотров 9, логических чтений 25, физических чтений 3, упреждающих чтений 19, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Таблица "Positions". Число просмотров 0, логических чтений 26817, физических чтений 1023, упреждающих чтений 0, lob логических чтений 0, lob физических чтений 0, lob упреждающих чтений 0.
Время выполнения:41023мс


которая не сильно отличается от
OPTION (RECOMPILE)


К сообщению приложен файл (Recompile 8649.sqlplan - 116Kb) cкачать
29 июл 15, 16:07    [17951029]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
SomewhereSomehow
Member

Откуда: Moscow
Сообщений: 2480
Блог
Шамиль Фаридович,

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

Я свел результаты ваших тестов в одну картинку:

• Clean – запрос с локальными переменными, в оценке используются догадки, оценка близка к реальной.
• Clean_querytraceon - запрос с локальными переменными, в оценке используются догадки, оценка близка к реальной, отключена оптимизация Nested Loops Prefetch
• Recompile – запрос где локальные переменные заменяются константами, используется устаревшая статистика и оценка 1 строка, таким образом Prefetching не используется в части случаев.
• Recompile_querytraceon– запрос где локальные переменные заменяются константами, используется устаревшая статистика и оценка 1 строка и Prefetching не используется вообще.
+ сводная картинка
Картинка с другого сайта.

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

Вот выдержка из BOL о PAGEIOLATCH_SH.
автор
Occurs when a task is waiting on a latch for a buffer that is in an I/O request. The latch request is in Shared mode. Long waits may indicate problems with the disk subsystem.

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

Для данного теста это ожидание нормально (мы же везде очищаем буферный кэш).

Для рабочей среды, это плохо, и как правило значит, что нужно добавить памяти. Хотя, это не всегда так, например, кто-то может вымывать страницы из кэша, например, большие сканирования не относящиеся к этому запросу. Можете почитать статью Пола Рэндала про это ожидание, Knee-Jerk Wait Statistics : PAGEIOLATCH_SH, там хорошо расписано. Для анализа боевой системы, можете также помониторить счетчик PLE. Как его интерпретировать есть в другой статье Рэндала - Knee-Jerk PerfMon Counters : Page Life Expectancy.

На данном этапе мы выяснили на что уходит в тесте основное время – на работу с диском (других ожиданий у вас согласно приведенным данным нет). Теперь собственно вопрос, почему SQL Server работает с диском по-разному (случаи 1 и 3), если оценка одна строка – сервер работает с диском гораздо дольше.

Разделим ответственности между компонентами.

QP (Query Processor) – отвечает за построение и выполнение плана, итерацию по строкам и т.д.

SE (Storage Engine) – отвечает за работу с дисками, буферным пулом и т.д. и является более низкоуровневым компонентом.

QP влияет на то, как SE будет получать данные, например, он может запросить Prefetch, как делает в этом случае. Но когда SE получил задание от QP он сам волен выбирать, как и какими блоками он будет читать данные с диска.

В данном случае, даже отключение Prefetch не приближает по времени выполнения к случаю, когда оценка одна строка. Таким образом, долгая работа с диском — это зона ответственности только SE. Тем не менее, разница по времени появляется, когда возникают другие оценки, а это уже зона ответственности QP.

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

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

У меня получились такие результаты (план не выкладываю, он по форме такой же, кроме того можно его получить запустив репро):
+ результаты
Картинка с другого сайта.

Я запускал много раз, почти всегда запрос с оценкой в одну строку колеблется от 30 до 60 секунд. Хотя несколько раз он выполнялся даже быстрее (около 20 секунд), чем запрос с нормальной оценкой. В 2014 сервере время выполнения меньше (хотя план такой же как в 2008R2) и разница в 2014 не такая сильная а порядка 5-6 секунд.

Чтобы посмотреть в чем дело я использовал событие Extended Event - file_read_completed. Я его использовал в 2014 версии (хотя тесты делал и на 2008R2 и на 2014).
+ Из монитора расширенных событий
Картинка с другого сайта.

+ Сводная
Картинка с другого сайта.

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

К сожалению, не нашел нигде в документации или публикация упоминания о том, учитывает ли SE при формировании запроса к диску информацию от QP о количестве предполагаемых к прочтению данных. Может быть это не документировано, может быть я плохо искал, но эксперимент показывает, что какая-то зависимость есть.

В реальности, такая ситуация все-таки встречается не так часто, обычно стараются делать так, чтобы сервер все-таки работал в основном с буферным пулом и данные всегда были в кэше. А если какие-то данные поднимаются с диска, то это как правило, не горячие данные и всем наплевать, сколько будет работать запрос, который выполняется раз в полгода. Если от работы с диском начинают страдать горячие данные, как правило добавляют память, ну либо смотрят, что так активно вытесняет данные из кэша. В любом случае, на мой взгляд, надо сильно постараться, чтобы описанное выше поведение стало проблемой в реальной системе.

Так что, мне кажется, если у вас это в действительности это проблема, то посмотрите в сторону общей оптимизации системы, в том числе и покупки дополнительной памяти, а такое разное время — это проблема не оптимизатора. Как вариант, можно совсем от Lookup избавиться, чтобы прям совсем хорошо было, но эффект будет гораздо меньше, чем если бы просто данные были в памяти, а не поднимались с диска каждый раз.

Наверное, это все чем могу помочь по данному вопросу, так что удачи!

К сообщению приложен файл (test.sql - 9Kb) cкачать
29 июл 15, 18:02    [17951656]     Ответить | Цитировать Сообщить модератору
 Re: Разное время выполнения при одинаковом плане  [new]
Шамиль Фаридович
Member

Откуда: Саратов
Сообщений: 487
SomewhereSomehow,
большое спасибо за проведенную работу(в том числе просветительскую) и объемлющие ответы.
Я остановлюсь на том, чтобы убрать подсказки, так как большая часть запросов выполняется примерно с одинаковым объемом данных.
30 июл 15, 11:59    [17954193]     Ответить | Цитировать Сообщить модератору
Все форумы / Microsoft SQL Server Ответить