открыть форму с параметрами долго открывается

От экспертов «1С‑Рарус»: Неожиданная причина долгого открытия формы в «1С»

Оглавление

Первое открытие «Интереса» после запуска УТиВСК 3 занимает больше 15 секунд

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

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Рис. 1 Долгое первое открытие формы

Ограничения доступа на уровне записей (RLS) являются неотъемлемой частью решений на платформе 1С:Предприятие для среднего и крупного бизнеса. Они позволяют разграничить доступ к данным на основе значений этих данных. Например, можно дать менеджерам по продажам возможность видеть только своих клиентов. Давно известно, что включение RLS серьезно замедляет многие операции, и поэтому общепринятая рекомендация — включать только те RLS, без которых обойтись нельзя.

В программе УТиВСК 3 документ «Интерес» аккумулирует в себе всю информацию по ведению сделок с клиентами, и время открытия этого документа критически важно для качества программного продукта.

Исходная ситуация

Окружение

Описание проблемы

Проверяем RLS и SQL-запросы

Предположения и сбор материалов

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

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

Исходя из этого, было принято решение искать долгие запросы с RLS, выполняющиеся в модулях с повторным использованием. Для этого был собран технологический журнал с событиями CALL и DBMSSQL (рис. 2).

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

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

Анализ

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

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Рис.3 Топ серверных вызовов по длительности и скрипт, которым он был получен

В топе запросов также есть лидер, его длительность 1,3 сек. Это явно неоптимальный запрос, но он не оказывает решающего вклада в длительность вызова (рис. 4).

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Рис. 4 Топ SQL-запросов по длительности и скрипт, которым он был получен

Также, все прочие запросы имеют длительность менее 0,05 сек каждый (рис. 5).

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Рис. 5 Топ SQL-запросов по длительности (продолжение)

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

Больше внимания RLS

Предположения и сбор материалов — вторая итерация

При анализе собранного технологического журнала замечено, что тексты запросов, выполняющихся во время вызовов, очень объемные и сложные. Но при этом запросы быстро выполняются. Например, исполняемый СУБД текст самого длительного запроса содержит более 3300 строк, размер — 266 КБ (рис. 6).

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Рис. 6 Количество строк и размер текста самого длительного SQL-запроса

В связи с этим можно предположить, что основные затраты времени приходятся на формирование текстов запросов с RLS. Было решено снова собрать технологический журнал, но на этот раз включить в него событие SDBL (рис. 7).

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

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

Анализ —вторая итерация

Собранные данные также были обработаны скриптами. В топе событий SDBL оказались видны длительные события, связанные с выполнением запросов с RLS (рис. 8, 9).

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Рис. 8 Топ событий SDBL по длительности и скрипт, которым он был получен

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Рис. 9 Топ событий SDBL по длительности (продолжение)

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

Первый запрос из топа занимает в модели SDBL 409 строк, размер — 22,4 КБ. Текст SQL превосходит текст SDBL более чем в 8 раз по количеству строк и более чем в 11 раз по объему. Длительность события SDBL превышает длительность SQL-запроса более чем в 6 раз (рис. 10, сравните с рис. 6).

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Рис. 10 Количество строк и размер текста самого длительного события SDBL

Уменьшение времени на первое открытие формы документа «Интерес»

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Рис. 11 Результат оптимизации

Еще статьи по теме медленного открытия форм и замедления работы «1С»:

Источник

УТ11. Долго открываются формы.

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

рекомендую после теста на старом месте srvinfo сбэкапить и удалить (можно просто переименовать)

(16) у меня периодически начинают массово плодиться зависшие процессы с фоновым заданием обновление индекса ППД, точную зависимость от чего пока не установил

(0) > память тоже свободна
вот под виндой я б не стал так утверждать, она сама себе на уме по поводу реального распределения памяти и его отображения.

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

а диспетчер задач при этом показывает 95% свободно

(27) кроме процессов есть filesystem cache, который не виден ни в винде, ни в линуксе. Он ядреного уровня, к процессам не относится. На некоторое время работающей системе (т.е. не сразу после старта) обычно это весь свободный объем настоящей железной оперативки (без свопа).

а любимый 1с будет барахтаться в свопе, потому что кто-то файл открытым на чтение держит

(29) типичный коммент пользователя операционной системы, который не пытался разобраться в ее работе

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

(28)
Для win7 это 2 показатель группы «Физическая память» на вкладке «Быстродействие».

Все достаточно прозрачно.

processexplorer fs cache не показывает, поэтому я склонен думать, что этот параметр пользователям винды недоступен

в линуксе обычный top не показывает, htop может показать, если попросить

простая задачка:
предположим, 5 разных пользователей зашли по RDP через канал GPRS
каждый из них решил скопировать к себе кино весом по 5GB (разные) и начал процесс копирования, т.е. открыл файл на чтение
в это время админ решил заменить все фильмы бинарным мусором и перезаписал их, т.е. открыл на запись. Уже начатый процесс копирования должен отдать тот файл, который пользователь начал читать. Т.е., операционная система должна где-то хранить исходные 5х5 = 25 GB кино, которые раздолбаи через GPRS уже начали копировать. Да, такая фунцкция есть у всех современных файловых систем. Однако, программа должна уметь ее использовать. Что-то мне подсказывает, делается это редко. MS SQL сервер умеет это делать. Насчет остальных сильно не уверен.

Вот какое наблюдение есть. Только за сегодня размер кеша Сервера1С (C:\Program Files\1cv8\srvinfo\reg_1541\)предприятия составил 0.7 Гб. В SQL размер данных составляет 1.2 Гб.

Источник

открыть форму с параметрами долго открывается

УТ11. Долго открываются формы.

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

рекомендую после теста на старом месте srvinfo сбэкапить и удалить (можно просто переименовать)

(16) у меня периодически начинают массово плодиться зависшие процессы с фоновым заданием обновление индекса ППД, точную зависимость от чего пока не установил

(0) > память тоже свободна
вот под виндой я б не стал так утверждать, она сама себе на уме по поводу реального распределения памяти и его отображения.

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

а диспетчер задач при этом показывает 95% свободно

(27) кроме процессов есть filesystem cache, который не виден ни в винде, ни в линуксе. Он ядреного уровня, к процессам не относится. На некоторое время работающей системе (т.е. не сразу после старта) обычно это весь свободный объем настоящей железной оперативки (без свопа).

а любимый 1с будет барахтаться в свопе, потому что кто-то файл открытым на чтение держит

(29) типичный коммент пользователя операционной системы, который не пытался разобраться в ее работе

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

(28)
Для win7 это 2 показатель группы «Физическая память» на вкладке «Быстродействие».

Все достаточно прозрачно.

processexplorer fs cache не показывает, поэтому я склонен думать, что этот параметр пользователям винды недоступен

в линуксе обычный top не показывает, htop может показать, если попросить

простая задачка:
предположим, 5 разных пользователей зашли по RDP через канал GPRS
каждый из них решил скопировать к себе кино весом по 5GB (разные) и начал процесс копирования, т.е. открыл файл на чтение
в это время админ решил заменить все фильмы бинарным мусором и перезаписал их, т.е. открыл на запись. Уже начатый процесс копирования должен отдать тот файл, который пользователь начал читать. Т.е., операционная система должна где-то хранить исходные 5х5 = 25 GB кино, которые раздолбаи через GPRS уже начали копировать. Да, такая фунцкция есть у всех современных файловых систем. Однако, программа должна уметь ее использовать. Что-то мне подсказывает, делается это редко. MS SQL сервер умеет это делать. Насчет остальных сильно не уверен.

Вот какое наблюдение есть. Только за сегодня размер кеша Сервера1С (C:\Program Files\1cv8\srvinfo\reg_1541\)предприятия составил 0.7 Гб. В SQL размер данных составляет 1.2 Гб.

Методика расследования причин медленной работы операции на примере открытия управляемой формы


Ограничения применимости методики

Когда применяется методика:

Проверка ограничений и подготовка к расследованию

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

Фильтр по имени процесса для нашей задачи избыточен и нужен для того, чтобы в случае ошибочной настройки такого лога на сервере не получить сбор всех событий для серверных процессов, что может занять значительный объем. С другой стороны, при осознанном включении такой настройки на сервере (если клиентские приложения запускаются там же, где может быть развернут и сервер приложений 1С:Предприятие) мы в отдельном каталоге Client_Full увидим данные только клиентских приложений (хотя при этом подкаталоги других процессов тоже будут созданы, но они буду пустыми). Свойство Interface не собираем, так как оно дублируется более «человек читаемым» свойством IName (хотя даже последнее нам в данном примере не обязательно нужно).

После настройки технологических журналов и проверки корректности замера времени ОценкиПроизводительности БСП выполняем повторение операции с включенной отладкой.

Замеры времени средствами БСП будут выглядеть следующим образом:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

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

Замер отладчиком конфигуратора изображен на следующем рисунке:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Как видно, сумма длительности всех строк, связанных с открытием формы составила всего 1,523 секунды.

Определим точное время начала и завершения операции по данным регистра замеров времени БСП.
Для этого необходимо любым удобным способом преобразовать данные колонок «Дата начала замера» и «Дата окончания» из миллисекунд UTC, начиная с 01.01.0001 00:00:00 (обычно эти значения получены с помощью функции ТекущаяУниверсальнаяДатаВМиллисекундах()).
Например, можно воспользоваться онлайн инструментами вроде https://www.epochconverter.com/ (нас будут интересовать минуты, секунды и миллисекунды, отличия в часовых поясах и годах не важны), либо можно преобразовать значение в дату с точностью до секунд с помощью функции вида:

‘00010101’ + ТекущаяУниверсальнаяДатаВМиллисекундах() / 1000

а для миллисекунд взять остаток от деления на 1000 (то есть просто последние три цифры, обратите внимание на «779» на следующей картинке).

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Точное время начала замера (минут:секунд.миллисекунд): 25:10.779

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Точное время окончания замера (минут:секунд.миллисекунд): 25:23.801

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

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Здесь видно, что соответствующий нашему замеру серверный вызов SCALL завершился примерно за 10,1 секунды, это соответствует интервалу между запросом VRSREQUEST и ответом VRSRESPONSE.
Причем время начала замера почти совпадает с началом вызова, то есть событием VRSREQUEST, что собственно ожидаемо, так как замер БСП начинается на клиенте и должен быть непосредственно перед командой открытия формы. А вот окончание вызова сервера случилось раньше, чем окончание замера, что значит, что эта разница во времени пришлась на часть работы клиентского приложения.

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

После того, как их подготовили, перейдем в тонкий клиент 1С, откроем форму списка документов и непосредственно перед воспроизведением проблемной операции запустим сбор данных WPR (кнопка Start).

После открытия формы в тонком клиенте запись можно остановить и открыть ее для анализа. В открывшемся окне найдем по PID 5508 (его можно определить в диспетчере задач ОС или по логам ТЖ) наш тонкий клиент 1С и должны получить примерно следующую картинку:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

По данным Windows Performance Analyzer видим, что у нас нет серьезной нагрузки по дискам, а поток тонкого клиента потребляет 100% ЦП на протяжении длительного времени вплоть до завершения замера.

Запомним этот результат и проанализируем траффик.

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

При сборе данных с помощью Wireshark (и отбору по пакетам с сервером-источником равным серверу приложений 1С:Предприятие) запуск открытия формы документа будет выглядеть примерно так:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Здесь каждая такая строка – это пакет (или если точнее, то «кадр», frame), который в свою очередь является частью общего большого пакета поверх протокола TCP (PDU – Protocol Data Unit). Если их сложить, получим пакет около 70 Кб. Стоит обратить внимание, что это будет размер с учётом сжатия, а если без него – то должны получить что-то около 2500 – 3500 Кб данных.

Если вернуться к анализу технологического журнала и посмотреть на «Content-Length» (или «Body»), то увидим также те самые 70577 байт. Познавательно, можно взять на заметку, но пока новой информации не дает. В таком дампе Wireshark бывает полезно анализировать каждый отдельный кадр и возможные повторы отправки пакетов или увидеть сбросы TCP-соединений, которые могут приводить к ошибкам в работе клиентов (например, из-за антивирусов, которые могут распознать такое содержимое как подозрительное). Однако для нашей проблемы удобнее воспользоваться другим инструментом – прокси-сервером Fiddler и проанализировать с его помощью уже http-траффик.

Устанавливаем и запускаем Fiddler, на панели инструментов ищем «Browse», выбираем любимый браузер и запускаем в нем необходимое нам приложение (информационную базу 1С:Предприятие). После запуска переходим в форму списка документов (готовимся воспроизвести сценарий), возвращаемся в Fiddler и включаем сбор траффика (кнопка F12), переходим в браузер и открываем форму документа. После её открытия сбор траффика можно отключить и заняться его анализом. Мы должны получить примерно следующее:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

В данном дампе достаточно быстро находится относительно большой пакет искомого размера, выбираем его в списке слева, а в правой части окна переключаемся на страницу Inspectors, выбираем там просмотр заголовков (Headers), и так как у нас пакет является сериализованным json (Content-Type: application/json), то попросим Fiddler десериализовать его для нас.

После этого в окне предпросмотра отобразится древовидная структура ответа (response), которая передается с сервера на клиент и содержит так много данных. Далее нам необходимо проанализировать её и найти наиболее проблемные места. Может помочь кнопка Expand All, которая развернёт все элементы дерева, но это может занять некоторое время. Чтобы его сократить, сначала поймем, что именно нужно искать.

Подведем промежуточный итог:

Из всех этих пунктов для нас наиболее полезным и требующим дополнительного анализа является тезис «Размер пакета с формой подозрительно велик».
Какие могут быть причины для такой ситуации? В общем случае их несколько:

Так как наша проблема (у вас может быть по-другому) воспроизводится даже при очень небольшом количестве данных в ТЧ, и реквизитов у документа (т.е. объекта формы) совсем не много, то их мы не рассматриваем. Остаются реквизиты формы, не равные основному реквизиту «Объект».

Среди них находится несколько реквизитов, имеющих произвольный тип. Могут выглядеть так:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Сопоставляем эти данные с уже собранным ранее замером с помощью конфигуратора, и видим заполнение этих структур достаточно большим количеством элементов (например, можно 5059 в реквизите «СвойстваИзмерений»).
Снова вернемся к дампу траффика в Fiddler и найдем там элемент, отвечающий за параметры формы (response/props). Увидим там примерно следующее:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

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

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

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

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

Выводы и рекомендации

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

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

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

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

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

Открытие форм

Область применения: управляемое приложение, мобильное приложение.

Источник

Методика расследования причин медленной работы операции на примере открытия управляемой формы


Ограничения применимости методики

Когда применяется методика:

Проверка ограничений и подготовка к расследованию

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

Фильтр по имени процесса для нашей задачи избыточен и нужен для того, чтобы в случае ошибочной настройки такого лога на сервере не получить сбор всех событий для серверных процессов, что может занять значительный объем. С другой стороны, при осознанном включении такой настройки на сервере (если клиентские приложения запускаются там же, где может быть развернут и сервер приложений 1С:Предприятие) мы в отдельном каталоге Client_Full увидим данные только клиентских приложений (хотя при этом подкаталоги других процессов тоже будут созданы, но они буду пустыми). Свойство Interface не собираем, так как оно дублируется более «человек читаемым» свойством IName (хотя даже последнее нам в данном примере не обязательно нужно).

После настройки технологических журналов и проверки корректности замера времени ОценкиПроизводительности БСП выполняем повторение операции с включенной отладкой.

Замеры времени средствами БСП будут выглядеть следующим образом:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

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

Замер отладчиком конфигуратора изображен на следующем рисунке:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Как видно, сумма длительности всех строк, связанных с открытием формы составила всего 1,523 секунды.

Определим точное время начала и завершения операции по данным регистра замеров времени БСП.
Для этого необходимо любым удобным способом преобразовать данные колонок «Дата начала замера» и «Дата окончания» из миллисекунд UTC, начиная с 01.01.0001 00:00:00 (обычно эти значения получены с помощью функции ТекущаяУниверсальнаяДатаВМиллисекундах()).
Например, можно воспользоваться онлайн инструментами вроде https://www.epochconverter.com/ (нас будут интересовать минуты, секунды и миллисекунды, отличия в часовых поясах и годах не важны), либо можно преобразовать значение в дату с точностью до секунд с помощью функции вида:

‘00010101’ + ТекущаяУниверсальнаяДатаВМиллисекундах() / 1000

а для миллисекунд взять остаток от деления на 1000 (то есть просто последние три цифры, обратите внимание на «779» на следующей картинке).

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Точное время начала замера (минут:секунд.миллисекунд): 25:10.779

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Точное время окончания замера (минут:секунд.миллисекунд): 25:23.801

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

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Здесь видно, что соответствующий нашему замеру серверный вызов SCALL завершился примерно за 10,1 секунды, это соответствует интервалу между запросом VRSREQUEST и ответом VRSRESPONSE.
Причем время начала замера почти совпадает с началом вызова, то есть событием VRSREQUEST, что собственно ожидаемо, так как замер БСП начинается на клиенте и должен быть непосредственно перед командой открытия формы. А вот окончание вызова сервера случилось раньше, чем окончание замера, что значит, что эта разница во времени пришлась на часть работы клиентского приложения.

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

После того, как их подготовили, перейдем в тонкий клиент 1С, откроем форму списка документов и непосредственно перед воспроизведением проблемной операции запустим сбор данных WPR (кнопка Start).

После открытия формы в тонком клиенте запись можно остановить и открыть ее для анализа. В открывшемся окне найдем по PID 5508 (его можно определить в диспетчере задач ОС или по логам ТЖ) наш тонкий клиент 1С и должны получить примерно следующую картинку:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

По данным Windows Performance Analyzer видим, что у нас нет серьезной нагрузки по дискам, а поток тонкого клиента потребляет 100% ЦП на протяжении длительного времени вплоть до завершения замера.

Запомним этот результат и проанализируем траффик.

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

При сборе данных с помощью Wireshark (и отбору по пакетам с сервером-источником равным серверу приложений 1С:Предприятие) запуск открытия формы документа будет выглядеть примерно так:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Здесь каждая такая строка – это пакет (или если точнее, то «кадр», frame), который в свою очередь является частью общего большого пакета поверх протокола TCP (PDU – Protocol Data Unit). Если их сложить, получим пакет около 70 Кб. Стоит обратить внимание, что это будет размер с учётом сжатия, а если без него – то должны получить что-то около 2500 – 3500 Кб данных.

Если вернуться к анализу технологического журнала и посмотреть на «Content-Length» (или «Body»), то увидим также те самые 70577 байт. Познавательно, можно взять на заметку, но пока новой информации не дает. В таком дампе Wireshark бывает полезно анализировать каждый отдельный кадр и возможные повторы отправки пакетов или увидеть сбросы TCP-соединений, которые могут приводить к ошибкам в работе клиентов (например, из-за антивирусов, которые могут распознать такое содержимое как подозрительное). Однако для нашей проблемы удобнее воспользоваться другим инструментом – прокси-сервером Fiddler и проанализировать с его помощью уже http-траффик.

Устанавливаем и запускаем Fiddler, на панели инструментов ищем «Browse», выбираем любимый браузер и запускаем в нем необходимое нам приложение (информационную базу 1С:Предприятие). После запуска переходим в форму списка документов (готовимся воспроизвести сценарий), возвращаемся в Fiddler и включаем сбор траффика (кнопка F12), переходим в браузер и открываем форму документа. После её открытия сбор траффика можно отключить и заняться его анализом. Мы должны получить примерно следующее:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

В данном дампе достаточно быстро находится относительно большой пакет искомого размера, выбираем его в списке слева, а в правой части окна переключаемся на страницу Inspectors, выбираем там просмотр заголовков (Headers), и так как у нас пакет является сериализованным json (Content-Type: application/json), то попросим Fiddler десериализовать его для нас.

После этого в окне предпросмотра отобразится древовидная структура ответа (response), которая передается с сервера на клиент и содержит так много данных. Далее нам необходимо проанализировать её и найти наиболее проблемные места. Может помочь кнопка Expand All, которая развернёт все элементы дерева, но это может занять некоторое время. Чтобы его сократить, сначала поймем, что именно нужно искать.

Подведем промежуточный итог:

Из всех этих пунктов для нас наиболее полезным и требующим дополнительного анализа является тезис «Размер пакета с формой подозрительно велик».
Какие могут быть причины для такой ситуации? В общем случае их несколько:

Так как наша проблема (у вас может быть по-другому) воспроизводится даже при очень небольшом количестве данных в ТЧ, и реквизитов у документа (т.е. объекта формы) совсем не много, то их мы не рассматриваем. Остаются реквизиты формы, не равные основному реквизиту «Объект».

Среди них находится несколько реквизитов, имеющих произвольный тип. Могут выглядеть так:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

Сопоставляем эти данные с уже собранным ранее замером с помощью конфигуратора, и видим заполнение этих структур достаточно большим количеством элементов (например, можно 5059 в реквизите «СвойстваИзмерений»).
Снова вернемся к дампу траффика в Fiddler и найдем там элемент, отвечающий за параметры формы (response/props). Увидим там примерно следующее:

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

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

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

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

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

Выводы и рекомендации

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

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

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

открыть форму с параметрами долго открывается. Смотреть фото открыть форму с параметрами долго открывается. Смотреть картинку открыть форму с параметрами долго открывается. Картинка про открыть форму с параметрами долго открывается. Фото открыть форму с параметрами долго открывается

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

Источник

Добавить комментарий

Ваш адрес email не будет опубликован. Обязательные поля помечены *