От экспертов «1С-Рарус»: Зависание проведения документа при неоптимальных планах запросов из‑за Parameter sniffing в MS SQL. Сравнение с PostgreSQL

Непредсказуемое зависание сеанса пользователя при проведении документа в 1С

Сеть предприятий общественного питания ведет свою деятельность в «1С:УНФ 8. Управление предприятием общепита». После перехода на очередной релиз от пользователей стали поступать обращения, что при проведении документов в какой-то момент сеанс зависает и даже спустя 30–60 минут операции не завершаются. Зависание сеанса одного пользователя не вызывает замедление работы системы у остальных пользователей. Нагрузка на оборудование штатная и свободных ресурсов достаточно для нормальной работы.

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

Инфраструктура исследуемой системы

Программный продукт: 1С:УНФ 8. Управление предприятием общепита.
База данных: Microsoft SQL Server 2017 64х.
Платформа 1С:Предприятие 8: 8.3.20.1710 64х.
Операционная система: Windows Server 2012 R2.
Процессор: Intel(R) Xeon(R) Gold 6242R CPU @ 3.10GHz.
Оперативная память: 320 GB.
SSD: 3 TB.
Hypervisor: VMware ESXi, 7.0.3.

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

Основной процесс работы с программой является отражением фактов приготовления блюд и списания ингредиентов с помощью документов «Выпуск блюд». Для заполнения данных документов в решении поддерживается схема от чеков и от заказов на производство («Планы меню»). В режиме от чеков кассовые системы передают информацию о продажах и возвратах, затем данные за смену агрегируются и формируются учетные документы, одним из которых и является «Выпуск блюд».

Поиск причин зависания сеанса пользователя

Собираем и анализируем логи технологического журнала

Получив данное обращение, мы поначалу оказались в небольшой растерянности. Поэтому сказали, давайте соберём логи ТЖ по событиям CALL, SDBL, DBMSSQL и посмотрим нет ли чего-то такого длительного. Хотя надежды особо не было найти, так как нерегулярность зависания любого выпуска подсказывала, что дело не в этом. Впрочем, а вдруг кто нашалил так, что длительная операция срабатывает при каких-либо сложных условиях. Ничего не обнаружили...

Второй гипотезой являлись блокировки данных. И не просто блокировки, а множество мелких блокировок, каждая из которых не достигает порога в 20 секунд, но их много. Для их анализа был настроен сбор логов по событиям TLOCK, TTIIMEOUT, TDEADLOCK, EXCP.

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

Полный текст файла logcfg.xml:

<?xml  version="1.0" encoding="UTF-8"?>

<config  xmlns="http://v8.1c.ru/v8/tech-log">

       <log  history="24" location="d:\logs">

             <property  name="all"/>

             <event>

                    <eq  property="name" value="TLOCK"/>

                    <eq  property="p:processName" value="base_name"/>

             </event>

              <event>

                    <eq  property="name" value="TDEADLOCK"/>

                    <eq  property="p:processName" value="base_name"/>

             </event>

             <event>

                    <eq  property="name" value="TTIMEOUT"/>

                    <eq  property="p:processName" value="base_name"/>

             </event>

             <event>

                    <eq  property="name" value="EXCP"/>

                    <eq  property="p:processName" value="base_name"/>

             </event>

             <event>

                    <eq  property="name" value="CALL"/>

                    <eq  property="p:processName" value="base_name"/>

             </event>

             <event>

                    <eq  property="name" value="SDBL"/>

                    <eq  property="p:processName" value="base_name"/>

             </event>

             <event>

                    <eq  property="name" value="DBMSSQL"/>

                    <eq  property="p:processName" value="base_name"/>

             </event>

       </log>

       <dump  location="d:\dumps\"

                    create="1"

                    type="0"

                    externaldump="1"/>

</config> 

За время сбора логов по словам администратора возникло несколько таких зависаний хоть перепроведения и не запускались.

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

Приступим к анализу собранных логов. Их размер превышал 40 ГБ, поэтому для анализа используем bash-скрипты. Сначала посмотрим на длительность максимальных блокировок. Для этого выполняем следующие команды:

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

А вот блокировки, которые ожидали друг друга, заполняя свойство waitConnections — есть.

При этом их небольшое количество с длительностью каждого меньше 0,5 секунды. Следовательно, гипотеза о множестве маленьких блокировок не подтвердилась.

Ранее длительные вызовы были проанализированы так:

Видим событие открытия формы документа «Инвентаризации запасов», которое выполнялось порядка 40 минут, а также еще ряд длительных операций по 30 и 13 минут. То есть в системе попутно обнаруживались неприятности, которые надо было исправлять, но пока речь не о них.

Так, что же делать? Давайте соберем логи по запросам еще раз, вдруг мы что-то пропустили или собрали не в тот момент. Посмотрим на топ выполненных длительных запросов по событию SDBL:

В результате можно увидеть запрос, который выполнялся почти все 40 минут события CALL. А это уже зацепка за нужное направление!

Полный текст события с приведенным запросом:

Данный запрос в контексте 1С:

ВЫБРАТЬ

		ВТ_ОстаткиТоваров.Ингредиент КАК Ингредиент,

		ВТ_ОстаткиТоваров.Характеристика КАК Характеристика,

		ВТ_ОстаткиТоваров.Количество КАК Количество,

		&ПараметрСниффинг2 КАК ПараметрСниффинг,

		ВТ_ОстаткиТоваров.Партия КАК Партия,

		ВТ_ОстаткиТоваров.ЗаказПокупателя КАК ЗаказПокупателя,

		ЕСТЬNULL(ОбработкаСырья.Коэффициент, 1) КАК КоэффициентПартионныхПотерь

ИЗ

		ВТ_ОстаткиТоваров КАК ВТ_ОстаткиТоваров

			ЛЕВОЕ СОЕДИНЕНИЕ РегистрСведений.УОП_ОбработкаСырьяПартионная КАК ОбработкаСырья

			ПО ВТ_ОстаткиТоваров.Ингредиент = ОбработкаСырья.Ингредиент

				И ВТ_ОстаткиТоваров.Партия = ОбработкаСырья.Партия

			ЛЕВОЕ СОЕДИНЕНИЕ Справочник.ПартииНоменклатуры КАК ПартииНоменклатуры

			ПО ВТ_ОстаткиТоваров.Партия = ПартииНоменклатуры.Ссылка
УПОРЯДОЧИТЬ ПО

		ПартииНоменклатуры.УОП_СрокГодности

		ПартииНоменклатуры.УОП_ДокументПартии.Дата

По тексту запросов можно увидеть, что временная таблица соединяется с регистром сведений «Обработка cырья» (InfoRg15723) и со справочниками «Номенклатура» (Reference216) и «Партии номенклатуры» (Reference250) левыми соединениями.

При этом регистр сведений «Обработка сырья» у клиента не содержит записей вообще, а к справочникам идет соединение по ссылкам и кажется, что запрос вполне обычный. Да и после завершения зависшего сеанса, данный запрос отрабатывает меньше, чем за одну секунду. Что вызывает чувство противоречия и непонимания, т. к. у нас есть запрос, который в один момент времени отрабатывает за секунду, а в другой за 40 минут.

Подозреваем 1С:СЛК

Почему этот запрос один раз выполняется быстро, а в другой раз медленно? Сам запрос выполняется в рамках логики, зашифрованной с помощью компоненты защиты 1С:СЛК, которую обновляли как раз в данном релизе, но так совпало, что после выхода релиза «1С:Управление предприятием общепита» была выпущена новая версия компоненты 1С:СЛК. Т. к. срок между крайними релизами компоненты оказался слишком маленьким, а мы имеем непонятную ситуацию с запросом, то появляется подозрение на причастность данной компоненты к непонятным зависаниям. Однако, по итогу ее обновление не помогло и версия не подтвердилась.

Наблюдаем за поведением кластера серверов 1С и СУБД

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

Данная ситуация произошла буквально через несколько часов. В момент подключения снимаем значения показателей сеансов с периодом в 30–40 секунд и сохраняем в формате csv.

После чего выполняем сравнение результатов по зависшим пользователям и видим, что меняется только время вызова:

Принимаем решение заглянуть в Management Studio и с помощью следующего текста запроса посмотреть выполняемые запросы:

SELECT 

	session_id, 

	status, 

	wait_type, 

	command, 

	last_wait_type, 

	qt.text  as sql_text, 

	total_elapsed_time/1000 as [total_elapsed_time, sec],  

	wait_time/1000 as [wait_time, sec], 

	(total_elapsed_time - wait_time)/1000 as [work_time, sec], 

	percent_complete 

FROM sys.dm_exec_requests as qs  

	CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) as qt  

	where session_id >= 50 and session_id <> @@spid 

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

Стоит отметить, что информацию о выполняемых запросах также можно получить в Activity Monitor применив отборы по номеру процесса указанному в кластере серверов.

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

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

• Запрос не использует индексы.
• Соединение устанавливается не по правильным полям.
• Выбираемые данные отбираются слишком поздно.

Конечно, данные причины тоже приводят к медленному выполнению запросов. Если попробовать обобщить их, то главная причина — не оптимально подобранный план запросов!

Проверяем план запроса

В статье «Очистка процедурного кэша SQL для 1C. Мифы, реальность, практика» мы уже упоминали про план запросов, но давайте еще раз вспомним что это.

Язык запросов 1С, как и язык sql-запросов, является декларативным, т. е. мы говорим, что нам нужно найти, а не что нужно выполнять, чтобы найти. Задачей преобразования этого «что нужно» в «как это искать» занимается оптимизатор запросов. Данная компонента основываясь на информации о схеме базы данных, статистике и тексте выполняемого запроса формирует различные последовательности операций, которые приводят к требуемому результату.

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

Почему предполагаемую? При выполнении запроса данная компонента Microsoft SQL Server отталкиваясь от статистики сначала формирует именно предполагаемый план запроса (estimated execution plan), который и помещается в кэш, а уже после выполнения формируется фактический план запроса (actual execution plan), который дополняет предполагаемый план уже фактическими данными. Например, такими как: среда выполнения, затраченное время, время ЦП, количество выбираемых строк и многое другое.

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

Для того, чтобы в этом убедиться давайте посмотрим на план запроса, который будет выбирать все номенклатурные позиции с именем, начинающимся на «Пельмешки»:

ВЫБРАТЬ

		СпрНоменклатура.Ссылка КАК Номенклатура

ИЗ

		Справочник.Номенклатура КАК СпрНоменклатура

ГДЕ

		СпрНоменклатура.Наименование ПОДОБНО &НаименованиеНоменклатуры 

Эксперимент будем проводить на клиент-серверной базе. В качестве системы управления базами данных выступит Microsoft SQL Server.

Сначала для чистоты эксперимента очистим кэш планов. Для этого воспользуемся инструкцией DBCC FREEPROCCACHE.

Для сбора планов запроса можно воспользоваться средствами СУБД или собрать лог технологического журнала. Чтобы включить сбор планов запроса в логе технологического журнала необходимо в файл logcfg.xml добавить тег <plansql />. Подробнее про данную возможность по ссылке https://its.1c.ru/db/v8320doc/bookmark/adm/TI000000401.

Пример текста файла logcfg.xml с включенным сбором планов запроса:

<?xml version="1.0"?>

<config  xmlns="http://v8.1c.ru/v8/tech-log">

  <log location="c:\log"  history="24">

    <event>

      <eq property="name"  value="dbmssql"/>

    </event>

    <property name="sql"/>

    <property  name="plansqltext"/>

  </log>

  <plansql />

</config> 

В результате получим событие, где в Sql размещается выполняемый текст запроса на уровне СУБД, а в planSQLText — план запроса:

Если же выполнить сбор плана средствами Extended Events Microsoft SQL Server по событиям query_post_compilation_showplan, query_post_execution_showplan и sql_batch_completed:

То в результате можно получить такой предварительный план запроса:

И такой фактический план запроса:

Создадим новый элемент справочника, попадающий под условие, и попробуем перевыполнить запрос. В результате СУБД сформирует только фактический план запроса, а предполагаемый возьмет из кэша:

В этом также можно убедиться по значению свойства QueryPlanHash, которое можно увидеть в XML представлении плана и оно же будет сохраняться для данного запроса:

Стоит отметить, что если мы изменим значение параметра НаименованиеНоменклатуры, например, на «Пюрешка» то план запроса все равно не поменяется:

Связано это с тем, что в кэше планов будет находиться план, рассчитанный с учетом параметров запроса первого выполнения. Значения этих параметров можно увидеть в тегах ParameterCompiledValue, а значения, которые использовали при фактическом выполнении в ParameterRuntimeValue:

Механизм сканирования параметров parameter sniffing

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

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

Представим себе периодический регистр сведений «Цены номенклатуры» с измерениями «Номенклатура» и «Организация». Измерение «Организация» будет дополнительно индексировано:

В данном регистре будут фиксироваться цены организаций ООО «Плюшка-пампушка» и ИП «Пюрюшка с котлеткой» в процентом соотношении записей 99,9% к 0,1% соответственно:

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

ВЫБРАТЬ

       ЦеныНоменклатуры.Период КАК Период,

       ЦеныНоменклатуры.Номенклатура КАК Номенклатура,

       ЦеныНоменклатуры.Организация КАК Организация,

       ЦеныНоменклатуры.Цена КАК Цена

ИЗ

       РегистрСведений.ТЦ_ЦеныНоменклатуры КАК ЦеныНоменклатуры

ГДЕ

       ЦеныНоменклатуры.Организация = &Организация 

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

Как можно увидеть планы между собой отличаются. Для организации с меньшим количеством записей система приняла решение воспользоваться поиском по некластерном индексу с помощью Index seek, а потом дополняет информацию соединив с результатом поиска по кластерному индексу (Key lookup). Для организации с большим количеством записей система решила воспользоваться Clustered Index Scan, тем самым сразу просканировала по кластерному индексу.

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

Можно ли отключать parameter sniffing?

Вы можете спросить, а можно ли отключить механизм сканирования параметров (parameter sniffing) и как?

Для этого необходимо отключить флаг трассировки 4136 или начиная с версии SQL Server 2016 (13.x) это можно сделать на уровне базы данных:

Отключение данного механизма будет работать только если в запросе не используются OPTION(RECOMPILE), WITH RECOMPILE или OPTIMIZE FOR, но их из платформы 1С:Предприятие 8 и не прилетит.

В результате отключения данного механизма из плана запроса пропадет свойство ParameterCompiledValue и планы будут формироваться заново после каждого выполнения запроса:

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

Результат поиска причин зависания пользовательского сеанса

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

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

Устраняем причины зависания сеансов пользователей

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

Самый простой способ, который доступен из платформы «1С:Предприятие 8» без дополнительных настроек СУБД — формировать текст запроса динамически. Тогда для СУБД данный запрос будет казаться новым и план запроса будет сформирован заново.

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

В упрощенном виде это выглядит приблизительно так:

ТекстЗапроса = "ВЫБРАТЬ

|      ВТ_ОстаткиТоваров.Ингредиент КАК Ингредиент,

|      ВТ_ОстаткиТоваров.Характеристика КАК Характеристика,

|      ВТ_ОстаткиТоваров.Количество КАК Количество,

|      &ПараметрСниффинг2 КАК ПараметрСниффинг,

|      ВТ_ОстаткиТоваров.Партия КАК Партия,

|      ЕСТЬNULL(ОбработкаСырья.Коэффициент, 1) КАК КоэффициентПартионныхПотерь

|ИЗ

|      ВТ_ОстаткиТоваров  КАК ВТ_ОстаткиТоваров

|            ЛЕВОЕ СОЕДИНЕНИЕ РегистрСведений.УОП_ОбработкаСырьяПартионная КАК ОбработкаСырья

|            ПО ВТ_ОстаткиТоваров.Ингредиент = ОбработкаСырья.Ингредиент

|                   И  ВТ_ОстаткиТоваров.Партия = ОбработкаСырья.Партия

|            ЛЕВОЕ СОЕДИНЕНИЕ Справочник.ПартииНоменклатуры КАК ПартииНоменклатуры

|            ПО ВТ_ОстаткиТоваров.Партия = ПартииНоменклатуры.Ссылка

|

|УПОРЯДОЧИТЬ ПО

|      ПартииНоменклатуры.УОП_СрокГодности";

ТекстЗапроса = СтрЗаменить(ТекстЗапроса,  "&ПараметрСниффинг2", Строка(Новый УникальныйИдентификатор));

Но когда мы решили проверить данный запрос, то на уровне СУБД увидели следующий текст запроса SQL:

(@P1 nvarchar(4000),@P2  numeric(10),@P3 numeric(10),@P4 numeric(10),@P5 numeric(10),@P6 numeric(10),@P7  numeric(10),@P8 numeric(10),@P9 numeric(10),@P10 numeric(10),@P11  numeric(10),@P12 numeric(10),@P13 numeric(10))

SELECT

       T1._Q_000_F_000RRef,

       T1._Q_000_F_001RRef,

       T1._Q_000_F_003,

       @P1,

       T1._Q_000_F_004RRef,

       T1._Q_000_F_005RRef,

       ISNULL(CAST(T2._Fld19343  AS NUMERIC(8, 4)),1.0),

       T3._Fld4356,

       CASE  WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x000001A6 THEN  T4._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x0000018A  THEN T5._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef =  0x00006230 THEN T6._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND  T3._Fld4354_RTRef = 0x00000159 THEN T7._Date_Time WHEN T3._Fld4354_TYPE = 0x08  AND T3._Fld4354_RTRef = 0x00000162 THEN T8._Date_Time WHEN T3._Fld4354_TYPE =  0x08 AND T3._Fld4354_RTRef = 0x000001B3 THEN T9._Date_Time WHEN  T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x0000019A THEN T10._Date_Time  WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x00000174 THEN  T11._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x0000015F  THEN T12._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef =  0x00000185 THEN T13._Date_Time ELSE CAST(NULL AS DATETIME) END

FROM #tt34 T1 WITH(NOLOCK) 

Платформа «1С:Предприятие 8» самостоятельно обернула данное поле в параметр запроса. Хотя еще пару релизов платформы назад этот вариант срабатывал «на ура». Причину почему разработчики платформы так сделали можно понять: все для того же сокращения количества формирования планов запросов и оптимизации их количества в буферном кэше.

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

ГСЧ = Новый  ГенераторСлучайныхЧисел(ТекущаяУниверсальнаяДатаВМиллисекундах());

Слагаемое = ГСЧ.СлучайноеЧисло(0, 429496729) + ГСЧ.СлучайноеЧисло(0, 4294967295);

Слагаемое = ГСЧ.СлучайноеЧисло(0, 429496725) + ГСЧ.СлучайноеЧисло(0, 4294967295);



ТекстЗапроса = СтрЗаменить(ТекстЗапроса, "&Слагаемое1", Слагаемое1); 

ТекстЗапроса = СтрЗаменить(ТекстЗапроса, "&Слагаемое2", Слагаемое2); 

Однако выполнив этот запрос, мы увидели, что платформа выполняет данную арифметическую операции заранее, а результат передает все также через параметр. Следовательно, данный вариант не подойдет:

(@P1  numeric(10),@P2 numeric(10),@P3 numeric(10),@P4 numeric(10),@P5 numeric(10),@P6  numeric(10),@P7 numeric(10),@P8 numeric(10),@P9 numeric(10),@P10 numeric(10),@P11  numeric(10),@P12 numeric(10),@P13 numeric(10))

SELECT

       T1._Q_000_F_000RRef,

       T1._Q_000_F_001RRef,

       T1._Q_000_F_003,

       @P1,

       T1._Q_000_F_004RRef,

       T1._Q_000_F_005RRef,

       ISNULL(CAST(T2._Fld19343  AS NUMERIC(8, 4)),1.0),

       T3._Fld4356,

       CASE  WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x000001A6 THEN  T4._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x0000018A  THEN T5._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef =  0x00006230 THEN T6._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND  T3._Fld4354_RTRef = 0x00000159 THEN T7._Date_Time WHEN T3._Fld4354_TYPE = 0x08  AND T3._Fld4354_RTRef = 0x00000162 THEN T8._Date_Time WHEN T3._Fld4354_TYPE =  0x08 AND T3._Fld4354_RTRef = 0x000001B3 THEN T9._Date_Time WHEN T3._Fld4354_TYPE  = 0x08 AND T3._Fld4354_RTRef = 0x0000019A THEN T10._Date_Time WHEN  T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x00000174 THEN T11._Date_Time  WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x0000015F THEN  T12._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x00000185  THEN T13._Date_Time ELSE CAST(NULL AS DATETIME) END

FROM #tt34 T1 WITH(NOLOCK) 

Мы не сдавались и попробовали выполнить арифметическую операцию с одним из полей временной таблицы. Например, с количеством:

ТекстЗапроса = "ВЫБРАТЬ

  |      ВТ_ОстаткиТоваров.Ингредиент  КАК Ингредиент,

  |      ВТ_ОстаткиТоваров.Характеристика  КАК Характеристика,

  |      ВТ_ОстаткиТоваров.Количество  КАК Количество,

  |      ВТ_ОстаткиТоваров.Количество + &Слагаемое1 + &Слагаемое2 КАК ПараметрСниффинг,

  |      ВТ_ОстаткиТоваров.Партия  КАК Партия,

  |      ЕСТЬNULL(ОбработкаСырья.Коэффициент,  1) КАК КоэффициентПартионныхПотерь

  |ИЗ

  |      ВТ_ОстаткиТоваров  КАК ВТ_ОстаткиТоваров

  |            ЛЕВОЕ  СОЕДИНЕНИЕ РегистрСведений.УОП_ОбработкаСырьяПартионная КАК ОбработкаСырья

  |            ПО ВТ_ОстаткиТоваров.Ингредиент  = ОбработкаСырья.Ингредиент

  |                   И  ВТ_ОстаткиТоваров.Партия = ОбработкаСырья.Партия

  |            ЛЕВОЕ  СОЕДИНЕНИЕ Справочник.ПартииНоменклатуры КАК ПартииНоменклатуры

  |            ПО  ВТ_ОстаткиТоваров.Партия = ПартииНоменклатуры.Ссылка

  |

  |УПОРЯДОЧИТЬ ПО

  |      ПартииНоменклатуры.УОП_СрокГодности";


ГСЧ = Новый  ГенераторСлучайныхЧисел(ТекущаяУниверсальнаяДатаВМиллисекундах());

Слогаемое1 = ГСЧ.СлучайноеЧисло(0, 429496729) +  ГСЧ.СлучайноеЧисло(0, 4294967295);

Слогаемое1 = ГСЧ.СлучайноеЧисло(0, 429496725) + ГСЧ.СлучайноеЧисло(0,  4294967295);

ТекстЗапроса = СтрЗаменить(ТекстЗапроса,  "&Слогаемое1", Слогаемое1); 

ТекстЗапроса = СтрЗаменить(ТекстЗапроса,  "&Слогаемое2", Слогаемое2); 

Выполнив данный запрос, мы получили долгожданный результат с изменением планов и текста запроса:

Основная часть текста запроса, которая была выполнена:

(@P1  numeric(10),@P2 numeric(10),@P3 numeric(10),@P4 numeric(10),@P5 numeric(10),@P6  numeric(10),@P7 numeric(10),@P8 numeric(10),@P9 numeric(10),@P10 numeric(10),@P11 numeric(10),@P12 numeric(10))
SELECT

	T1._Q_000_F_000RRef,

	T1._Q_000_F_001RRef,

	T1._Q_000_F_003,

	((T1._Q_000_F_003 + 23423.0) + 454631.0),

	T1._Q_000_F_004RRef,

	T1._Q_000_F_005RRef,

	ISNULL(CAST(T2._Fld19343  AS NUMERIC(8, 4)),1.0),

	T3._Fld4356,

	CASE WHEN  T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x000001A6 THEN T4._Date_Time  WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x0000018A THEN T5._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x00006230  THEN T6._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef =  0x00000159 THEN T7._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND  T3._Fld4354_RTRef = 0x00000162 THEN T8._Date_Time WHEN T3._Fld4354_TYPE = 0x08  AND T3._Fld4354_RTRef = 0x000001B3 THEN T9._Date_Time WHEN T3._Fld4354_TYPE =  0x08 AND T3._Fld4354_RTRef = 0x0000019A THEN T10._Date_Time WHEN  T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x00000174 THEN T11._Date_Time  WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x0000015F THEN  T12._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x00000185 THEN T13._Date_Time ELSE CAST(NULL AS DATETIME) END
FROM  #tt34 T1 WITH(NOLOCK)

Мы выяснили, что арифметическая операция над полем решает данную проблему, а константы в полях преобразовываются в параметры, но что будет если просто вставить заранее верное условие в область ГДЕ? Т. е. когда значение параметров &Параметр1 и &Параметр2 равны. Тогда текст запроса выглядел бы так:

 ТекстЗапроса = "ВЫБРАТЬ

  |      ВТ_ОстаткиТоваров.Ингредиент  КАК Ингредиент,

  |      ВТ_ОстаткиТоваров.Характеристика  КАК Характеристика,

  |      ВТ_ОстаткиТоваров.Количество  КАК Количество,

  |      &ПараметрСниффинг2 КАК ПараметрСниффинг,

  |      ВТ_ОстаткиТоваров.Партия  КАК Партия,

  |      ЕСТЬNULL(ОбработкаСырья.Коэффициент,  1) КАК КоэффициентПартионныхПотерь

  |ИЗ

  |      ВТ_ОстаткиТоваров  КАК ВТ_ОстаткиТоваров

  |            ЛЕВОЕ  СОЕДИНЕНИЕ РегистрСведений.УОП_ОбработкаСырьяПартионная КАК ОбработкаСырья

  |            ПО  ВТ_ОстаткиТоваров.Ингредиент = ОбработкаСырья.Ингредиент

  |                   И  ВТ_ОстаткиТоваров.Партия = ОбработкаСырья.Партия

  |            ЛЕВОЕ  СОЕДИНЕНИЕ Справочник.ПартииНоменклатуры КАК ПартииНоменклатуры

  |            ПО  ВТ_ОстаткиТоваров.Партия = ПартииНоменклатуры.Ссылка

  |

  |ГДЕ

  |      &ПараметрСниффинг1  = &ПараметрСниффинг2

  |

  |УПОРЯДОЧИТЬ ПО

  |      ПартииНоменклатуры.УОП_СрокГодности";

  ЗначениеПараметра = Строка(Новый УникальныйИдентификатор);

  ТекстЗапроса = СтрЗаменить(ТекстЗапроса, "&ПараметрСниффинг1", ЗначениеПараметра);

  ТекстЗапроса = СтрЗаменить(ТекстЗапроса, "&ПараметрСниффинг2", ЗначениеПараметра); 

Если посмотреть на выполняемый текст запроса, то можно увидеть, что условие преобразовалось в 1 = 1. Причем значения параметров не влияют на результат, т. е. можно передать ГУИД = ГУИД или Число = Число или АрифметическаяОперация1 = АрифметическаяОперация2 — все преобразовывается в 1 = 1. Даже если выполнять несколько пар с разными значениями.

Следовательно, динамическое изменение текста в данном случае не поможет:

(@P1  numeric(10),@P2 numeric(10),@P3 numeric(10),@P4 numeric(10),@P5 numeric(10),@P6  numeric(10),@P7 numeric(10),@P8 numeric(10),@P9 numeric(10),@P10  numeric(10),@P11 numeric(10),@P12 numeric(10))

SELECT

	T1._Q_000_F_000RRef,

	T1._Q_000_F_001RRef,

	T1._Q_000_F_003,

	T1._Q_000_F_004RRef,

	T1._Q_000_F_005RRef,

	ISNULL(CAST(T2._Fld19343  AS NUMERIC(8, 4)),1.0),

	T3._Fld4356,

	CASE WHEN  T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x000001A6 THEN T4._Date_Time  WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x0000018A THEN  T5._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x00006230  THEN T6._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x00000159  THEN T7._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef =  0x00000162 THEN T8._Date_Time WHEN T3._Fld4354_TYPE = 0x08 AND  T3._Fld4354_RTRef = 0x000001B3 THEN T9._Date_Time WHEN T3._Fld4354_TYPE = 0x08  AND T3._Fld4354_RTRef = 0x0000019A THEN T10._Date_Time WHEN T3._Fld4354_TYPE =  0x08 AND T3._Fld4354_RTRef = 0x00000174 THEN T11._Date_Time WHEN  T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x0000015F THEN T12._Date_Time  WHEN T3._Fld4354_TYPE = 0x08 AND T3._Fld4354_RTRef = 0x00000185 THEN T13._Date_Time  ELSE CAST(NULL AS DATETIME) END

FROM #tt34 T1 WITH(NOLOCK)

LEFT OUTER JOIN dbo._InfoRg19340 T2

ON ((T1._Q_000_F_000RRef =  T2._Fld19341RRef) AND (T1._Q_000_F_004RRef = T2._Fld19342RRef)) AND (T2._Fld929  = @P1)

LEFT OUTER JOIN dbo._Reference181 T3

ON ((T1._Q_000_F_004RRef = T3._IDRRef))  AND (T3._Fld929 = @P2)

LEFT OUTER JOIN dbo._Document422 T4

ON (T3._Fld4354_TYPE = 0x08 AND  T3._Fld4354_RTRef = 0x000001A6 AND T3._Fld4354_RRRef = T4._IDRRef) AND  (T4._Fld929 = @P3)

LEFT OUTER JOIN dbo._Document394 T5

ON (T3._Fld4354_TYPE = 0x08 AND  T3._Fld4354_RTRef = 0x0000018A AND T3._Fld4354_RRRef = T5._IDRRef) AND  (T5._Fld929 = @P4)

WHERE 1=1

ORDER BY (T3._Fld4356) 

Несмотря на динамическое изменение текста запроса платформа «1С:Предприятие 8» дополнительно старается помочь оптимизировать количество построение планов. Из всех рассматриваемых нами вариантов лишь арифметическая операция над полем выборки позволила решить задачу принудительного перестроения планов запроса.

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

Мы проанализировали события логирования в журнале регистрации и увидели, что все запросы, которые начинали выполняться — завершились. Что подтверждало факт отсутствия обращений от пользователей:

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

Стоит отметить, что в Microsoft SQL Server есть дополнительные возможности влияния на решения оптимизатора запроса. Одним из них является механизм хинтов.

Данных механизм переопределяет поведение оптимизатора запросов на время выполнения SQL-инструкции.

Однако, повлиять с помощью хинта со стороны платформы не получиться. Для этого потребуется настроить новое руководство планов (Plan Guides):

В результате оптимизатор запросов будет добавлять выбранный хинт к запросу. На картинке представлена команда запуска рекомпиляции плана, но в данное поле можно добавить уже фиксированный план. Подробнее про данный механизм можно прочитать в документации https://docs.microsoft.com/ru-RU/sql/relational-databases/performance/plan-guides?view=sql-server-ver15.

Альтернативный способ — Force plan

Альтернативным способом решения задачи может стать Force Plan от MS SQL. Таким подходом можно воспользоваться, например, когда нельзя вносить изменения в типовое решение, стоящее на поддержке.

Force plan это функционал блока Query Store, который появился в версии SQL Server 2016 CTP2. Query Store — это хранилище планов запросов и статистической информации для каждой базы данных в отдельности.

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

Проведём подготовительные работы для использования Force plan

Для включения функции Query Store необходимо в настройках базы установить Operation mode в режим Read Write, т. е. сервер будет как собирать, так и сохранять данные запросов:

Так же это можно сделать запросом:

ALTER DATABASE <database_name>

  SET QUERY_STORE = ON (OPERATION_MODE = READ_WRITE); 

Где <database_name> — это имя базы для которой хотим включить хранилище запросов.

После включения хранилища запросов в дереве объектов нашей базы появится соответствующая папка Query Store:

Которая содержит следующие варианты срезов:

• Regressed Queries — запросы, по которым показатели ухудшились.
• Overall Resource Consumption — общее потребление ресурсов для базы в целом.
• Top Resource Consuming Queries — самые затратные запросы.
• Queries With Forced Plans — запросы по которым используется принудительное использование форсированных планов.
• Queries With High Variation — запросы, по которым высокий разброс показателей производительности.
• Tracked Queries — монитор показателей выбранных запросов.

Настраиваем использование Force plan

Возьмем пример с периодическим регистром сведений «Цены номенклатуры». Ранее мы разобрались, что в зависимости от первоочередности запроса кэшировался первый или второй план. Давайте форсируем оптимальный план для обоих случаев и посмотрим, что получится.

После включения Query Store выполним оба запроса с очисткой кэша ещё раз и найдем наш запрос в хранилище запросов.

План запроса для 999000 записей:

План запроса для 1000 записей:

Сформировалось два плана, как и ожидалось: 6132404 и 6132420.

Теперь форсируем план, который использует Clustered Index Scan, т. к. его применение вернет результат за приемлемое время на любом объеме выборки в отличии от второго плана.

Для этого нажимаем Force Plan и у нашего плана появляется признак закрепления:

Теперь проверим в Extended Events какой план будет выполняться по различным параметрам запроса с очисткой кэша:

Как видим, для любых входных параметров будет использоваться закрепленный план.

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

Как будет вести себя PostgreSQL в аналогичной ситуации

В теории

Кэширование в системе управления базами данных PostgreSQL устроено иначе, чем в MSSQL Server. Как такового понятия процедурного кэша в данной СУБД не существует.

Этапы выполнения запроса в PostgreSQL

Такой подход имеет ряд как недостатков, так и преимуществ:

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

Оптимизация построения планов планировщиком

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

Но в ситуациях, когда рассмотрение всех возможных вариантов выполнения запросов занимает слишком много времени и памяти, планировщик запросов в PostgreSQL имеет ряд особенностей для ускорения и «удешевления» построения плана.

Например, такие оптимизации имеют место при выполнении запросов с большим количеством операций соединения. Чтобы выбрать разумный (но не обязательно наилучший) план запроса за приемлемое время, PostgreSQL использует генетический оптимизатор запросов, когда количество соединений превышает некоторый предел. Более подробно об этом можно прочитать в документации (https://postgrespro.ru/docs/postgrespro/14/planner-optimizer).

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

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

Подготовка запроса (https://postgrespro.ru/docs/postgrespro/14/sql-prepare) разбирает и трансформирует его обычным образом, но полученное дерево разбора сохраняется в памяти сеанса. При последующем выполнении команды EXECUTE подготовленный оператор планируется и исполняется. Такое разделение труда исключает повторный разбор запроса, при этом позволяет выбрать наилучший план выполнения в зависимости от определенных значений параметров. Более подробно мы уже рассказывали о данном механизме в сравнении с MSSQL в статье об очистке процедурного кэша.

Отмечу лишь то, что из-за отсутствия глобального кэша, даже если запрос уже был разобран одним сеансом, другой будет вынужден разобрать его заново. Поэтому, при использовании 1С в связке с postgres, данный механизм, на наш взгляд, не является приоритетным.

Варианты не «из коробки»

Для PostgreSQL написано достаточно большое количество различных плагинов и расширений. И если нас не устраивает время работы планировщика/оптимизатора запросов, то тут стоит упомянуть такие расширения, как:

• Adaptive Query Optimizer (https://github.com/postgrespro/aqo) — расширение, которое дает обратную связь планировщику от реального выполнения запроса, по результатам которого, планировщик корректирует свои планы в будущем.
• Pg_hint_plan (https://github.com/ossc-db/pg_hint_plan) — расширение, которое позволяет управлять планом выполнения запроса с помощью специальных указаний, записываемых в комментариях.

Из вышеописанного поведения планировщика запросов в PostgreSQL можем сделать вывод, что проблемы с переиспользованием неоптимального для текущего набора параметров плана запроса, которая порой наблюдается при включенном механизме parameter sniffing в MSSQL, не должно происходить.

На практике

Проверим на практическом примере, как PostgreSQL справляется с построением планов запросов и их исполнением для одинаковых запросов с разным значением передаваемых параметров.

Для проведения эксперимента будем использовать тестовую копию базы «1С:УНФ 8. Управление предприятием общепита», в которой проводилось расследование в первой части статьи.

Базу развернем на виртуальной машине под управлением Ubuntu 20.04 в связке с 1С 8.3.20.1710 и PostgreSQL 14. План эксперимента будет следующий:

• Настроить сбор логов технологического журнала 1С на события выполнения запросов в СУБД с выводом планов запросов.
• Воспроизвести ситуацию с выполнением запроса, который был виновником ситуации с неоптимальным переиспользованием планов в первой части статьи.
• Воспроизвести выполнение того же самого запроса, но с меньшим количеством данных.
• Сравнить полученные планы запросов.

Настройка сбора логов

Для начала создадим каталог, в который 1С будет собирать логи технологического журнала:

Далее нам необходимо назначить пользователя, от имени которого запущен сервер 1С владельцем созданной директории:

После этого создаем/открываем существующий файл настроек сбора логов, например, при помощи nano:

Настраиваем сбор на события DBPOSTGRS, которое фиксирует исполнение операторов SQL в postgres, а также SDBL, которое фиксирует исполнение запросов к модели базы данных платформы 1С. Также не забываем указать необходимость сбора планов запросов при помощи тега plansql:

<?xml version="1.0"  encoding="UTF-8"?>

<config xmlns="http://v8.1c.ru/v8/tech-log">

        <log history="24" location="/var/log/log_tj">

                <property name="all"/>

                <event>

                        <eq  property="name" value="SDBL"/>

                </event>

                <event>

                        <eq  property="name" value="DBPOSTGRS"/>

                </event>

        </log>

        <plansql/>

</config> 

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

Воспроизведение проблемного запроса

Нам известно, что проблемный запрос исполняется при обращении к остаткам при заполнении производственных таблиц фактическим количеством в документах «Выпуск блюд» и «Инвентаризация товаров». Текст запроса до оптимизаций приведен ниже:

Корнем длительного выполнения в MSSQL было использование одного и того же плана запроса при разном количестве строк во временной таблице ВТ_ОстаткиТоваров.

Возьмем два документа «Выпуск блюд». В одном будет готовиться всего несколько блюд, а в другом несколько сотен блюд. В каждом из этих документов выполним заполнение производственных таблиц:

Заполнение производства выполняем со включенным сбором логов технологического журнала 1С. После чего останавливаем его, переименовав файл настроек:

И проверим наличие собранных логов при помощи команды tree:

Анализ логов и просмотр планов запросов

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

Для этого, нам необходимо сопоставить текст запроса в 1С с текстом запроса в postgres. Воспользуемся обработкой, которая выводит структуру хранения метаданных и найдем в ней имена интересующих нас таблиц, а именно регистра накопления «Запасы»:

И регистра сведений «УОП_ОбработкаСырьяПартионная»:

Далее, при большом объеме логов технологического журнала 1С мы можем воспользоваться инструментами bash или же специальными инструментами, например «1С-Рарус: СОК (анализ лога технологического журнала)».

В нашем случае, мы собирали логи точечно и объем совсем небольшой, поэтому просто попробуем выполнить поиск по имени таблиц регистров:

В результате нашли 2 события DBPOSTGRS с искомым текстом запроса и 2 события SDBL для все того же запроса:

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

План запроса лог технологического журнала собирает ровно в таком же виде, как он выводится командой EXPLAIN ANALYZE:

Производить анализ в текстовом виде неудобно, существует несколько неплохих сторонних инструментов визуализации, например, explain.tensor.ru. Воспользуемся данным инструментом и взглянем на собранные планы запроса.

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

Оптимизатор выбрал план запроса, в котором соединение временной таблицы остатков с таблицей регистра сведений выполняется оператором nested loops.

А вот для второго плана для запроса с большим количеством записей во временной таблице остатков оптимизатор уже подбирает другой, более оптимальный с его точки зрения план с использованием оператора hash join для соединения таблиц:

Какой вывод можно сделать из увиденного? Оптимизатор запросов в postgres выбирает разные планы запросов для одного и того же запроса с разными значениями параметров исходя из имеющейся у него статистической информации и алгоритмов подбора планов.

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

Подведем небольшие итоги

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

Второе, если говорить собственно о проблематике, то следует обратить внимание, что «прибить» гвоздиком план бывает не так просто. Вспомните ситуацию, когда оптимизатор платформы преобразовывал guid в секции ВЫБРАТЬ в параметр и придется поискать решение, например, воспользовавшись force plan.

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

Всем удачи на нелегком пути экспертизы!