Замер времени выполнения временных таблиц больших запросов

Итак, поскольку все разрабатываемые/поддерживаемые мною запросы я привык хранить в sel файлах, и обкатывать их в консоли, то я не стал заморачиваться с написанием новой обработки. Я просто добавил кнопку и её обработчик в консоль которой привык пользоваться. Поэтому в данной статье постараюсь описать именно суть моей доработки. А так же поделюсь модифицированной версией вполне стандартной консоли запросов.

Идея.

Однажды в очередной раз столкнувшись с тем, что в новой декаде отчет стал работать дольше чем обычно, я подумал что мне нужен инструмент, который бы мог замерить время выполнения каждого подзапроса (временной таблицы) моего большого запроса. Тогда бы я мог точно знать в чем проблема и как её можно решить. Я долго серфил по Интернету в поисках подобного инструмента. Но так ничего и не нашел. Тогда я стал думать как бы я мог это сделать сам.
Все сводилось к тому что мне надо было разбивать запрос на отдельные составляющие, и отдельно их выполнять засекая время выполнения.
Вариантов реализации в голове крутилось несколько. Но лишь путем проб и ошибок я пришел к тому который оказался реальным.

Разбивка запроса.

Для разбивки запроса на мелкие составляющие я использую такой не хитрый алгоритм:

Текст = ЭлементыФормы.ТекстЗапроса.ПолучитьТекст();
	
	МП = Новый Массив;   //Массив подзапросов
	МП.Очистить();
	
	Ш = 0;
	Пока Найти(Текст, ";") > 0 Цикл
		Текст = ОбрезатьНачалоТекста(Текст);
		ПодЗапрос = СокрЛП(Сред(Текст,Найти(Текст,"ВЫБРАТЬ"),Найти(Текст,";") - Найти(Текст,"ВЫБРАТЬ") + 1));
		Если НЕ СокрЛП(ПодЗапрос) = "" Тогда
			МП.Добавить(ПодЗапрос);
		КонецЕсли;
		
		Текст = Сред(Текст, СтрДлина(ПодЗапрос) + 1, СтрДлина(Текст) - СтрДлина(ПодЗапрос) + 1);
		Ш = Ш + 1;
		Если Ш > 1000 Тогда
			Прервать; //предохранитель от зацикливаний
		КонецЕсли;
	КонецЦикла;

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

Вот код этой функции:

Функция ОбрезатьНачалоТекста(Текст)
	
	Пока Найти(Текст, "ВЫБРАТЬ") > 1 Цикл
		Текст = СокрЛ(Сред(Текст, 2));
	КонецЦикла;
	
	Если Найти(Текст, "ВЫБРАТЬ") = 0 Тогда
		Текст = "";
	КонецЕсли;
	
	Возврат Текст;
	
КонецФункции

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

Создаем такую переменную где будем хранить эти данные. А так же я подготавливаю визуальные компоненты моей консоли запросов для отображения результатов.

ВВП = Новый Структура; //Время выполнения подзапроса
	ВВП.Очистить();
	
	//Подготовим ТЧ для отображения замеров времени
	РезультатТаблица.Очистить();
	РезультатТаблица.Колонки.Очистить();
	ЭтаФорма.ЭлементыФормы.ТаблицаРезультата.Колонки.Очистить();
	РезультатТаблица.Колонки.Добавить("ИмяПодзапроса");
	РезультатТаблица.Колонки.Добавить("Время");
	
	Для Каждого ТекПоле Из РезультатТаблица.Колонки Цикл  //добавим колонки в гриде
		ЭтаФорма.ЭлементыФормы.ТаблицаРезультата.Колонки.Добавить(ТекПоле.Имя);
	КонецЦикла;
	Для Каждого ТекПоле Из ЭтаФорма.ЭлементыФормы.ТаблицаРезультата.Колонки Цикл
		ТекПоле.Данные = ТекПоле.Имя;
	КонецЦикла;

Теперь начинаем непосредственно процесс замера времени.

//Начинаем в цикле замеры времени.
	Для Ш = 0 По МП.Количество() - 1 Цикл
		                                     
		Имя = ПолучитьИмяВременнойТаблицы(МП[Ш]);
		ПЗ = Новый Запрос;
		ПЗ.Текст = "";
		УничтожениеВТ = "";
		
		//На случай если в запросе используется одно имя временной таблицы несколько раз.
		//Перед повторным созданием - удаляем отработавший экземпляр
		Для Ж = 0 По Ш Цикл
			ПризнакИспользованияРанее = Ложь;
			Для К = 0 По Ж Цикл
				Если ПолучитьИмяВременнойТаблицы(МП[Ж]) = ПолучитьИмяВременнойТаблицы(МП[К]) И НЕ К = Ж Тогда
					ПризнакИспользованияРанее = Истина;
				КонецЕсли;
			КонецЦикла;	
			Если ПризнакИспользованияРанее Тогда               
				ПЗ.Текст = ПЗ.Текст + "
				|УНИЧТОЖИТЬ " + ПолучитьИмяВременнойТаблицы(МП[Ж]) + "; 
				|" + МП[Ж];
			Иначе
				ПЗ.Текст = ПЗ.Текст + "
				|" + МП[Ж];
				УничтожениеВТ = УничтожениеВТ + "
				|УНИЧТОЖИТЬ " + ПолучитьИмяВременнойТаблицы(МП[Ж]) + ";";
			КонецЕсли;
		КонецЦикла;
		
		ПЗ.Текст = ПЗ.Текст + УничтожениеВТ;
		
		Для Каждого СтрокаПараметров Из мФормаПараметров.Параметры Цикл
			Если СтрокаПараметров.ЭтоВыражение Тогда
				ПЗ.УстановитьПараметр(СтрокаПараметров.ИмяПараметра, Вычислить(СтрокаПараметров.ЗначениеПараметра));
			Иначе
				ПЗ.УстановитьПараметр(СтрокаПараметров.ИмяПараметра, СтрокаПараметров.ЗначениеПараметра);
			КонецЕсли;
		КонецЦикла;
		
        //Засекаем время
		ВремяНачалаВыполнения = ТекущаяДата();
		Попытка
			ПЗ.Выполнить();
		Исключение
			Сообщить(ОписаниеОшибки());
			Возврат;
		КонецПопытки;
		Затрачено = ТекущаяДата() - ВремяНачалаВыполнения;
		ОбщееВремя = ДатуВЧисло(Дата(Формат('19000101'+Затрачено, "ДФ='dd.MM.yyyy HH:mm:ss'")));
		Предыдущие = 0;
		Для Каждого ТВ Из ВВП Цикл
			Предыдущие = Предыдущие + ТВ.Значение;
		КонецЦикла;
		ТекущееВремя = ОбщееВремя - Предыдущие;
		Если ТекущееВремя < 0 Тогда
			ТекущееВремя = 0;
		КонецЕсли;
		ВВП.Вставить(Имя, ТекущееВремя);
		Сообщить("Талица: " + Имя + " Время: " + Формат(ЧислоВДату(ТекущееВремя), "ДФ='HH:mm:ss'"));
		НС = РезультатТаблица.Добавить();
		НС.ИмяПодзапроса = Имя;
		НС.Время = Формат(ЧислоВДату(ТекущееВремя), "ДФ='HH:mm:ss'");
		
	КонецЦикла;

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

Функция ПолучитьИмяВременнойТаблицы(ПодЗапрос)
	
	Старт = Найти(ПодЗапрос, "ПОМЕСТИТЬ") + 9;
	Количество = Найти(ПодЗапрос, "ИЗ") - Старт;
	НаименованиеВТ = СокрЛП(Сред(ПодЗапрос, Старт, Количество));
	
	Возврат НаименованиеВТ; 
	
КонецФункции

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

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

//	Функция преобразует получаемую в параметре дату в формат числа (TDouble)
//	Если параметр TDouble установлен в Истина, точка отчета: 30.12.1899 12:00:00 (Традиционно для Delphi)
//	Если параметр TDouble установлен в Ложь (по умолчанию), точка отчета: 01.01.1900 00:00:00 (по умолчанию точка отсчета для 1С)
Функция ДатуВЧисло(Знач пДата, TDouble = Ложь) 
	
	Возврат ?(TDouble, (пДата - Дата(1899,12,30,12,0,0)) / 86400, (пДата - Дата(1900,01,01,0,0,0)) / 86400);
	
КонецФункции

Функция ЧислоВДату(Знач пДата, TDouble = Ложь) 
	
	Возврат Дата(?(TDouble, Дата(1899,12,30,12,0,0) + (пДата * 86400), Дата(1900,01,01,0,0,0) + (пДата * 86400)));
	
КонецФункции

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

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

p.s.
 Лично я для дебага и замеров делаю отдельную версию запроса. В ней я все результирующие таблицы (не временные) так же помещаю во временные таблицы с условными именами вроде ВТ_ДебагN. Так же если общее время выполнения запроса приближено к 15-20-30 минутам, то почем бы не наложить ограничения "ПЕРВЫЕ NNNNN" в ключевых подзапросах, для экономии времени. Но тут стоит понимать что чем больше данных тем более реальной будет картина замера, и некоторые подзапросы с маленьким количеством данных могут попросту не проявить своих тормозов. Поэтому с этим надо осторожно.

Желаю всем правильных и быстро работающих запросов! :) 

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