В погоне за APDEX-ом, или как создать HighLoad на недорогом серверном железе

В прошлом году компания 1С реализовала свой собственный тест, имитирующий одновременную работу 30 000 пользователей в «1С:ERP Управление предприятием», в рамках которого осуществляется моделирование работы ключевых пользователей ERP, таких как диспетчеры производства, менеджеры по закупкам и продажам, кладовщики, бухгалтеры.

В прошлом году вместе с коллегами из компании ИТ-Экспертиза мы решили повторить данное тестирование, используя в качестве СУБД Postgres Pro Enterprise. 

Что из себя представляет тест

Тестирование выполняется с применением инструмента «Тест-Центр», входящего в состав «1С:Корпоративный инструментальный пакет». 

В рамках теста моделируется работа 30 000 пользователей, распределённых по 15 функциональным сценариям, охватывающим ключевые процессы системы 1C:ERP. Основную нагрузку формируют массовые операционные сценарии: продажи, закупки, склад, производство, взаиморасчёты и бухгалтерский учёт. Дополнительно моделируются менее массовые, но ресурсоёмкие процессы: различные виды планирования, регламентированная отчётность (НДС), бюджетирование. Длительность теста составляет порядка 11 часов и проводится на реалистичной базе данных, итоговый объём которой составляет около 1 Тб. База данных распространяется компанией 1С в виде файла выгрузки информационной базы в формате .dt (~31 Гб), который доступен по запросу. Нам его предоставили коллеги из «ИТ-Экспертизы».

По итогам нагрузочного тестирования на основе времени выполнения ключевых операций рассчитывается показатель APDEX (Application Performance Index), по которому определяется, был ли тест успешным.

Если в двух словах, то APDEX — это международный стандарт оценки производительности информационных систем, который рассчитывается как отношение количества удовлетворительных откликов к общему числу операций с учётом весов: быстрые операции (в пределах целевого времени) учитываются полностью, допустимые (до четырёхкратного превышения целевого времени) — с коэффициентом 0,5, а медленные не учитываются. Формула расчёта имеет вид:

где

• NS — количество быстрых операций;

• NT — количество допустимых операций;

• N — общее число операций.

Для прохождения теста, APDEX 0,85 и выше считается хорошим результатом (https://its.1c.ru/db/metod8dev/content/5807/hdoc): при таком значении оценки значительная часть операций выполняется в пределах целевого времени, и лишь некоторая часть попадает в допустимый диапазон задержек, не оказывая заметного влияния на общее восприятие производительности системы.

Результаты теста от самой 1С: APDEX равный 0.858, полученный на собственной сборке PostgreSQL 16.4−49.1C ( https://v8.1c.ru/metod/article/firma-1s-uspeshno-provela-nagruzochnoe-testirovanie-1s-erp-upravlenie-predpriyatiem-na-30-000-polzovateley.htm ). Допускаем, что в рамках теста 1С:ERP целевые времяена ключевых бизнес-операций заданоы достаточно честным образом, поскольку даже небольшое количество неидеальных операций снижает итоговый индекс и не позволяет легко приблизиться к APDEX = 1. 

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

Подготовка стенда 

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

• сервер приложений 1С;

• сервер СУБД;

• нагрузочная станция (терминальный сервер).

Начинаем потрошить нашу лабу. С серверами приложений «1С:Предприятие» и сервером СУБД всё получилось довольно просто. Кластер серверов приложений 1С состоял из трёх физических железок, под каждую из машин мы нашли и выделили отдельные bare-metal-серверы на базе процессоров Intel Xeon Gold 6338 третьего поколения. Не самые новые и топовые процессоры (базовая частота — 2.0 ГГц и пиковая — 3.2 ГГц), зато все одинаковые. Сервер с PostgreSQL использовал аналогичное железо, разве что оперативной памяти на нём было побольше. 

Ввиду того что проведение теста невозможно без клиентских и серверных лицензий для самого 1С, для их размещения нужен отдельный сервер лицензирования. Но больших мощностей для него не требуется: нам с большим запасом хватило виртуальной машины с 4 vCPU и 8GB RAM. 

Таким образом, конфигурация получилась такой: 

А вот подобрать оборудование под терминальные сервера оказалось не так просто.

Во время нагрузочного теста основными источниками нагрузки выступают виртуальные рабочие места (ВРМ), создаваемые с помощью инструмента «Тест-центр». В процессе работы ВРМ формируют нагрузку как на кластер серверов приложений 1С, так и на сервер системы управления базами данных, по сути осуществляя открытие форм, заполнение документов и построение отчетов так, как это делают настоящие пользователи системы. 

ВРМ запускаются на терминальных серверах (они же «нагрузчики»). Принято считать, что один терминальный сервер может обеспечить стабильную работу около 200 ВРМ. Была и ещё одна рекомендация от коллег из «ИТ Экспертизы», которой мы придерживались: терминальный сервер с 10 CPU и 70 Гб RAM позволяет без проблем запустить ~170 ВРМ. Простая математика подсказывает, что для создания нагрузки в 30 000 пользователей нам должно хватить 180 небольших виртуалок — звучит как задача для нашего лаборатного кластера Proxmox. 

Учитывая большое число необходимых ядер (1800), мы задействовали почти все ноды нашего лабораторного кластера, состоящего из оборудования разных вендоров, а потому итоговый стенд получился весьма разношёрстным по характеристикам.

Большая часть состояла из серверов на базе уже далеко немолодого Intel(R) Xeon(R) Gold 5220R, с базовой частотой 2.20 ГГц, а также следующего поколения Intel(R) Xeon(R) Gold 6338, с базовой частотой  2.00 ГГц. Но было и два сервера с AMD-шными EPYC-ами на 198 ядер, и экзотика в виде Intel(R) Xeon(R) Gold 6348H с четырьмя сокетами.

Итоговая конфигурация оборудования для терминальных серверов выглядела следующим образом: 

Кроме виртуальных машин для нагрузчиков нам понадобятся вспомогательные ВМ для сервера с которого непосредственно запускается «Тест-Центр» и сервер мониторинга. 

Даже с учётом использования SMT (Simultaneous Multithreading), выдать всем виртуалкам по 10 vCPU поровну удалось не везде: некоторым нагрузчикам досталось только по 8 ядер. Забегая вперёд, даже несмотря на это и на различия в характеристиках серверов виртуализации и, как следствие, использование разных типов CPU у виртуальных машин, потребление ресурсов терминальными машинами не являлось узким местом в рамках данного тестирования.

Подготовка окружения

С железом определились, теперь поговорим про софтверную часть.

В качестве операционной системы мы везде использовали RED OS 8.0.2 (с ядром 6.12.56-1.red80.x86_64 на момент тестирования), как одну из рекомендуемых отечественных ОС, подходящих как для серверных, так и клиентских инсталляций 1С. На железных серверах приложений и СУБД использовалась ОС без графического режима, а на терминальных серверах было установлено графическое окружение Mate. Здесь же заметим, что для корректной работы теста, на терминальных серверах потребуется выставить русскую локаль ru_RU.UTF-8.

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

Первым шагом мы подготовили так называемый kickstart-файл для RED OS, который автоматизирует процесс установки и первичной конфигурации ОС. Kickstart позволяет автоматически развернуть систему, настроить дисковые разделы, сеть, установить необходимые пакеты, настроить пользователей и выполнить другие задачи конфигурации, не требующие вмешательства пользователя. 

Далее с помощью packer была выполнена автоматическая установка ОС в Proxmox с использованием kickstart-файла. В результате был сформирован эталонный шаблон (template) виртуальной машины, содержащий готовую базовую систему. 

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

При создании каждой виртуальной машины используется механизм cloud-init, который выполняет первичную настройку (hostname, сеть, ssh-ключи и базовые параметры системы). Финальная конфигурация и установка прикладного ПО выполняются с помощью Ansible, который обеспечивает точечную настройку и конфигурацию сервисов внутри уже запущенных виртуальных машин.

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

На сервера приложений мы установили технологическую платформу версии 8.3. Использовалась сборка 8.3.27.1786, содержащая все необходимые для успешного теста доработки. Данная сборка доступна для скачивания всем имеющим доступ к порталу https://releases.1c.ru. Грамотная настройка 1С-кластера является отдельной наукой, но к счастью, потребовалась единоразово. 

На сервере БД была развёрнута Postgres Pro Enterprise 17.7.1.

Перед тестами

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

• сбор и последующее удаление логов СУБД и 1С (технологический журнал);

• перезапуск всех сервисов и служб 1С;

• перезапуск терминальных серверов;

• восстановление БД из бэкапа, со всеми ранее применёнными настройками, с помощью ProBackup.

Также после восстановления БД из бэкапа требуется выполнить запуск регламентной задачи на «обновление доступа на уровне записей».  С первого запуска мы столкнулись с тем, что 1С обрывал её по таймауту в 900 секунд. Происходило это из-за слишком долгого выполнения запросов к регистрам, что приводило к тому, что 1С зависал на этой задаче бесконечно.

На скриншоте видно 5 регистров, которые никак не могли обработаться из-за долгих sql-запросов: 

При поднятии таймаута до 5 часов 1С операции всё-таки выполнял. На момент первых запусков мы махнули на это рукой, но решили эту проблему позже. 

Нагрузочные испытания 

Тест на 10 000 ВРМ

Начинаем наши замеры с пристрелочного запуска на 10 000 ВРМ и получаем итоговый APDEX 0.853. Неплохо, но могло быть и лучше. При этом на диске nvme1n1, на котором располагалась $PGDATA, во время всего теста наблюдалась очередь:

Поскольку дисков у нас было несколько, далее последовал самый очевидный шаг — уменьшить нагрузку в $PGDATA вынесением pg_wal на отдельный диск nvme2n1.

Заодно включаем опцию «—no-collect.database» для postgres_exporter, чтобы избавиться от чрезмерно большого кол-ва запросов «SELECT pg_database_size($1)» к нашей базе данных.

Тест на 20 000 ВРМ: разбираемся с дисками на СУБД 

Поднимаем число ВРМ до 20 000, перезапускаем тест и получаем APDEX 0.790 и более 800 невыполненных задач 1С.

Несмотря на вынос pg_wal, на диске с pg_data продолжали наблюдаться высокие задержки на запись на диск и очереди:

Первым делом решаем выполнить простую проверку — заглянуть в вывод команды «nvme list«. Пристальный взгляд показал, что все наши диски были отформатированы с размером логического блока (lbaf) 512 байт: 

[root@asusmicro27 ~]# nvme listNode                  Generic               SN                   Model                                    Namespace  Usage                      Format           FW Rev  --------------------- --------------------- -------------------- ---------------------------------------- ---------- -------------------------- ---------------- --------/dev/nvme0n1          /dev/ng0n1            S6VANN0X514555       SAMSUNG MZQL215THBLA-00A07               0x1         12.63  GB /  15.36  TB    512   B +  0 B   GDD5302Q/dev/nvme1n1          /dev/ng1n1            S6VANN0X605836       SAMSUNG MZQL215THBLA-00A07               0x1          1.97  GB /  15.36  TB    512   B +  0 B   GDD5302Q/dev/nvme2n1          /dev/ng2n1            S6VANN0X605833       SAMSUNG MZQL215THBLA-00A07               0x1          2.51  TB /  15.36  TB    512   B +  0 B   GDD5302Q/dev/nvme3n1          /dev/ng3n1            S6VANT0WB00560       SAMSUNG MZQL215THBLA-00A07               0x1         38.55  GB /  15.36  TB    512   B +  0 B   GDD5302Q

LBAF (Logical Block Address Format) — это формат логического блока, который используется NVMe-диском для адресации данных. Он определяет размер минимальной единицы ввода-вывода, с которой работает диск на логическом уровне. Современные NVMe-диски обычно поддерживают несколько LBA-форматов с разными размерами блока. Посмотреть их можно командой:

$ nvme id-ns -H /dev/nvme0n1 | grep LBA

Пример вывода:

LBA Format  0 : Metadata Size: 0 bytes - Data Size: 512 bytes - Relative Performance: 0 Best (in use)LBA Format  1 : Metadata Size: 0 bytes - Data Size: 4096 bytes - Relative Performance: 0 Best

В нашем случае видно, что используется LBAF = 0 с размером 512 B. Это значение по умолчанию применяется для обеспечения совместимости, хотя для нашей нагрузки 4K-блоки потенциально могут обеспечить более высокую эффективность за счёт снижения накладных расходов на операции ввода-вывода.

Форматируем все диски, кроме системного, под 4K-блоки (осторожно, все данные будут удалены):

$ nvme format /dev/nvme1n1 --lbaf 1 --ses=1$ nvme format /dev/nvme2n1 --lbaf 1 --ses=1$ nvme format /dev/nvme3n1 --lbaf 1 --ses=1

Кроме того, решаем задействовать последний свободный диск и под $PGDATA собрать raid0 под mdadm:

$ mdadm --create --verbose /dev/md0 --level=0 --raid-devices=2 --chunk=512K /dev/nvme1n1 /dev/nvme2n1$ mkfs.ext4 -b 4096 -O fast_commit -E stride=128,stripe-width=256 -L u02 /dev/md0$ mkfs.ext4 -b 4096 -O fast_commit -E stride=0,stripe-width=0 -L u03 /dev/nvme3n1

По результатам данного запуска обнаружилась и другая проблема: мониторинг загрузки ядер виртуалок с терминальными серверами показал, что у части машин некоторые ядра были недозагружены, а у других, наоборот, был сильный перегруз, всё это на одной и той же железной ноде Proxmox кластера. Дело оказалось вот в чём: для того чтобы гарантированно выделить физические ядра ноды гипервизора конкретному виртуальному серверу, мы привязывали виртуальные ядра к физическим. При этом ядра выделяются не последовательно, а в рамках одного numa-узла, что позволяет улучшить эффективность использования памяти. Поскольку виртуальных машин много и наши ресурсы не гомогенны, при первых запусках этот процесс был отлажен не до конца, а потому имела место ошибка: некоторые ВМ пересекались по аффинити ядер, например за двумя разными виртуалками были закреплены ядра 36–39, 88–91 и 40–43, 88–91. Получалось, что ядра 88–91 оказывались перегружены. Перед последующими запусками мы исправили эти ошибки.

Тест на 30 000 ВРМ — первый запуск. Разбираемся с временными объектами

Правки сделаны, сразу подаём целевую нагрузку в 30 000 ВРМ и спустя несколько часов работы сталкиваемся с 100%-й утилизацией CPU на сервере БД и зависанием серверов приложений 1С: запуск не прошёл, APDEX не посчитался. Очереди на дисках всё равно высокие. Смотрим подробнее: часть ВРМ у нас не запустились с ошибкой

«Отправитель: erp-thin37.

Следующие ВРМ не удалось инициализировать до истечения таймаута инициализации (1,500 с):

 — erp-thin37.0 (PID: 45245, сеанс: 52021); ОЦИР Реализация_ТЦ000033; ВРМ №783″

В логах серверов приложений 1С видим исключения вида: 

EXCP,4,level=ERROR,process=rphost,p:processName=erp30k,OSThread=1089368,t:clientID=1227,t:applicationName=1CV8C,t:computerName=erp-thin167,t:connectID=8391,SessionID=9633,Usr=ЦНТИБ Внутреннее потребление_ТЦ000030,AppID=1CV8C,DBMS=DBPOSTGRS,DataBase=database\erp30k,Exception=DatabaseException,Descr='The database connection is closed by the administratorConnection to server at "database" (10.7.0.174), port 5432 failed: timeout expired

Увы, сервер БД перестал отвечать серверу 1С, и тест упал. 

К счастью, в базе у нас были настроены pgpro_stats с pgpro_pwr и каждые пять минут создавался снимок метрик через функцию take_sample(). Исследуем pwr-отчёт за проблемный интервал: один из запросов обращающийся к служебным регистрам создавал 50% всей нагрузки, постоянно выполнял seq scan-ы по таблицам и висел в топе. Выглядит скорее как следствие проблем, а не причина. Смотрим дальше и замечаем, что мы забыли включить параметр enable_temp_memory_catalog, который позволяет для временных таблиц, индексов и других временных объектов использовать системный каталог в оперативной памяти, что снижает нагрузку на запись в отношения обычного системного каталога: pg_class, pg_attribute и некоторые другие. 

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

Был и ещё один полезный параметр, который мы добавили перед следующим запуском —  skip_temp_rel_lock. Он позволяет пропускать блокировки для временных отношений и индексов этих отношений. На профиле нагрузки от 1С это проявлялось в том, что во время вызова SQL функции fasttruncate (активно используется в коде 1С приложения для урезания временных таблиц) значительное время занимал вызов Си-функции LockRelationOid(), то есть создание блокировки на таблицы. Поэтому когда происходит активная работа с временными таблицами, включение параметра способно заметно повлиять на производительность.

Тест на 30 000 ВРМ — второй запуск

Делаем повторный запуск на 30 000 ВРМ. Несмотря на то что по итогу теста утилизация на сервер БД снизилась до 50%, а серверы приложений 1С и вовсе были загружены до 20% (терминалки — до 80%), APDEX мы получили всего лишь 0.731. Хорошо то, что первый запуск на 30 000 который завершился корректно. Плохо, что APDEX неудовлетворительный. 

Отмечаем, что в директорию pgsql_tmp постоянно записывались временные файлы, общий объём которых достигал порядка 2–3 ГБ. Это связано с особенностями работы PostgreSQL: при выполнении операций, таких как сортировка или агрегация больших объёмов данных, превышающих доступный объём памяти, система использует временные файлы на диске.

Решение есть — выносим данный каталог на tmpfs:

tmp_sql on /u02/data/base/pgsql_tmp type tmpfs (rw,relatime,size=104857600k,inode64)

Делаем перезапуск и получаем APDEX = 0.744. Продолжаем вносить изменения: 

• Ещё немного разгружаем наши диски. Мы вынесли временные файлы на RAM диск, но не вынесли временные таблицы. Поэтому создаём и выносим на tmpfs каталог, в котором будут создаваться временные таблицы и их индексы. Делается это путём указания табличного пространства, созданного в tmpfs (см. temp_tablespace) 

• Включаем опцию enable_background_freezer. При частом создании и удалении большого количества временных таблиц autovacuum может не успевать очищать данные системных таблиц, что приводит к их распуханию (bloating). Background freezer очищает удалённые записи на страницах в памяти и «разрастание» системных таблиц существенно уменьшается

Каждое изменение улучшало и APDEX и утилизацию CPU и IO.

Тест на 30 000 ВРМ — последующие запуски. Тюним СУБД

После последних правок утилизация CPU на сервере БД не превышала 40% большую часть теста: 

Также очередь на диски не превышала 20, до этого пики были до 100-500: 

Утилизация серверов приложений 1С тоже была на невысоком уровне: 

И всё же APDEX снова меньше необходимого — 0.767.

Тут самое время вспомнить о проблеме с перерасчётом прав доступа, о которой мы говорили ранее. 

Устав ждать лишние пять часов перед каждым пересчётом, мы придумали workaround — создавать дополнительные индексы для тормозящих запросов перед выполнением перерасчёта (а тормозящих запросов было 5 штук). Пять свежесозданных индексов для пяти запросов перерасчёта решают проблему, однако способ этот не совсем легальный: право создавать индексы в базе 1С имеет только сам 1С. И поскольку менять мы можем только свой код и настройки базы, начинаем разбираться предметно. Как оказалось, нужная комбинация значений work_mem + hash_mem_multiplier может превратить correlated query, присоединяемый по (not) exists в связке с OR, в hash table в памяти, после чего сложность проверки условия заметно снижается.

Для проблемных запросов со значением параметра hash_mem_multiplier = 2 необходимый объём памяти для получения хорошего запроса составил следующие значения (в скобках — объём work_mem, где план неоптимальный):

• Query 1 work_mem = 183MB (182)

• Query 2 work_mem = 256MB (240)

• Query 3 work_mem = 150MB (140)

• Query 4 work_mem = 150MB (140)

• Query 5 work_mem = 160MB (150)

Оптимальный план содержит в себе предикаты hashed SubPlan, тогда как в неоптимальном плане такого нет:

Limit  (cost=80086.42..790621738.62 rows=10000 width=171) (actual time=3095.094..3095.098 rows=0 loops=1)   Buffers: shared hit=52383 read=111367   I/O Timings: shared read=438.879   ->  Incremental Sort  (cost=80086.42..9003321800.85 rows=113887 width=171) (actual time=3095.092..3095.096 rows=0 loops=1)         Sort Key: t1._fld127378, t1._fld127379_type, t1._fld127379_rtref, t1._fld127379_rrref, t1._fld127380_type, t1._fld127380_rtref, t1._fld127380_rrref, t1._fld127381_type, t1._fld127381_rtref, t1._fld127381_rrref, t1._fld127382_type, t1._fld127382_rtref, t1._fld127382_rrref, t1._fld127383_type, t1._fld127383_rtref, t1._fld127383_rrref         Presorted Key: t1._fld127378, t1._fld127379_type, t1._fld127379_rtref, t1._fld127379_rrref, t1._fld127380_type, t1._fld127380_rtref, t1._fld127380_rrref, t1._fld127381_type, t1._fld127381_rtref, t1._fld127381_rrref, t1._fld127382_type, t1._fld127382_rtref         Full-sort Groups: 1  Sort Method: quicksort  Average Memory: 25kB  Peak Memory: 25kB         Buffers: shared hit=52383 read=111367         I/O Timings: shared read=438.879         ->  Result  (cost=0.69..9003308295.67 rows=113887 width=171) (actual time=3095.082..3095.086 rows=0 loops=1)               One-Time Filter: (ANY (SubPlan 3).col1)               Buffers: shared hit=52383 read=111367               I/O Timings: shared read=438.879               ->  Index Scan using _inforg127376_1 on _inforg127376 t1  (cost=0.69..9003308010.95 rows=113887 width=170) (actual time=3095.076..3095.077 rows=0 loops=1)                     Index Cond: ((_fld1551 = '0'::numeric) AND (_fld127377_type = '\\x08'::bytea) AND (_fld127377_rtref = '\\x000000a4'::bytea) AND (_fld127377_rrref = '\\xa7a9000d884fd00d11e4c17ff00e69af'::bytea))                     Filter: ((_fld127379_type >= '\\x01'::bytea) AND (NOT CASE WHEN (_fld127378 = '0'::numeric) THEN false ELSE CASE WHEN ((_fld127378 - ((((((_fld127378)::numeric(12,8) / '2'::numeric))::numeric(12,8) - 0.5))::numeric(15,0) * '2'::numeric)) = '1'::numeric) THEN true ELSE false END END) AND ((_fld127379_type >= '\\x01'::bytea) OR ((_fld127379_type = '\\x01'::bytea) AND (_fld127379_rtref = '\\x00000000'::bytea) AND (_fld127379_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127380_type >= '\\x01'::bytea)) OR ((_fld127379_type = '\\x01'::bytea) AND (_fld127379_rtref = '\\x00000000'::bytea) AND (_fld127379_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127380_type = '\\x01'::bytea) AND (_fld127380_rtref = '\\x00000000'::bytea) AND (_fld127380_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127381_type >= '\\x01'::bytea)) OR ((_fld127379_type = '\\x01'::bytea) AND (_fld127379_rtref = '\\x00000000'::bytea) AND (_fld127379_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127380_type = '\\x01'::bytea) AND (_fld127380_rtref = '\\x00000000'::bytea) AND (_fld127380_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127381_type = '\\x01'::bytea) AND (_fld127381_rtref = '\\x00000000'::bytea) AND (_fld127381_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127382_type >= '\\x01'::bytea)) OR ((_fld127379_type = '\\x01'::bytea) AND (_fld127379_rtref = '\\x00000000'::bytea) AND (_fld127379_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127380_type = '\\x01'::bytea) AND (_fld127380_rtref = '\\x00000000'::bytea) AND (_fld127380_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127381_type = '\\x01'::bytea) AND (_fld127381_rtref = '\\x00000000'::bytea) AND (_fld127381_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127382_type = '\\x01'::bytea) AND (_fld127382_rtref = '\\x00000000'::bytea) AND (_fld127382_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127383_type >= '\\x01'::bytea))) AND ((_fld127378 <> '4'::numeric) OR ((_fld127378 = '4'::numeric) AND (NOT (ANY ((_fld127379_type = (hashed SubPlan 2).col1) AND (_fld127379_rtref = (hashed SubPlan 2).col2) AND (_fld127379_rrref = (hashed SubPlan 2).col3) AND (_fld127380_type = (hashed SubPlan 2).col4) AND (_fld127380_rtref = (hashed SubPlan 2).col5) AND (_fld127380_rrref = (hashed SubPlan 2).col6)))))))                     Rows Removed by Filter: 384644                     Buffers: shared hit=52383 read=111367                     I/O Timings: shared read=438.879                     SubPlan 2                       ->  Seq Scan on _accumrg36802 t2  (cost=0.00..171017.98 rows=2624798 width=168) (actual time=0.228..1383.270 rows=2624798 loops=1)                             Filter: (_fld1551 = '0'::numeric)                             Buffers: shared hit=44489 read=93719                             I/O Timings: shared read=339.306               SubPlan 3                 ->  Materialize  (cost=0.00..0.37 rows=21 width=1) (actual time=0.004..0.004 rows=1 loops=1)                       ->  Values Scan on "*VALUES*"  (cost=0.00..0.26 rows=21 width=1) (actual time=0.001..0.001 rows=1 loops=1) Planning Time: 0.698 ms Execution Time: 3100.215 ms

План того же запроса, если памяти недостаточно:

 Limit  (cost=80086.42..790621738.62 rows=10000 width=171)   ->  Incremental Sort  (cost=80086.42..9003321800.85 rows=113887 width=171)         Sort Key: t1._fld127378, t1._fld127379_type, t1._fld127379_rtref, t1._fld127379_rrref, t1._fld127380_type, t1._fld127380_rtref, t1._fld127380_rrref, t1._fld127381_type, t1._fld127381_rtref, t1._fld127381_rrref, t1._fld127382_type, t1._fld127382_rtref, t1._fld127382_rrref, t1._fld127383_type, t1._fld127383_rtref, t1._fld127383_rrref         Presorted Key: t1._fld127378, t1._fld127379_type, t1._fld127379_rtref, t1._fld127379_rrref, t1._fld127380_type, t1._fld127380_rtref, t1._fld127380_rrref, t1._fld127381_type, t1._fld127381_rtref, t1._fld127381_rrref, t1._fld127382_type, t1._fld127382_rtref         ->  Result  (cost=0.69..9003308295.67 rows=113887 width=171)               One-Time Filter: (ANY (SubPlan 2).col1)               ->  Index Scan using _inforg127376_1 on _inforg127376 t1  (cost=0.69..9003308010.95 rows=113887 width=170)                     Index Cond: ((_fld1551 = '0'::numeric) AND (_fld127377_type = '\\x08'::bytea) AND (_fld127377_rtref = '\\x000000a4'::bytea) AND (_fld127377_rrref = '\\xa7a9000d884fd00d11e4c17ff00e69af'::bytea))                     Filter: ((_fld127379_type >= '\\x01'::bytea) AND (NOT CASE WHEN (_fld127378 = '0'::numeric) THEN false ELSE CASE WHEN ((_fld127378 - ((((((_fld127378)::numeric(12,8) / '2'::numeric))::numeric(12,8) - 0.5))::numeric(15,0) * '2'::numeric)) = '1'::numeric) THEN true ELSE false END END) AND ((_fld127379_type >= '\\x01'::bytea) OR ((_fld127379_type = '\\x01'::bytea) AND (_fld127379_rtref = '\\x00000000'::bytea) AND (_fld127379_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127380_type >= '\\x01'::bytea)) OR ((_fld127379_type = '\\x01'::bytea) AND (_fld127379_rtref = '\\x00000000'::bytea) AND (_fld127379_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127380_type = '\\x01'::bytea) AND (_fld127380_rtref = '\\x00000000'::bytea) AND (_fld127380_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127381_type >= '\\x01'::bytea)) OR ((_fld127379_type = '\\x01'::bytea) AND (_fld127379_rtref = '\\x00000000'::bytea) AND (_fld127379_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127380_type = '\\x01'::bytea) AND (_fld127380_rtref = '\\x00000000'::bytea) AND (_fld127380_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127381_type = '\\x01'::bytea) AND (_fld127381_rtref = '\\x00000000'::bytea) AND (_fld127381_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127382_type >= '\\x01'::bytea)) OR ((_fld127379_type = '\\x01'::bytea) AND (_fld127379_rtref = '\\x00000000'::bytea) AND (_fld127379_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127380_type = '\\x01'::bytea) AND (_fld127380_rtref = '\\x00000000'::bytea) AND (_fld127380_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127381_type = '\\x01'::bytea) AND (_fld127381_rtref = '\\x00000000'::bytea) AND (_fld127381_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127382_type = '\\x01'::bytea) AND (_fld127382_rtref = '\\x00000000'::bytea) AND (_fld127382_rrref = '\\x00000000000000000000000000000000'::bytea) AND (_fld127383_type >= '\\x01'::bytea))) AND ((_fld127378 <> '4'::numeric) OR ((_fld127378 = '4'::numeric) AND (NOT EXISTS(SubPlan 1)))))                     SubPlan 1                       ->  Result  (cost=0.56..23820.56 rows=1 width=0)                             One-Time Filter: (('\\x08'::bytea = t1._fld127379_type) AND ('\\x000000e6'::bytea = t1._fld127379_rtref) AND ('\\x08'::bytea = t1._fld127380_type) AND ('\\x000001dd'::bytea = t1._fld127380_rtref))                             ->  Index Scan using _accumrg36802_3 on _accumrg36802 t2  (cost=0.56..23820.56 rows=1 width=0)                                   Index Cond: ((_fld1551 = '0'::numeric) AND (_fld36803rref = t1._fld127379_rrref))                                   Filter: (_fld36804rref = t1._fld127380_rrref)               SubPlan 2                 ->  Materialize  (cost=0.00..0.37 rows=21 width=1)                       ->  Values Scan on "*VALUES*"  (cost=0.00..0.26 rows=21 width=1)

Таким образом решаем перед следующим запуском теста выставить с запасом:

• hash_mem_multiplier=4

• work_mem=256MB

А заодно поправить: 

• from_collapse_limit=20 

• join_collapse_limit=20

• effective_io_concurrency=1

Также мы составили Top самых долгих запросов, наблюдаемых при тестировании,  собранных из технологического журнала 1С и сопоставленных с операциями в 1С. Некоторые из них мы смогли поправить точечными настройками: так, например при выполнении теста операция печать формы МБ-8 из документа «Списание из эксплуатации» выполнялась под нагрузкой в среднем более 10 минут, вместо ожидаемых 2–3 секунд, а потому операция сильно вылезала за пределы целевого  времени и в зачёт APDEX по ней шёл 0. Воспроизводим проблему и получаем план выполнения соответствующего запроса в базе с помощью модуля auto_explain. 

Оказалось, что в одной из колонок (_value_rrref) очень неравномерное распределение значений: много редких и немного очень частых.

select cnt2, count (*), sum (count (*)) over (order by cnt2 range between current row and unbounded following) running_total,       round (100 * count (*) / sum (count (*)) over (), 2) rate  from (select _value_rrref, power(2, trunc(log(2, count (*))))::bigint cnt2          from test_AccRgED1632 group by _value_rrref) group by cnt2 order by cnt2;  cnt2   |  count  | running_total | rate  ---------+---------+---------------+-------       1 |  159218 |       3650382 |  4.36       2 | 1153795 |       3491164 | 31.61       4 | 1058374 |       2337369 | 28.99       8 |  637616 |       1278995 | 17.47      16 |  315185 |        641379 |  8.63      32 |  225637 |        326194 |  6.18      64 |   50144 |        100557 |  1.37     128 |   14245 |         50413 |  0.39     256 |   19446 |         36168 |  0.53     512 |    9912 |         16722 |  0.27    1024 |    1966 |          6810 |  0.05    2048 |    2155 |          4844 |  0.06    4096 |     373 |          2689 |  0.01    8192 |    1302 |          2316 |  0.04   16384 |     585 |          1014 |  0.02   32768 |     396 |           429 |  0.01   65536 |      12 |            33 |  0.00  131072 |       6 |            21 |  0.00  262144 |       7 |            15 |  0.00  524288 |       2 |             8 |  0.00 1048576 |       3 |             6 |  0.00 4194304 |       3 |             3 |  0.00(22 rows)

При стандартном default_target_statistics=100 PostgreSQL хранит слишком грубую статистику, а потому планировщик сильно ошибался в оценках селективности и  выбирал неоптимальный план: 

Insert on ttt  (cost=127.08..127.13 rows=0 width=0) (actual time=194421.376..194421.390 rows=0 loops=1)   Buffers: shared hit=13328056 read=12, local hit=5 Planning:   Buffers: shared hit=889 Planning Time: 61.241 ms Execution Time: 194423.395 ms

Как итог — запрос выполнялся катастрофически долго и читал десятки миллионов буферов. Увеличиваем точность статистики для проблемной колонки и делаем ANALYZE:

erp30k=# alter table _accrged1632 alter column _value_rrref set statistics 1000;ALTER TABLEerp30k=# analyze (verbose) _accrged1632;ИНФОРМАЦИЯ:  анализируется "public._accrged1632"ИНФОРМАЦИЯ:  "_accrged1632": просканировано страниц: 300000 из 2403324, они содержат "живых" строк: 17850934, "мёртвых" строк: 0; строк в выборке: 300000, примерное общее число строк: 143005260ANALYZE

В результате получаем больше значений в MCV (most common values) и адекватный план: 

Insert on ttt  (cost=74.28..75.63 rows=0 width=0) (actual time=126.198..126.207 rows=0 loops=1)   Buffers: shared hit=4384, local hit=5... Planning:   Buffers: shared hit=2 Planning Time: 45.781 ms Execution Time: 126.502 ms

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

Финальный запуск (но это неточно)

Ещё несколько тестовых запусков с внесёнными изменениями не привели к ощутимому повышению APDEX.

Чтобы ускорить получение результата, мы решили снизить длительность теста с 11 часов до 3, но получили рост утилизации CPU на СУБД до 100% CPU и зависание сервера 1С. Судя по отчётам pg_profile, уменьшение времени теста до двух часов привело к резкому росту интенсивности запросов (по части операций возросло количество вызовов в секунду) по сравнению со стандартным 11-часовым тестом. Изучив код самих сценариев, стало понятно, что такой подход с данным тестом не работает. Зависимость интенсивности выполнения от таймаута теста была нелинейной и просто уменьшить параметр «интенсивность» и получить менее интенсивное выполнение задач оказалось невозможно.

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

В какой-то момент на самом сервере СУБД мы развернули  сервис, который периодически выполнял запрос «SELECT * FROM config LIMIT 100», обращаясь к базе через  unix socket, и замерял время и исполнение. По логу видно, что порой время исполнения сильно варьируются:

[18:18:01] Query executed in 3589 µs[18:18:04] Query executed in 264955 µs[18:18:07] Query executed in 3662 µs[18:18:10] Query executed in 214534 µs[18:18:13] Query executed in 4237 µs

Такой огромный разброс при выполнении простого запроса вкупе с ещё одним наблюдением — довольно частых LWLock-ах pgpro_stats в pg_stat_activity — сподвигли нас убрать pgpro_stats из shared_preload_libraries перед следующими замерами. Как известно, в любом расследовании главное — не выйти на самих себя 🙂 Правда, подобные ожидания также наблюдались и при замене pgro_stats на pg_stat_statements. В ближайших релизах мы планируем внести правки, снижающие влияние сбора статистики на производительность. 

Также, несмотря на невысокую утилизацию процессора СУБД при последних запусках, обнаруживаем, что процессор по ходу нагрузки фактически спал, находясь в глубоком режиме энергосбережения (С6). Взаимодействия с С-состояниями linux осуществляет с помощью драйверов: acpi_idle (берёт настройки состояний из BIOS) и intel_idle (современная реализация Intel). Узнать какой драйвер используется в системе можно в файле /sys/devices/system/cpu/cpuidle/current_driver

В нашем случае использовался драйвер intel_idle, а настройки были сделаны для acpi_idle и потому не оказывали нужного влияния. Правим /etc/default/grub: добавляем в параметр загрузчика ядра опцию intel_idle.max_cstate=1, ограничивая максимальное C-состояние до C1, снижая задержки выхода процессора из состояния простоя.

И поскольку ранее мы уже видели, что утилизация CPU не является боттлнеком, вдобавок решаем разместить СУБД на одном процессоре (ведь утилизация CPU очень низкая), чтобы снизить кросс-NUMA взаимодействие CPU и памяти.

Итак, делаем запуск со всеми ранее примененными настройками:

• from_collapse_limit=20

• join_collapse_limit=20

• hash_mem_multiplier=4

• work_mem=256MB

• effective_io_concurrency=1

• auto_explain.log_min_duration = ’60s’

• shared_preload_libraries = ‘pg_wait_sampling,pg_query_state,auto_explain’

• skip_temp_rel_lock=on

• enable_temp_memory_catalog = on

• enable_background_freezer = on

psql_tmp вынесены на tmpfs:

• tmp_sql on /u02/data/base/pgsql_tmp type tmpfs (rw,relatime,size=104857600k,inode64)

поправлена статистика для столбца: 

• alter table _accrged1632 alter column _value_rrref set statistics 1000;
  analyze (verbose) _accrged1632;

из shared_preload_libraries убраны pgpro_stats и pg_stat_statements

Ура! На этот раз APDEX составил 0.856. А это значит, что совокупность всех внесённых изменений позволила нам достичь общей производительности ключевых бизнес-операций по итогам нагрузочного теста на уровне «Хорошо». Оборудование тоже показало себя с лучшей стороны. Утилизация СУБД с Postgres Pro Enterprise 17.7.1 в ходе теста не превышала 30%:

Время отклика дисков на чтение находилось в пределах 1 мс, на запись — в среднем не превышало 2,5 мс: 

Серверы приложений 1С также чувствовали себя хорошо: каждый из трёх серверов в среднем был загружен на 20%: 

Время отклика дисков на запись в период выполнения теста находилось в пределах 10 мс:

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

Выводы

Не будем скрывать, что тестирование 1C:ERP доставило нам немало хлопот, начиная с подготовки и развёртывания окружений (не каждый день приходится создавать 180 виртуалок в Proxmox-е) и заканчивая тюнингом параметров операционной системы и самого PostgreSQL. Тем приятнее оказался конечный результат: Postgres Pro Enterprise 17.7.1 не только продемонстрировал уверенную работу на типовом оборудовании на базе процессоров Intel Xeon Gold второго и третьего поколений с частотой 2.0–2.2 ГГц, но и обеспечил стабильную производительность под нагрузкой, характерной для промышленной эксплуатации ERP-систем. 

Хотя и не сразу, но нам удалось подобрать оптимальный набор параметров конфигурации PostgreSQL, учитывающих специфику 1С. Эти настройки уже находят своё применение в нашей утилите pgpro_tune и доступны для применения через пресет “1c.tune”. Уверены, что и особенности настройки ОС и аппаратных компонентов, с которыми мы столкнулись в данном нагрузочном тестировании, также будут полезны сообществу.

От начала работ до финального запуска прошло чуть более трёх месяцев. За это время было:

• выпито немало кофе нашей командой в нескольких часов поясах

• сделан 31 запуск теста 1С ERP 30K или 14 дней (341 часов) общего времени или 400 тысяч процессорных ядер-часов

• создана автоматизация тестирования 1С позволяющая запускать тесты по нажатию на одну кнопку

Несмотря на то, что полученный результат по показателю APDEX удовлетворяет критериям самой компании 1С, тестирование выявило ряд областей, требующих дальнейших улучшений и оставляющих пространство для оптимизации. А поэтому, работа в этом направлении продолжается: сейчас мы проводим тестирование альтернативного ERP-теста от компании «ИТ-Экспертиза», профиль нагрузки которого является ещё более разнообразным и интенсивным. О полученных результатах мы с радостью расскажем в следующих материалах.

Прошло пара месяцев… И снова запуск

Итак, тестирование прошло успешно и про тест на некоторое время забыли. В недавнем выпуске Postgres Pro Enterprise 17.9 добавилось несколько улучшений, связанных с производительностью временных таблиц: Замечания к релизу Postgres Pro Enterprise 17.9.1

Снова запускаем тест. В этот раз подготовка к запуску занимает меньше суток, что не может не радовать. Благодаря упомянутым улучшениям, APDEX стал 0.875 (был 0.856). При этом утилизация CPU также на том уровне около 20%. На графике ниже можно увидеть, что среднее время самых частных операций уменьшилось примерно на одинаковую величину:

Хочется отметить, что тест запускался и запускается на типовом оборудовании. Насколько известно, большинство продуктовых окружений использует виртуализацию, поэтому в ближайшие недели запланирована миграция стенда с bare-metal на виртуализацию. Как говорится: «Но это уже совсем другая статья».