1с журнал регистрации зависает

Обновлено: 07.07.2024

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

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

Сбор и анализ стандартных данных

Разберем пример для операции открытия формы документа "Табель учёта рабочего времени".

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

Настройка технологического журнала на клиенте может быть такой:

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

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

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

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

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

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

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

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

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

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

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

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

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

Стандартными инструментами не удается увидеть причину проблем низкой производительности работы (открытия) управляемой формы, поэтому воспользуемся следующими помощниками:

Отладчик операционной системы: Windows Performance Recorder для сбора метрик и Windows Performance Analyzer для их визуализации и анализа;
Анализатор сетевых протоколов Wireshark или прокси-сервер Fiddler Web Debugger.

Установим и запустим Windows Performance Recorder ("C:\Program Files (x86)\Windows Kits\8.1\Windows Performance Toolkit\WPRUI.exe"), укажем настройки:

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

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

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

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

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

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

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

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

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

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

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

Проблем с медленной работой прикладного кода 1С или запросов нет.
Большая часть времени открытия формы состоит из сетевого взаимодействия.
Размер пакета с формой подозрительно велик.
После получения пакетов имеем высокую утилизацию ЦП тонким клиентом 1С (или веб-клиентом).
Потерянное время находится где-то между окончанием/началом работы прикладного кода 1С и сетевой передачей.

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

Сама по себе большая и сложная форма с большим количеством экранных элементов и реквизитов. Наверное, редкий и точно не очень правильный случай, лучше такого избегать на этапе проектирования систем.
Простая форма, но много данных в реквизитах формы (включая данные объекта), в особенности:
- Хранилище значения, Строка(0);
- Большие коллекции (Таблица, Дерево, Список);
- Произвольный тип (концентрация проблем).
Так как наша проблема (у вас может быть по-другому) воспроизводится даже при очень небольшом количестве данных в ТЧ, и реквизитов у документа (т.е. объекта формы) совсем не много, то их мы не рассматриваем. Остаются реквизиты формы, не равные основному реквизиту "Объект".

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

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

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

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

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

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

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

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

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

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

Внимание! Данный форум является модерируемым.
Для получения к нему доступа необходимо зарегистрироваться или авторизоваться на сайте.
Добрый день. Столкнулась со следующей проблемой. В справочнике Пользователи изменила полное наименование (добавила отчество, больше ничего не трогала), и теперь в журнале регистрации, когда пытаюсь сформировать историю только по этому пользователю, то ничего не отображается, а когда смотрю весь журнал регистрации, то вижу, что в колонке Имя пользователя данный пользователь написан как раньше, без отчества. Как же сформировать журнал регистрации по этому пользователю? Добрый день.
Какими средствами формируется журнал регистрации?
Дело в том, что в журнале регистрации не хранятся ссылки. В противном случае объекты (в данном случае пользователи) не смогут быть удалены, т.к. появятся битые ссылки. Имя пользователя фиксируется в журнале в том виде, какой он был на момент создания записи в журнале. Сейчас заметила, что если формировать журнал регистрации через Сервис - Журнал регистрации, то действительно имя указывается верное, то которое сейчас. А вот старое (до изменения) имя, не правильное, отображается, если формировать журнал регистрации через АРМ (администратор) на вкладке Журнал регистрации. С чем может быть связано различие, при формировании из разных мест? Добрый день.
Вы пробовали после внесенных изменений зайти через того пользователя, у которого изменили данные? да, пробовала, все зашлось. Но и после этого имя в журнале старое. Мне всех больше не понятно, почему при отборе по этому пользователю (из справочника пользователи) в журнале 0 позиций, хотя данный пользователь работает в базе В АРМ администратора выводится та информация, которую возвращает платформа. И именно имя пользователя это строка, которая фиксируется в журнале на момент возникновения события (это имя нами и выводится).
Что касается текущего имени в журнале (тот что формируется средствами платформы) то это уже какая то постобработка полученных данных.
Добавим индикатор текущего имени пользователя как отдельная колонка. Немного Вас не поняла. Где нужно добавить индикатор текущего имени пользователя? значит сейчас мне никак не посмотреть историю, выбрав этого пользователя? Все тоже самое можно смотреть и через Сервис - Журнал регистрации.
Добрый день.
Не стал создавать новой темы.
У нас возникла проблема с журналом регистрации - зависает.

Конфигурация Альфа Авто Автосалон 5
Релиз 5.0.05.08
Платформа 8.2.16.368

Конфигурация сервера E5430 2,66 12Gb ОЗУ
WinServer 2008 R2
БД SQL 2008 Standart

Количество пользователей 15-20 человек.

БД Альфа ведется с начала 2012 года с учетом выгруженной из старой БД.
Объем документов примерно 20-40 заказ нарядов в день.

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

А просматривать и фильтровать журнал по пользователям в настоящий момент нужно постоянно.

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

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

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

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

Мы поставили перед собой задачу сократить открытие такой формы до времени <= 30 секунд.

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

Используется трехзвенная клиент-серверная архитектура с доступом тонкого клиента через веб-сервер. Сервер СУБД и Сервер 1С:Предприятия совмещены на одной машине.

Сервер СУБД
- Процессор: Intel Xeon CPU E5-2637 v2, 2 процессора 3,5 Ghz.
- Память: 96 GB (разрешено потреблять СУБД не более 73728 MB).
- Жесткий диск SSD.
- MSSQLServer 2014 (12.0.4237.0).
- MS Windows NT 6.1 (7601).
Сервер «1С:Предприятие»
- Тот же сервер, что и сервер СУБД.
- Память: доступна вся свободная память, то есть, не менее 24576 MB.
Веб-сервер
- Процессор: Intel core 2 DUO E7500 2,93 GHz.
- Память: 4 GB.
- MS Internet Information Services 8.5.96.
- MS Windows Server 2012 R2.
Тонкий клиент
- Процессор: Intel Core i5.
- Память: 16 GB.
- Диск SSD.
- 1С 8.3.14.1694 — тонкий клиент.
- MS Windows 10.
Ищем причину медленного открытия формы и устраняем ее в «1С»

1. Для начала расследования снимаем замер производительности в «1С» процесса открытия формы

В замере видно, что лидер по абсолютному времени выполнения — метод «ОткрытьФорму».

Из 104 секунд открытия 64 приходятся на этот метод.

При этом сделать вывод о причинах медленного открытия из этого замера невозможно.

2. Соберем технологический журнал для анализа медленного открытия

Какие события собираем

Собираем события CALL и SCALL.

Выдержка из документации по платформе:
- SCALL — исходящий удаленный вызов (исходящий вызов на стороне источника вызова).
- CALL — входящий удаленный вызов (удаленный вызов на стороне приемника вызова).
Эти события возникают при клиент-серверном взаимодействии.

Бытует мнение, что SCALL всегда возникает при обращении с клиента на сервер, а CALL — при приходе этого обращения на сервер.

Нередко это так и есть, например, когда клиент обращается к серверу.

Однако это не всегда так. Например, могут быть обращения внутри сервера между менеджером кластера и рабочим процессом, между сервером и клиентом и так далее.

Пример иного случая возникновения событий CALL и SCALL.

Цели сбора

Преследуем 2 цели:
- посмотреть длинные по времени вызовы;
- найти «лаги» в технологическом журнале.
С длинными вызовами вопросов не возникает: есть оператор программы, который длится слишком долго, и это можно в явном виде обнаружить в ТЖ. По сути, хотим увидеть то же, что в замере производительности.

Что такое «лаг технологического журнала»? Под ним понимается ситуация, когда в явном виде событий с большим временем исполнения в журнале нет, но косвенно об этом догадываемся за счет присутствия большой паузы между двумя соседними событиями в журнале по одной сессии.

Метод сбора

Метод сбора технологического журнала (далее — ТЖ) — обычный:
- в папке C:\Program Files\1cv8\conf создаем файл logcfg.xml (структура файла ниже);
- ждем, пока в папке с логами, указанной в logcfg, появятся подпапки с именами процессов сервера;
- выполняем открытие формы;
- убираем файл logcfg.xml из папки;
- ждем не более 5 минут, пока система завершит запись файлов журнала;
- забираем файлы технологического журнала из подпапки rphost_<номер процесса>.
В нем настроено:
- папка для сбора логов C:\logs;
- отбор по событиям CALL и SCALL;
- отбор по имени базы rarus_fb.
Анализируем данные собранного лога технологического журнала. Нехитрым скриптом посмотрим наиболее долгие вызовы.

Примечание по скрипту

По сути, скрипт отбирает из ТЖ события, с длительностью от 2 знаков (с 10 секунд и более). Т. к. время в ТЖ 8.3 — в микросекундах, то нам нужен отбор по времени > 8 разрядов; чтобы не писать много букв в регулярном выражении, используем синтаксис расширенных регулярных выражений: , который включается ключом -E.

Видим, что существует долгое событие CALL длительностью 85 секунд, на котором происходит большое потребление памяти 554 Мб, а в пике 701 Мб и оно возникает на методе ПолучитьФорму.

Соберем лаги ТЖ.

Сделаем это более сложным скриптом, суть которого в том, чтобы сравнить по времени 2 соседних события ТЖ и найти среди них наибольшие паузы.
- в скрипте делаем отбор по t:clientID, равному ID нашего клиента, чтобы учесть только события по текущему пользователю.
В результате получаем:

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

Видно, что первым номером идет лаг, сопоставимый по времени с временем открытия формы.

Делаем предположение, о том, что тяжелая форма долго загружается с сервера на клиент.

3. Посмотрим на форму в конфигураторе

Что же такое разработчик заложил на форме? Может быть данные формы перегружены избыточной информацией?

Важный элемент расследования — просто посмотреть на творение рук разработчика глазами в конфигураторе «1С».

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

А строк совсем немало. И всё это при открытии перегружается с сервера на клиент.

Убедимся в этом тезисе.

4. Используем Fiddler в режиме ReverseProxy

Чтобы окончательно убедиться в том, что медленная работа обусловлена «большими» данными формы и понять, что именно это за данные, перехватим их.

Режим Reverse proxy позволяет «вставить Fiddler в разрыв» между веб-сервером и клиентом и проанализировать пакеты обмена.

Настройка Fiddler в режиме ReverseProxy

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

Настройка режима состоит на верхнем уровне из двух этапов:
- настроить на веб-сервере переадресацию url-rewrite на сервер с Fiddler’ом;
- настроить сам Fiddler.
Для настройки веб-сервера вводим правило url-rewrite на сервер finsrv, порт 8888, на котором будет слушать Fiddler.

Устанавливаем на отдельный сервер наш Fiddler и настраиваем в режиме Reverse proxy, как описано здесь.
Отслеживаем взаимодействие между веб-сервером и клиентом «1С»

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

Видим входящий запрос с большим объемом данных.

Предполагаем, что это и есть данные формы. Смотрим подробности данных в правом окне:

Обращаем внимание, что прочитать можно только заголовки, а данные, похоже, сжаты, о чем также свидетельствует надпись 1C‑SDCversion и далее — MZ, что соответствует началу сжатой части.
- По 1C-SDCversion — ищем на партнерском форуме «1С» и встречаем упоминание о том, что это метод сжатия deflate.
Вспоминаем, что по умолчанию клиент «1С» запрашивает работу со сжатием данных между клиентом и сервером.

С помощью запуска тонкого клиента со специальным параметром отключаем этот режим.

Делаем повторное открытие формы и видим в Fiddler’е уже вполне читаемую картину.

Обращаем внимание, что без сжатия данные формы весят более 1 Мб, что немало.

Наконец справа видим данные формы:

Переходим на представление «TextView», копируем в буфер и сохраняем как xml.

Обращаем внимание на наличие больших блоков в ветке props c внушительным количеством строк, которое сопоставимо с числом строк таблиц значений на форме:

а также со свойством fullChanged="true". Последнее скорее всего означает разрешение на изменение строк объекта на клиенте.

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

С точки зрения функционирования алгоритма они не требуются на клиенте. Принимаем решение избавиться от таблиц значений на клиенте.

5. Разгружаем форму в «1С»

Что тяжелее всего?
- На форме есть таблицы значений с большим числом строк.
- Обработка объект содержит табличные части с большим числом строк.
Отказываемся от использования таблиц значений на форме и табличных частей в пользу такого подхода:
- на сервере создаем таблицы значений;
- при переходе на клиента помещаем их во временное хранилище, а на форме храним только его адрес;
- после возврата на сервер получаем таблицы значений из временного хранилища.
6. Смотрим в Fiddler результат «разгрузки» формы

Видно, что объем данных формы сократился более чем в 5 раз.

7. Делаем повторный замер производительности и смотрим потребление памяти и лаги в ТЖ

Накатываем изменения на рабочую базу, собираем замер производительности «1С».

Видим, что теперь открытие формы экземпляра бюджета составляет 25 секунд, а метод ОткрытьФорму — всего 2,1 секунды.

Читайте также: