tc_app get_current_error зависает на ошибке из обработчика объекта и рассинхронизирует соединение

[afk-yar]

Версия: 1c-testpilot 1.5.0 (коммит 701630a), платформа 8.3.27.2074, тонкий клиент,
файловая база 1С:ERP 2.5.27.79.

Что происходит

На окне ошибки, которое открылось вместо формы, tc_app(action="get_current_error")
не получает ответа. Вызов висит до таймаута (по умолчанию 30 с, с
set_max_action_time(10) — 10 с) и возвращает timed out. После этого соединение
рассинхронизировано: все следующие вызовы падают с
the connection desynchronised after a timeout: 1 answer(s) to earlier commands were never received — call tc_disconnect and tc_connect, пока не выполнить disconnect + connect.

Как воспроизвести

1. tc_window(action="execute_command", command="e1cib/data/Документ.АктОРасхожденияхПослеОтгрузки.Форма.ФормаДокумента")
   — новый документ без основания. Ответ: ok: false, code: navigation_failed,
   form_name: ErrorWindow. Исключение брошено в ОбработкаЗаполнения модуля объекта через
   общий модуль (вложенная ошибка: «Ошибка при выполнении обработчика - 'ОбработкаЗаполнения'
   по причине: …»).
2. tc_app(action="get_current_error") → через 30 с Error executing tool tc_app: timed out.
3. Любой следующий вызов → connection desynchronised.

Контроль: e1cib/data/Документ.СчетНаОплатуКлиенту.Форма.ФормаДокумента — тоже окно ошибки,
но исключение из ПриСозданииНаСервере модуля формы (одноуровневое). Там get_current_error
отвечает сразу.

Это не платформа

На том же окне той же базы официальный менеджер тестирования (сценарий Тестера
ПодробноеПредставлениеОшибки(Приложение.ПолучитьТекущуюИнформациюОбОшибке())) получил ответ
за 2,3 с — полный двухуровневый стек:

Ошибка при выполнении обработчика - 'ОбработкаЗаполнения'
по причине:
A type of base documents for the discrepancy report is not specified when creating the document.
{ОбщийМодуль.РасхожденияСервер.Модуль(607)}:ВызватьИсключение ...
{Документ.АктОРасхожденияхПослеОтгрузки.МодульОбъекта(129)}:РасхожденияСервер.ПроверитьТипОснованияАктаПриСоздании(ЭтотОбъект);

Для контрольной формы — 2,6 с. Значит, клиент 1С на GetCurrentErrorInfo отвечает, а
testpilot ответ не принимает. Гипотеза: разбор ответа с вложенной причиной
(ИнформацияОбОшибке.Причина) в tc_get_current_error (server.py, ERR_MIDDLE = e041,
pad=4) — ответ другой структуры не распознается как ответ на команду.

Чего хотелось бы

1. Разбор ответа GetCurrentErrorInfo с вложенной причиной.
2. Независимо от п.1: таймаут одного read-вызова не должен рвать все соединение — либо
   дочитывать/отбрасывать запоздавший ответ, либо переподключаться автоматически.

Обход сейчас

Текст ошибки читается из элемента ErrorInfo окна ошибки:
tc_find(action="find_objects", name="ErrorInfo", root_ref=<ref окна>) — поле title,
без зависания. Но для исключений из модуля формы там общий текст «К сожалению, возникла
непредвиденная ошибка…», и настоящий текст дает только get_current_error.

[afk-yar]

Воспроизводится и на 1.7.0 (b3eeba0), тот же стенд, те же две формы:

tc_app:set_max_action_time -> max_action_time: 10
АктОРасхожденияхПослеОтгрузки.ФормаДокумента:
  tc_window:execute_command 0.41 с -> ok: false, navigation_failed, ErrorWindow
  tc_find:find_objects(ErrorInfo) 0.00 с -> текст ошибки читается
  tc_app:get_current_error 10.01 с -> Error executing tool tc_app: timed out
  после disconnect + connect работа продолжается
СчетНаОплатуКлиенту.ФормаДокумента (контроль):
  tc_app:get_current_error 0.01 с -> ok: true, error: "{Документ.СчетНаОплатуКлиенту.Форма.ФормаДокумента.Форма(26)}: ..."

Код tc_get_current_error между 1.5.0 и 1.7.0 не менялся. Возможно, механизм тот же, что в п. 3 issue #3: _binary_frame_end не находит конец кадра ответа, дальше таймаут и рассинхронизация.

[ksv47]

Проверили 1.7.1 (4f7ce83) на Linux, тонкий клиент 8.3.27.2214, отдельная файловая тестовая база. Прогон выполнен 24 сентября.

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

• На 1.7.0 тот же сценарий: get_current_error завершается таймаутом через 10,01 с; следующий вызов не проходит из-за рассинхронизации, остановка клиента принудительная.
• На 1.7.1: ответ за 0,03 с, error содержит ошибку обработчика, details содержит вложенную причину и ссылки на общий модуль и модуль объекта. Следующее чтение активного окна проходит, клиент завершается штатно (shutdown: graceful).

На нашем воспроизведении проблема исправлена. Исходную ERP из сообщения автора issue не проверяли.