N+1 в коде: ищем запросы в циклах с помощью графа вызовов

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

Черновик этой статьи был методикой без единого запуска. Я собрала стенд на платформе 1С, запустила на нём все примеры кода, измерила время и число запросов к PostgreSQL и написала анализатор, который находит такие места по графу вызовов. Главное из замера на клиент-серверной базе: цикл по 3000 документам, читающий реквизит ссылки, выполнил около 3003 запросов к PostgreSQL и занял 5,43 с. Тот же результат одним запросом получился за 0,16 с. Все цифры получены на старом компьютере 2011 года, подробности в разделе про железо. Миллисекунды из статьи на свою систему переносить нельзя, число запросов определяется кодом.

💻 Железо стенда

Все замеры сделаны на скромном рабочем компьютере. Клиент, кластер 1С и PostgreSQL работают на нём одновременно, сеть между рабочим процессом 1С и СУБД не участвует.

Во время замера параллельно работали Docker Desktop, браузер и приложение ЭПД-Клиент сервиса nopikreport.com. Это мой рабочий компьютер, выделенный стенд в этом эксперименте не участвует. Для читателя из этого следует одно: абсолютные времена в таблицах относятся к "хилому" железу. На современном процессоре и с сетью между сервером приложений и СУБД они будут другими, а сетевой обмен на каждый запрос в схеме N+1 добавит свою долю. Число запросов от скорости компьютера не зависит, но проверено только на этой версии платформы.

🧪 Как устроен стенд

Конфигурация собрана из выгрузки в файлы: справочник Контрагенты, документ РеализацияТоваров с реквизитами Контрагент (ссылка на справочник), Статус (строка) и Сумма (число), два общих модуля. В базе 300 контрагентов и 3000 документов, у каждого третьего документа статус «Черновик». Загрузка конфигурации и проверка модулей идут из Конфигуратора, ответ платформы:

Обновление конфигурации успешно завершено
Синтаксических ошибок не обнаружено!

Стенд собран в двух вариантах: файловая база и клиент-серверная база на кластере 1С с PostgreSQL в контейнере. Подключение к обеим идёт через внешнее соединение (COM) из 32-битного PowerShell. Это не вызов серверного кода из тонкого клиента, поэтому на продуктивном контуре времена могут отличаться.

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

Число запросов на клиент-серверной базе берётся из pg_stat_statements контейнера: сумма вызовов по базе до и после замера. Подготовка аргумента (получение ссылок и для варианта СуммаПоОбъектам загрузка объектов) считается отдельным прогоном на тех же данных и вычитается из общего счёта. Счётчик шумит на единицы запросов из-за служебных обращений платформы: значение 3003 вместо 3000 ничего не значит. Медиана -1 у варианта с объектами читается как ноль.

📊 Что показал замер

Клиент-серверная база (PostgreSQL в Docker), время в миллисекундах и число запросов к PostgreSQL:

Файловая база, время в миллисекундах:

Что видно по таблицам.

• Число запросов равно числу документов. СуммаВТелеЦикла на 500, 1000 и 3000 документах выполнил около 501, 1001 и 3003 запросов: по одному на документ. Это и есть N+1, выраженный числом запросов.
• Время растёт вместе с числом запросов. На 3000 документах цикл занял 5430 мс на сервере и 1704 мс в файловой базе, на один документ около 1,81 и 0,57 мс. Клиент-серверный вариант на этом компьютере медленнее примерно в 3,2 раза.
• Скрытое чтение через вызов стоит столько же, сколько чтение в теле цикла: ЧерновикиСкрытоеЧтение выполнил около 3002 запросов. Просмотр одного тела цикла такой код не покажет.
• Чтение через две точки, Документ.Контрагент.Наименование, дало около 3302 запросов на 3000 документах: 3000 по документам и ещё около 300 по контрагентам. Справочник читается один раз на каждого контрагента, повторные чтения того же контрагента запросов не добавляют. Так же устроены 802 запроса на 500 документах: 500 документов и 300 контрагентов.
• Имя переменной на скорость и число запросов не влияет: у СуммаСтрокаДокумента счёт такой же, как у СуммаВТелеЦикла.
• Если вызывающий код передал загруженные объекты, цикл с той же точкой запросов не делает: СуммаПоОбъектам на 3000 документах занял 7 мс. Загрузка объектов в замер не входит, её запросы переехали в код, который готовил массив.
• Один запрос вместо цикла: 1 запрос на 500 и 1000 документах и около 10 на 3000. Почему на 3000 документах их несколько, я не исследовала: предположение, что платформа делит длинный список параметра на части, я не проверяла.

Чтение двух разных реквизитов одной и той же ссылки подряд я не замеряла: в стенде каждая ссылка читается одним реквизитом.

Последнее наблюдение про объекты объясняет, почему по тексту цикла нельзя сказать «это N+1» наверняка. Один и тот же код Объект.Сумма быстр для загруженных объектов и медлен для ссылок, а тип параметра известен только вызывающему.

🔗 Граф вызовов от тела цикла

Анализатор nplus1_scan.py написан на Python и читает файлы .bsl. Он работает в четыре шага. Сначала убирает из текста комментарии и содержимое строк, сохраняя номера строк. Затем находит процедуры и функции, циклы Для Каждого, Для и Пока с границами их тел. Потом для каждого цикла идёт по вызовам: процедуры своего модуля и вызовы вида Модуль.Метод. И наконец отслеживает переменную цикла: если она передана в вызов как отдельный аргумент, соответствующий параметр вызываемой процедуры тоже считается ссылкой из цикла.

Ключевой фрагмент, переход по вызову с переносом переменной:

1
2
3
4
5
6
7
8
9
10
11
12
13

    for m in re.finditer(r"(?<![\w.])(?:(\w+)\.)?(\w+)\s*\(([^()]*)\)", s):
        mod_part, name, args = m.group(1), m.group(2), m.group(3)
        if name.lower() in KEYWORDS or re.search(r"Новый\s*$", s[:m.start()], re.I):
            continue
        target = procs.get((mod_part, name.lower())) if mod_part and mod_part in modules else (
            procs.get((proc.module, name.lower())) if not mod_part else None)
        if target is None or (target.module, target.name) in seen:
            continue
        argv = [a.strip() for a in args.split(",")]
        passed = [target.params[i] for i, a in enumerate(argv) if a in tracked and i < len(target.params)]
        if passed:
            accesses(target, passed, range(target.start + 1, target.end), path + [f"{target.name}:{target.start}"],
                     loop, org, depth + 1, seen | {(target.module, target.name)})

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

🔎 Что нашёл анализатор

Запуск на модуле с вариантами:

python nplus1_scan.py stand/Н1_Примеры.bsl

Файлов: 1. Кандидатов: 5. Пропущено циклов: 2.

[кандидат] Н1_Примеры  цикл СуммаВТелеЦикла:8  чтение Документ.Сумма (1) в СуммаВТелеЦикла:9
           путь: СуммаВТелеЦикла:8  | коллекция: параметр: тип неизвестен
[кандидат] Н1_Примеры  цикл ЧерновикиСкрытоеЧтение:17  чтение Документ.Статус (1) в ЭтоЧерновик:26
           путь: ЧерновикиСкрытоеЧтение:17 > ЭтоЧерновик:25  | коллекция: параметр: тип неизвестен
[кандидат] Н1_Примеры  цикл ДлинаИмёнКонтрагентов:32  чтение Документ.Контрагент.Наименование (2) в ДлинаИмёнКонтрагентов:33
           путь: ДлинаИмёнКонтрагентов:32  | коллекция: параметр: тип неизвестен
[кандидат] Н1_Примеры  цикл СуммаСтрокаДокумента:68  чтение СтрокаДокумента.Сумма (1) в СуммаСтрокаДокумента:69
           путь: СуммаСтрокаДокумента:68  | коллекция: параметр: тип неизвестен
[кандидат] Н1_Примеры  цикл СуммаПоОбъектам:98  чтение Объект.Сумма (1) в СуммаПоОбъектам:99
           путь: СуммаПоОбъектам:98  | коллекция: параметр: тип неизвестен
[пропущен] Н1_Примеры  цикл ЧерновикиОдинЗапрос:52  переменная Данные: таблица значений: строки в памяти
[пропущен] Н1_Примеры  цикл ДлинаИмёнОдинЗапрос:88  переменная -: выборка запроса: поля читаются из выборки

Сверка с замером на клиент-серверной базе:

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

Правило «имя переменной начинается со слова Строка, значит это строка таблицы» в исходном черновике предлагалось как эвристика. Я добавила его в анализатор отдельным ключом --name-heuristic и запустила:

python nplus1_scan.py stand/Н1_Примеры.bsl --name-heuristic
...
[пропущен] Н1_Примеры  цикл СуммаСтрокаДокумента:68  переменная СтрокаДокумента: эвристика по имени: «Строка…»

Эвристика пропустила СуммаСтрокаДокумента, а это медленный вариант: 5780 мс и около 3000 запросов. Имя переменной ничего не говорит о типе. По умолчанию ключ выключен.

🧩 Как читать результат и что исправлять

Список анализатора служит поводом для проверки. Для каждой строки нужно ответить на два вопроса: что на самом деле лежит в коллекции и сколько элементов в ней бывает. Для ссылок и большого числа элементов цикл переписывается: нужные поля выбираются одним запросом, дальше код идёт по строкам результата. Так устроены варианты ЧерновикиОдинЗапрос и ДлинаИмёнОдинЗапрос:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43

Функция ЧерновикиОдинЗапрос(МассивДокументов) Экспорт
    Запрос = Новый Запрос;
    Запрос.Текст =
    "ВЫБРАТЬ
    |    Реализация.Ссылка КАК Ссылка,
    |    Реализация.Статус КАК Статус
    |ИЗ
    |    Документ.РеализацияТоваров КАК Реализация
    |ГДЕ
    |    Реализация.Ссылка В(&МассивДокументов)";
    Запрос.УстановитьПараметр("МассивДокументов", МассивДокументов);
    ТаблицаДанных = Запрос.Выполнить().Выгрузить();
    Количество = 0;
    Для Каждого Данные Из ТаблицаДанных Цикл
        Если СтрокаЧерновик(Данные) Тогда
            Количество = Количество + 1;
        КонецЕсли;
    КонецЦикла;
    Возврат Количество;
КонецФункции

Функция СтрокаЧерновик(Данные)
    Возврат Данные.Статус = "Черновик";
КонецФункции

Функция ДлинаИмёнОдинЗапрос(МассивДокументов) Экспорт
    Запрос = Новый Запрос;
    Запрос.Текст =
    "ВЫБРАТЬ
    |    Реализация.Ссылка КАК Ссылка,
    |    Реализация.Контрагент.Наименование КАК Наименование
    |ИЗ
    |    Документ.РеализацияТоваров КАК Реализация
    |ГДЕ
    |    Реализация.Ссылка В(&МассивДокументов)";
    Запрос.УстановитьПараметр("МассивДокументов", МассивДокументов);
    Итог = 0;
    Выборка = Запрос.Выполнить().Выбрать();
    Пока Выборка.Следующий() Цикл
        Итог = Итог + СтрДлина(Выборка.Наименование);
    КонецЦикла;
    Возврат Итог;
КонецФункции

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

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

🧭 Ограничения

Замер выполнен один раз на одном компьютере, описанном выше: платформа 8.3.27.2130, 3000 документов и 300 контрагентов, три запуска каждого сочетания. Разброс между запусками на клиент-серверной базе доходит до нескольких сотен миллисекунд. Два полных прогона подряд дали для СуммаВТелеЦикла на 3000 документах 6260 и 5430 мс (первый я переснимала из-за ошибки в подсчёте запросов), то есть до 15% между прогонами. Поэтому различия в 10-15% между вариантами с одинаковым числом запросов ничего не доказывают. Клиент, кластер 1С и СУБД расположены на одной машине, на сетевой схеме с отдельными серверами время запросов будет другим, а при N+1 разница накапливается на каждом запросе. Вызов серверного кода из тонкого клиента, другие версии платформы и другие версии PostgreSQL я не проверяла.

Анализатор читает исходный текст регулярными выражениями и русскоязычный синтаксис. Он не определяет типы переменных, не видит динамические вызовы и вызовы через переменную, не различает ветви условий и переносит в вызываемую процедуру только переменную, переданную отдельным аргументом. Модули форм, расширений и внешних обработок попадут в анализ, если вы дадите их файлы. Табличные части и коллекции, загруженные вместе с объектом, он сам не отличает от чтения из базы; такие места остаются в списке для проверки.

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

📚 Источники

• Платформа 1С:Предприятие 8.3.27.2130, команды Конфигуратора /LoadConfigFromFiles, /UpdateDBCfg, /CheckModules, внешнее соединение через COM, утилита rac для создания базы в кластере.
• PostgreSQL, расширение pg_stat_statements (счётчик числа выполненных запросов).
• Предшественники на Infostart: Запросы в 1С, которые выглядят нормально, но работают плохо; Оптимизация кода 1С: простые приемы; обсуждение на форуме Оптимизация обращений к реквизитам объектов через точку. Эти материалы я нашла поиском; полный текст не открывала, поэтому их выводы здесь не пересказываю. Здесь добавлены запуск на платформе, подсчёт запросов на PostgreSQL, замер и анализатор с обходом вызовов.

📎 Файл к статье

В архиве к статье 11.3-companion.zip: анализатор nplus1_scan.py, каталог stand со сборщиком базы build_stand.py, модулями Н1_Примеры.bsl и Н1_Стенд.bsl, скриптом замера measure.ps1, итогами results.csv и results-server.csv, сводками summary.md и summary-server.md, вывод анализатора scan-output.txt и README. Сначала запустите анализатор на модуле с примерами, потом соберите стенд командой python build_stand.py и запустите замер в 32-битном PowerShell. Для клиент-серверного варианта база создаётся в кластере заранее, подробности в README. Цифры времени зависят от компьютера и базы.

 

Нинель Адольевна Щербакова (Ninel_S)

Архитектор • SRE & DevOps инженер • HighLoad 1С

Автор 48 технических публикаций на Infostart. Разработчик NOPik, SRE-Suite-for-1C и мультиагентных ассистентов для экосистемы 1С:Предприятие.

Каталог статей и открытых репозиториев Ninel_S