Поиск и анализ длительных вызовов - CALL, SCALL

24.06.24

База данных - HighLoad оптимизация

Обсудим поиск и разбор причин длительных серверных вызовов CALL, SCALL.

Ранее мы искали проблемы через поиск длительных запросов и рассматривали событие технологического журнала DBPOSTGRES (5 простых шагов и 15 минут на разворачивание инструмента мониторинга проблем производительности базы 1С), сейчас поговорим про поиск проблем через длительные операции исполнения кода 1С на сервере.

CALL - это входящий удаленный вызов (на стороне приемника). Мы запросили с клиента что-то на сервер.

SCALL - исходящий серверный вызов. Например, rphost обратился к rmngr. Более подробная информация по этим событиям находится на ИТС.

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

 

1. Настройка технологического журнала

 

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

 
 Настройка технологического журнала для сбора событий CALL

 

<?xml version="1.0" encoding="UTF-8"?> 
<config xmlns="http://v8.1c.ru/v8/tech-log">
    <log location="C:\LOGS\CALL" history="12">
        <event> 
             <eq property="Name" value="CALL"/>
             <ge property="Durationus" value="5000000"/>
        </event> 
        <property name="all"/>
    </log>  
</config>

 

 

Замечание! Для настройки сбора серверных вызовов следует использовать название события - SCALL.

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

 

Рис. Добавление замера событий CALL

 

Теперь мы можем начать анализировать длительные вызовы и переходим к следующему разделу.

 

2. Поиск проблем

 

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

 

Рис. События CALL

 

Теперь давайте посмотрим, были ли какие-нибудь длительные запросы внутри интервала CALL. У нас сбор таких событий конечно же настроен. В этом случае, достаточно просто сделать отбор по пользователю и интервалу. Интервал у нас получился = 12:00-13:19. Начало интервала = время окончания за минусом длительности события.

 

Рис. Длительные запросы DBPOSTGRES в интервале события CALL

 

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

 

Рис. Context события картинка

 

 
 Context события

 

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

 

Рис. Текст проблемного запроса с выделенными проблемными местами

 

 
 Полный текст проблемного запроса

 

3. Анализ проблемы

 

1) Рассмотрим сначала обращение через точку внутри вложенного запроса. Что разработчики хотели добиться вот таким условием "ЕСТЬNULL(Товары.Заказ.Номер, """")"? 

Поле "Заказ", которое в документе соответствует реквизиту "ЗаказКлиента" может содержать ссылку или не содержать. Получается если у нас ссылка будет пустая, то получение данных через точку даст нам NULL. Иными словами проверяется заполнен заказ клиента в шапке или в табличной части.

Замечание! Если документ создан по нескольким заказам, то этот реквизит в табличной части заполняется и взводится флаг в шапке "РеализацияПоЗаказам". Если же один заказ клиента, то заполняется реквизит шапки "ЗаказКлиента".

Иными словами разработчики вместо того чтобы использовать флаг "РеализацияПоЗаказам", который собственно и предназначен для определения где находится ссылка на заказ придумали такую необычную конструкцию. Возможно данный флаг не всегда соответствует вышеуказанному описанию, тогда на него действительно полагаться не следует. Отсюда два вывода:

  1. С моей точки зрения, было бы удобнее всегда заполнять реквизит заказа в табличной части товары. 
  2. Переписать конструкцию на проверку флага "РеализацияПоЗаказам".

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

3) К тому же использование вложенных запросов может дополнительно влиять на снижение производительности. Читатель скажет, там же используется временная таблица, а для временной таблицы статистика рассчитывается, поэтому сильного влияния быть не должно. Это было бы так, если бы не получение через точку от поля составного типа. А в текущем случае у нас получается соединение временной таблицы с двумя таблицами - заказы клиентов и возвраты товаров от клиентов. Поэтому получается ситуация не однозначная, а фактически планировщик ошибается (что рассмотрено ниже).

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

Теперь посмотрим план запроса и посмотрим что на нем не так.

План запроса выглядит так https://explain.tensor.ru/archive/explain/2ff0449484417331128cb2c0a0b82e4e:0:2024-06-21#explain

С точки зрения плана запроса мы понимаем, что в данном случае довольно сильно ошибается планировщик Postgres.

 

Рис. Часть графического плана запроса

 

Объясним почему:

  • если мы посмотрим на оператор чтения данных из временной таблицы (#54), то мы видим что оценочное количество строк 328, а фактическое 1.  Не верная оценка, хотя платформа выполняет анализ временной таблицы.
  • оператор получения данных из индекса заказа клиента (#8) использует условие поиска по индексу, только области данных, а нужно было бы по ссылке. Разделители не используются, поэтому таблица будет прочитана полностью, что не эффективно.
  • используется оператор соединения хешированием (#7), с условием по ссылке, хотя достаточно было соединения циклами. 

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

 

Заключение

 

Использование анализа длительных вызовов CALL, SCALL позволит вам выделить места в коде 1С, которые занимают достаточно много времени и заняться оптимизацией подобных участков кода. Используйте подобные замеры в дополнении к контролю длительных запросов.

См. также

HighLoad оптимизация Программист Платформа 1С v8.3 Конфигурации 1cv8 Бесплатно (free)

Анализ простого плана запроса. Оптимизация нагрузки на ЦП сервера СУБД используя типовые индексы.

13.03.2024    4256    spyke    28    

48

HighLoad оптимизация Инструменты администратора БД Системный администратор Программист Платформа 1С v8.3 Конфигурации 1cv8 Абонемент ($m)

Обработка для простого и удобного анализа настроек, нагрузки и проблем с SQL сервером с упором на использование оного для 1С. Анализ текущих запросов на sql, ожиданий, конвертация запроса в 1С и рекомендации, где может тормозить.

2 стартмани

15.02.2024    10162    206    ZAOSTG    74    

110

HighLoad оптимизация Программист Платформа 1С v8.3 Конфигурации 1cv8 Абонемент ($m)

Встал вопрос: как быстро удалить строки из ТЗ? Рассмотрел пять вариантов реализации этой задачи. Сравнил их друг с другом на разных объёмах данных с разным процентом удаляемых строк. Также сравнил с выгрузкой с отбором по структуре.

09.01.2024    9260    doom2good    49    

70

HighLoad оптимизация Системный администратор Программист Бесплатно (free)

При переводе типовой конфигурации 1C ERP/УТ/КА на PostgreSQL придется вложить ресурсы в доработку и оптимизацию запросов. Расскажем, на что обратить внимание при потерях производительности и какие инструменты/подходы помогут расследовать проблемы после перехода.

20.11.2023    11207    ivanov660    6    

80

HighLoad оптимизация Бесплатно (free)

Казалось бы, КОРП-системы должны быть устойчивы, быстры и надёжны. Но, работая в рамках РКЛ, мы видим немного другую картину. Об основных болевых точках КОРП-систем и подходах к их решению пойдет речь в статье.

15.11.2023    6146    a.doroshkevich    22    

74

Мониторинг Журнал регистрации Технологический журнал Системный администратор Программист Абонемент ($m)

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

1 стартмани

13.11.2023    3890    9    AlexSTAL    0    

47

HighLoad оптимизация Запросы

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

11.10.2023    17765    skovpin_sa    14    

102
Комментарии
Подписаться на ответы Инфостарт бот Сортировка: Древо развёрнутое
Свернуть все
1. пользователь 24.06.24 15:52
Сообщение было скрыто модератором.
...
2. SerVer1C 785 24.06.24 17:28 Сейчас в теме
Гуд! Только вы как-то конец статьи оборвали. Хотелось бы узнать, на какой код переписали и какой прирост скорости получили.
3. rozer 309 24.06.24 20:47 Сейчас в теме
(2) на Выразить ..вероятно)
user1326593; +1 1 Ответить
7. ivanov660 4544 25.06.24 09:17 Сейчас в теме
(3)
1. Зачем-то минус влепили, надо просто пояснить почему выразить не подойдет.
2. Выразить помогает в том случае, когда нам требуется приведение значения составного типа к одному или нескольким типам из множества. Например, всего 20 типов в составном поле, а среди них нам нужен только заказ клиента. А в данном случае дата, номер и дата согласования нам требуются от всех типов, которые входят в состав. Поэтому операция выразить не поможет.
METAL; cleaner_it; rozer; +3 Ответить
5. ivanov660 4544 25.06.24 08:54 Сейчас в теме
(2)
1. Оптимизировали, время сократилось, как и должно до мс
2. Как ниже написали вынесли во временную таблицу, немного переиграли получение через точку, чуть позже добавлю
4. gzharkoj 512 24.06.24 21:29 Сейчас в теме
(2) Подзапрос вытащить во временную таблицу, начать с этого, дальше явно самому соединять с нужными таблицами.

Также предположу, что если явно внести условие в подзапрос на ограничение Заказов клиента вида
Где Товары.ЗаказКлиента в (&Заказы), то планировщик сообразит что к чему, с номенклатурой так же.

Интересно проверить, если отключить RLS, планировщик так же будет сканировать весь индекс заказа клиента в исходном запросе? по идее время на анализ высвободится и, возможно, планировщик сможет что-то адекватное предложить
ivanov660; +1 Ответить
6. ivanov660 4544 25.06.24 08:57 Сейчас в теме
(4)
1. Да, будет. RLS накладывается на каждую строку таблицы источника, а остальные проблемные части запроса особо не меняются. Фактически именно из-за RLS и получается такое время.
2. Вариант с дополнительным условием на заказы клиента, хорошее предложение. Попробую напишу.
8. пользователь 25.06.24 20:21
Сообщение было скрыто модератором.
...
9. DoctorRoza 25.06.24 21:36 Сейчас в теме
Чтобы найти топ медленных запросов, ТЖ совсем необязателен. Достаточно запрос а pg_admin написать ко внутренним таблицам. Также, подойдёт и обычный замер производительности подключить.
5000000 - это 500 сек
10. pavlov_ss 28.06.24 08:36 Сейчас в теме
Подскажите, а обновление проекта на гитхабе планируется? Я о https://github.com/Polyplastic/1c-parsing-tech-log
На гите подписан на обновления, а статью на инфостарте мог пропустить, отсюда и вопрос.
11. paulwist 02.07.24 12:02 Сейчас в теме
используется оператор соединения хешированием (#7), с условием по ссылке, хотя достаточно было соединения циклами.


Ммм, на основании "чего" сделан такой вывод, какой выигрыш будет в base-cost при сканировании циклами??
13. ivanov660 4544 12.07.24 03:57 Сейчас в теме
(11) Исходя из логики использования операторов. Соединения циклами используется при маленьком количестве выбранных строк, что в данном случае фактически и есть при выполнении.
12. avk_avk 11.07.24 15:05 Сейчас в теме
В статье упустили настройку SCALL и его смысл.
Оставьте свое сообщение