Оглавление
Введение
Все начиналось как обычно: пользователь обратился с проблемой длительного сохранения карточки элемента справочника. И первое, что мы сделали, попробовали воспроизвести ситуацию у себя. Так начнется же наше расследование!
Информационное окружение
Конфигурация написана на БСП. Подсистема, на объекте которой наблюдается замедление, в настоящий момент выделена в отдельный продукт «1С‑Рарус: Диаграммы» и мы её используем в нашем решении «1С‑Рарус: Мониторинг производительности».
Аппаратное обеспечение и ПО
- CPU: 2xIntel Xeon E5-2637 v2.
- ОЗУ: 96 ГБ.
- СУБД: PostgreSQL 12.22.
- Платформа 1С:Предприятие 8: 8.3.21.1622 64х.
- Серверная ОС: Linux Ubuntu 18.4.
Состав подсистемы «Диаграммы»
Атомарной единицей подсистемы является диаграмма. Каждый элемент справочника хранит настройку выводимой диаграммы:
Эти диаграммы объединяются в страницы. Страница — это то, что пользователь видит одномоментно на экране:
Страницы, в свою очередь, объединяются в доски. Доска формируется пользователем по области наблюдения. Например, финансовые показатели конкретного филиала:
Для удобства работы пользователя был разработан АРМ, который представлен на картинке ниже. В АРМе можно добавлять новые доски, на доски добавлять страницы и на страницы добавлять диаграммы. Диаграммы выводятся с помощью HTML-документа на форму.
Описание проблематики пользователем
Пользователь открывает форму настройки страницы из АРМа. По окончании работы с ней (перестановка диаграмм на странице) пользователь нажимает «Записать и закрыть». После этого предсказать время, на которое зависнет система, невозможно. Это может быть и одна секунда, и 2 минуты. Причем одна и та же страница может сохраняться иногда минуту, а иногда 5 секунд.
Воспроизведение ошибки
Сначала мы взяли доску с изображения выше, но увидеть на ней какие-то значительные «тормоза» у нас не получилось. Поэтому мы выбрали другую доску для экспериментов — одну из тех, которую использует обратившийся пользователь, и стали пробовать воспроизводить зависание на ней. Доска состоит из 19 страниц, на каждой странице по 3–5 диаграмм. После нескольких подходов смогли воспроизвести «тормоза». В частности, для отладки мы выбрали 8‑ую страницу:
Первое нажатие «Записать и закрыть» заняло чуть больше минуты:
Второе же сохранение выполнилось гораздо быстрее:
Третий эксперимент был проведен с сохранением 6-й страницы:
А вот сохранив после этого страницу 8 снова получили чуть больше время, чем во второй раз:
Как видно из замеров, самое большое время занимает процедура «ОбработкаИзмененияСтраницы», выполняющаяся на форме «АРМ Доски». Внутри мы видим вызов 2‑х процедур «ОчиститьФорму» и «ДобавитьСтраницуНаСервере». Первая удаляет страницу с формы, вторая добавляет страницу на форму в конец:
Это сделано, т. к. математика расположения диаграмм на странице доски нетривиальная (об этом мы рассказавали в одном из докладов 1C‑RarusTechDay), и чтобы не усложнять математику перемещения и изменения состава групп и элементов было дешевле удалить и создать всё заново.
Причем стоит отметить, что для пользователя такое действие не заметно, т. к. стандартная панель страниц скрыта, а вместо неё используется нарисованная и упорядоченная панель.
Как видно на скриншоте после всех проделанных действий страницы 6 и 8 сместились в конец:
Смещение страниц в конец возможно и есть причина длительного сохранения? Мы решили это проверить. Для этого сохранили в файлы структуру элемнтов формы во время отладки до удаления страницы и после добавления обратно:
Но формы оказались совершенно идентичными:
Что-то мы упускаем, но что именно?
Поэтому мы решили ещё раз посмотреть замер производительности длительного сохранения. И тут мы заметили, что больше минуты длится вызов с клиента серверной процедуры «ОбработкаИзмененияСтраницы», в то время как «Суммарное серверное время» не превышает и секунды:
Получается, что где‑то между клиентом и сервером теряется целая минута! Значит надо её найти.
Перехват трафика
Мы решили поискать ответ в передаваемом с клиента на сервер 1С и обратно трафике. Для этого мы воспользовались одной из программ-перехватчиков.
Программы-перехватчики бывают 2 типов:
- Sniffer — например, Wireshark.
- Proxy — например, Fiddler или mitmproxy.
Они различаются по принципу работы. Сниферы не лезут в трафик, а просто его слушают, а прокси пропускают трафик через себя, в том числе давая возможность анализировать его содержимое:
Для нашей задачи подходят перехватчиики с типом Proxy, т. к. пакеты между клиентом и сервером 1С передаются в зашифрованном виде. Когда они передаются через прокси, мы можем увидеть их содержимое. Тут стоит уточнить, что перехватываться будут https-запросы, а это значит, что 1С мы должны запустить именно через веб-ссылку.
Мы воспользовались программой mitmproxy — она распространяется бесплатно и не подвержена санкциям:
Как настроить захват трафика?
Инструкция приводится для захвата на Windows, т. к. захват производится на клиентской машине, а чаще всего пользователи работают именно в этой операционной системе. На сайте так же можно найти дистрибутивы и для других ОС.
Скачать и установить программу:
Перед запуском необходимо установить сертификат. Скачать его можно по адресу mitm.it. Но для этого необходимо сначала настроить свойства браузера:
В разделе «Подключение» перейти к «Настройкам сети» и указать адрес прокси-сервера 127.0.0.1 и порт 8080:
Открыть Internet Explorer, перейти по адресу mitm.it и скачать сертификат:
После этого необходимо обязательно восстановить стандартные настройки прокси:
Установить сертификат в хранилище «Доверенные корневые центры сертификации»:
Запустить mitmweb — это mitmproxy в графическом интерфейсе:
Далее настроить 1С: открыть окно запуска и в нужной базе поменять настройки прокси:
Теперь все готово для захвата трафика выбранной базы.
Результат захвата выглядит следующим образом:
Стоит отметить, что этих запросов и ответов платформа 1С порождает достаточно много, и для нахождения нужного требуются некоторые усилия и практика.
Продолжение расследования
Мы запустили захват трафика и снова выполнили операцию «Записать и закрыть» 2 раза. Поиск нужных запросов производили по ряду признаков:
- Временные промежутки, в которых выполнялись операции.
- Имя исполняемого метод.
- Размер передаваемого пакета больше обычного, а второй запрос уже по схожему размеру.
Из найденных пакетов скопировали тело ответа (Response) в формате xml в Kdiff3 и получили следующие различия:
Мы увидели, что в первом случае с сервера приходит информация об изменениях индексов страниц, идущих после удаляемых, а во втором случае такого нет. В этот момент мы сделали следующие предположения:
- Удаление страницы все же приводит к изменению структуры формы.
- В итоге удаляется не только элемент «Страница», с которым мы работали, а по сути все последующие элементы формы со своим наполнением.
- С учетом того, что на каждой странице расположены тяжелые поля HTML и множество служебных групп и элементов, то это действие занимает значительное время.
Исправление
Исходя из проблематики исправление было простым: мы переписали полное удаление страницы на удаление вложенных в неё элементов:
А далее вместо добавления страницы находим существующий зарезервированный под неё элемент формы «Страница» и наполняем его диаграммами.
В итоге задача была решена. Замеры стали стабильными и не превышали 1 секунды:
Выводы
- В первую очередь эта статья посвещена человеской лени разбираться в сложном коде и формировании технического долга в виде полного удаления страницы. Поэтому рекомендуем всегда задумываться о цене быстрых и не обдуманных решений.
- Эксперт должен владеть не только анализом лога ТЖ, но и уметь использовать нестандартные инструменты, уместные и эффективные в конкретной ситуации.
Бонус-исследование
Решив задачу пользователя мы задались вопрос: «А как влияет на время отрисовки содержимое формы?».
Мы провели исследование для ответа на этот вопрос. Заключается оно в открытии различных форм с разным набором элементов и данных. А чтобы показания были достаточно точными, то на них не должно быть ничего лишнего кроме исследуемых объектов. Поэтому мы создали формы специально для исследования. Но мы были бы не инженерами, если бы делали такие формы руками. Поэтому мы создали обработку, которая генерирует обработки для исследования.
Генератор обработок
Генератор позволяет создавать обработки с одной формой, на которой добавлены реквизиты и элементы формы с указанной типизацией и в указанном количестве:
Сгенерированные файлы XML сохраняются в специальную структуру папок:
После чего с помощью командной строки «склеивается» Обработка.epf:
И на выходе мы получаем простую форму без изысков типа групп элементов, страниц и декораций:
Тесты
Тесты проводились на одной и той же клиент-серверной базе. Сервер на ОС Linux, клиент — Windows. Замеры производились в миллисекундах. Для получения времени мы вычисляем разницу между временем в мс в процедуре «ПриОткрытии» и процедуре «ПриСозданииНаСервере». Стоит отметить, что замеры не претендуют на абсолютную истину и выполнялись на конкретной машине и в конкретной базе. Так же время указанное в таблице — это время открытия, но некоторые формы зависали и после открытия на некоторое время и были совершенно не поворотливы в работе:
Результаты замеров времени представлены в таблице ниже. Для удобства восприятия время представлено в секундах. Были сгенерированны формы с однотипными реквизитами и элементами в количестве 100, 1 000 и 10 000. Каждая форма открывалась несколько раз и из таблицы видно, что второе открытие подряд зачастую быстрее первого. Например из таблицы видно, что форма, на которой размещено 1 000 реквизитов и их элементов с типом «Строка неограниченной длины» с заполненными значениями в 500 знаков заняло 3,4 секунды. Там где стоят прочерки — замер, соответственно, не производился.
Можно сразу увидеть вес элементов при открытии — например самыми легкими, не считая невыводимых реквизитов на форму, оказались декорации формы. Среди реквизитов примитивных типов выиграли «Булево». Так же можно заметить, что разный объем данных в «Таблицах значений» также влияет на отрисовку формы.
Стоит очень внимательно изучить данную таблицу самостоятельно и сделать интересные выводы для себя:
Элемент | Открытие |
Количество |
||
---|---|---|---|---|
100 |
1000 |
10000 |
||
Число (15,2) | Первое |
0,45 |
3,50 |
248,35 |
Второе |
0,15 |
2,05 |
217,69 |
|
Строка (100) | Первое |
0,31 |
3,23 |
249,24 |
Второе |
0,11 |
2,05 |
207,36 |
|
Строка (0) с заполнением 500 знаков | Первое |
0,36 |
3,40 |
303,92 |
Второе |
0,12 |
2,15 |
272,91 |
|
HTML (Сайт) | Первое |
2,89 |
101,76 |
— |
Второе |
2,54 |
110,58 |
— |
|
Дата | Первое |
0,35 |
3,30 |
277,29 |
Второе |
0,15 |
2,22 |
224,56 |
|
Булево | Первое |
0,25 |
1,75 |
86,00 |
Второе |
0,07 |
0,63 |
62,11 |
|
Ссылка | Первое |
0,35 |
3,83 |
302,35 |
Второе |
0,15 |
1,88 |
272,79 |
|
Реквизит Дата без вывода на форму | Первое |
— |
0,58 |
2,27 |
Второе |
— |
0,23 |
0,67 |
|
Табличный документ | Первое |
0,50 |
4,39 |
442,74 |
Второе |
0,26 |
2,54 |
417,24 |
|
Табличный документ с заполнением 100 строк 20 колонок | Первое |
0,61 |
5,71 |
454,06 |
Второе |
0,37 |
5,21 |
426,8 |
|
Табличный документ с заполнением 10 000 строк 50 колонок | Первое |
28,53 |
302,16 |
— |
Второе |
34,72 |
Превышен максимальный расход памяти сервера за один вызов |
— |
|
Форматированный документ | Первое |
11,70 |
238,67 |
— |
Второе |
11,47 |
258,12 |
— |
|
Таблица значений из 15 колонок с заполнением 10 строк | Первое |
6,28 |
100,58 |
— |
Второе |
1,73 |
40,23 |
— |
|
Таблица значений из 15 колонок с заполнением 10 000 строк | Первое |
50,64 |
— |
— |
Второе |
46,38 |
— |
— |
|
Дерево значений из 15 колонок с заполнением 10 строк | Первое |
9,32 |
112,26 |
— |
Второе |
1,61 |
30,01 |
— |
|
Дерево значений из 15 колонок с заполнением 10 000 строк | Первое |
267,81 |
— |
— |
Второе |
264,77 |
— |
— |
|
Декорация Надпись | Первое |
0,19 |
1,15 |
42,63 |
Второе |
0,05 |
0,28 |
19,07 |
|
Декорация Картинка(64×64) | Первое |
0,24 |
1,22 |
45,53 |
Второе |
0,04 |
0,29 |
20,19 |
|
Группа с одним элементом Булево | Первое |
0,27 |
1,93 |
96,64 |
Второе |
0,06 |
0,80 |
65,44 |
|
Группа с отображением с одним элементом Булево | Первое |
0,28 |
3,74 |
171,94 |
Второе |
0,09 |
1,06 |
146,87 |
|
Страницы | Первое |
0,97 |
11,75 |
178,41 |
Второе |
0,95 |
10,02 |
148,45 |
Для более легкого прочтения представляем вашему вниманию несколько графиков по данной таблице.
Первый график полностью дублирует таблицу:
Второй график отражает данные для 1 000 элементов при первом открытии. Сюда не попали заполненные таблицы значенений, т. к. уже при 100 элементах время достигает 1 минуты, а для дерева значений превышает 4 минуты:
И последний график показывает кривую увеличения времени для каждого типа элементов от количества элементов на форме:
В качестве заключения снова хотим дать совет не лениться в разработке и не оставлять технические долги «на потом». Не стоит перегружать формы и по возможности некоторые вещи выносить в другие вспомогательные формы.
От экспертов «1С-Рарус»





