Очень медленная реакция подсказки в конце большого модуля

Нашел похоже этот фрагмент в логе

Ссылка скрыта

В нем есть строка, выводимая Турбоконфом:

---Ощеее время T9 = 560ms

Что примерно соответствует наблюдению. Но в служебных сообщениях не видно этой строки.

А в быстром тесте (в начале модуля) вижу в логе строку

---Ощеее время T9 = 95ms

Проблема очевидно тут

[27.04.25 16:46:04:957] GetUIAutomationCachedInfo() 33ms, total calls 230
[27.04.25 16:46:04:957] Set CurText, length = 1091448
[27.04.25 16:46:04:957] Set CurrentPos =929382
[27.04.25 16:46:04:957] Set CurSelectedText, length = 0
[27.04.25 16:46:05:359] char = '
', hasCloseWord: False
[27.04.25 16:46:05:359] T9CurrentControlType=документ

Те самые 400мс

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

Я давно уже сохраняю такие параметры сеанса

Процедура УстановитьРежимЗаменыШтатнойПодсказки(Знач НовоеЗначение) Экспорт
	ТурбоКонф.СохранитьЗначениеСеанса(Строка(Конфигуратор.ГлавноеОкно)+"_"+"T9AlwaysShowOnCtrlSpace", НовоеЗначение);
ТурбоКонф.СохранитьЗначениеСеанса(Строка(Конфигуратор.ГлавноеОкно)+"_"+"T9AllowAutoInvokeInsideCommonStrings", НовоеЗначение);
КонецПроцедуры

Думал их будет достаточно.

(4) tormozit, где здесь флаг конфигуратора "показывать подсказку после точки"?

(5) bolsun, эти параметры я всегда устанавливаю одновременно с подавлением штатной подсказки. Могу добавить еще один.

(6) tormozit, ты проверяешь этот флаг в последующих сеансах? Вдруг пользователь включит его обратно.

Я про этот флаг

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

(9) tormozit, я могу убрать эту проверку, но возможны ошибки в случае если флаг окажется включенным.

(10) bolsun, понял, протестирую эту ситуацию

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

(12) bolsun, да, это слабое место у многих подобных механизмов - серию точек не тестируют. Но и реальный пользователь очень редко зажимает точку =) В моем коде кругом есть защита от такого. И в твоем уже тоже. Если говорить про скорость работы штатного анализатора кода конфигуратора в общем, то с учетом выделенных на него скромных трудочасов наверное это нормальная скорость.

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

6.4.9250.27909
https://disk.yandex.ru/d/HalnaWbUugl0Cw

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

(15) bolsun, Теперь реакция стала очень быстрой. Позже еще буду делать тесты с нетипичными настройками.

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

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

Прошу в Турбоконфе при появлении окна штатной подсказки при включенном флаге T9AlwaysShowOnCtrlSpace вызывать метод скрипта "ПриПоявленииШтатнойПодсказки". Там я буду показывать уведомление с действием отключения подсказок конфигуратора.

Проблема вернулась

Строка  668: [25.06.25 10:53:53:717] ---Общее время T9 = 785ms
Строка  918: [25.06.25 10:53:56:978] ---Общее время T9 = 609ms
Строка 1244: [25.06.25 10:53:59:599] ---Общее время T9 = 605ms

Ссылка скрыта

(18) tormozit, ищи причину у себя

Замер: Время выполнения скрипта ИРАдаптер->ПриПолученииДанныхТ9: 592 ms

[25.06.25 10:53:53:200] -Передача текста модуля 124 мс
[25.06.25 10:53:53:211] -Разбор позици в модуле 11 мс
[25.06.25 10:53:53:216] Обновление поля текста программы 156 мс
[25.06.25 10:53:53:219] Расчет типов контекста 3 мс
[25.06.25 10:53:53:408] Заполнение слов контекста 189 мс
[25.06.25 10:53:53:469] Время передачи набора слов "Глобальный;0;;Нет;;Нет;Истина;Нет;;;Нет;Нет;Нет" = 23 мс
[25.06.25 10:53:53:495] Время передачи набора слов "" = 8 мс
[25.06.25 10:53:53:501] Время передачи 93 мс

Вот тут смотри - та же ситуация, что была в исходном логе (2) заявки

[25.06.25 10:53:59:090] Set CurSelectedText, length = 0
Куда делись 400 мс? Скрипт тут не участвует.
[25.06.25 10:53:59:539] T9CurrentControlType=документ
...
[25.06.25 10:53:59:590] Замер: ShowT9() ПриПолученииДанныхТ9() time = 41ms

Полный фрагмент:

[25.06.25 10:53:59:065] ------------------Положение курсора изменилось---------------------
[25.06.25 10:53:59:065] oldPos = ; newPos =
[25.06.25 10:53:59:065] GetUIAutomationInfoAsync()... title=Общий модуль ирКлиент: Модуль - Конфигуратор - КомплекснаяАвтоматизация,curFg=3348972,fg=3348972
[25.06.25 10:53:59:065] GetUIAutomationCachedInfoAsync()... title=Общий модуль ирКлиент: Модуль - Конфигуратор - КомплекснаяАвтоматизация,curFg=3348972,fg=3348972
[25.06.25 10:53:59:065] GetUIAutomationCachedInfo()... title=Общий модуль ирКлиент: Модуль - Конфигуратор - КомплекснаяАвтоматизация,curFg=3348972,fg=3348972
[25.06.25 10:53:59:065] CurrentDocumentRuntimeId=
[25.06.25 10:53:59:069] curFg=Общий модуль ирКлиент: Модуль - Конфигуратор - КомплекснаяАвтоматизация, curFg=3348972
[25.06.25 10:53:59:069] controlType: документ
[25.06.25 10:53:59:069] name:
[25.06.25 10:53:59:078] text.Length=939488
[25.06.25 10:53:59:078] selectedRange.Length=1
[25.06.25 10:53:59:090] result.CurrentRangeText.Length=939488
[25.06.25 10:53:59:090] result.Position=939488
[25.06.25 10:53:59:090] doc.Position = 939488
[25.06.25 10:53:59:090] CurrentDocumentRuntimeId=42 3348972 4 642486844
[25.06.25 10:53:59:090] Set LastDocument for pid=38060 42 3348972 4 642486844
[25.06.25 10:53:59:090] Set SetLastElement for wnd=3348972
[25.06.25 10:53:59:090] GetUIAutomationCachedInfo() 25ms, total calls 16
[25.06.25 10:53:59:090] Set CurText, length = 939488
[25.06.25 10:53:59:090] Set CurrentPos =939488
[25.06.25 10:53:59:090] Set CurSelectedText, length = 0

Куда делись 400 мс? Скрипт тут не участвует.

[25.06.25 10:53:59:539] T9CurrentControlType=документ
[25.06.25 10:53:59:539] Set CurrentPos =939488
[25.06.25 10:53:59:539] Set CurSelectedText, length = 0
[25.06.25 10:53:59:539] Warning: Автовызов = True
[25.06.25 10:53:59:539] Замер: ShowT9() CheckAndDisableOverlayTopMost() time = 0ms
[25.06.25 10:53:59:539] Запускаем обработчик ПередПолучениемДанныхТ9 в скрипте ...
[25.06.25 10:53:59:539] ExecuteScript user_scripts\RDT.os, entryPoint=ПередПолучениемДанныхТ9, title=Общий модуль ирКлиент: Модуль - Конфигуратор - КомплекснаяАвтоматизация
[25.06.25 10:53:59:539] TurboMenuButton Hide()
[25.06.25 10:53:59:541] IdentifyDocument() info.RuntimeId=42 3348972 4 642486844, controlType=документ, className=V8TopLevelFrame, title=Общий модуль ирКлиент: Модуль - Конфигуратор - КомплекснаяАвтоматизация
[25.06.25 10:53:59:541] Документ идентифицирован: ИмяДокумента:Общий модуль ирКлиент: Модуль, ИмяКонфигурации:КомплекснаяАвтоматизация, ЭтоРасширение=False
[25.06.25 10:53:59:542] docInfo=ScriptEngine.HostedScript.Library.StructureImpl
[25.06.25 10:53:59:543] Обработчик ПередПолучениемДанныхТ9 - 1 мс
[25.06.25 10:53:59:543] NeedReleaseModifiers: False
[25.06.25 10:53:59:543] Флаг ContinueKeyEventHandling = False
[25.06.25 10:53:59:543] Set SafeKeyboardMode = False
[25.06.25 10:53:59:543] Замер: Время выполнения скрипта ИРАдаптер->ПередПолучениемДанныхТ9: 3 ms
[25.06.25 10:53:59:543] СтандартнаяОбработка = False
[25.06.25 10:53:59:543] Замер: ShowT9() ПередПолучениемДанныхТ9() time = 3ms
[25.06.25 10:53:59:543] Set IsHybridMode=False
[25.06.25 10:53:59:543] value==_isHybridMode exit...
[25.06.25 10:53:59:547] Замер: ShowT9() Init time = 4ms
[25.06.25 10:53:59:548] Set CurText, length = 939488
[25.06.25 10:53:59:548] Запускаем обработчик ПриПолученииДанныхТ9 в скрипте ...
[25.06.25 10:53:59:548] ExecuteScript user_scripts\RDT.os, entryPoint=ПриПолученииДанныхТ9, title=Общий модуль ирКлиент: Модуль - Конфигуратор - КомплекснаяАвтоматизация
[25.06.25 10:53:59:548] IdentifyDocument() info.RuntimeId=42 3348972 4 642486844, controlType=документ, className=V8TopLevelFrame, title=Общий модуль ирКлиент: Модуль - Конфигуратор - КомплекснаяАвтоматизация
[25.06.25 10:53:59:548] Документ идентифицирован: ИмяДокумента:Общий модуль ирКлиент: Модуль, ИмяКонфигурации:КомплекснаяАвтоматизация, ЭтоРасширение=False
[25.06.25 10:53:59:548] docInfo=ScriptEngine.HostedScript.Library.StructureImpl
[25.06.25 10:53:59:555] -ЗаголовокОкна = Общий модуль ирКлиент: Модуль - Конфигуратор - КомплекснаяАвтоматизация
[25.06.25 10:53:59:559] ИмяКонфигурации = КомплекснаяАвтоматизация
[25.06.25 10:53:59:559] Заголовок документа = Общий модуль ирКлиент: Модуль
[25.06.25 10:53:59:560] -Определение имени модуля 5 мс
[25.06.25 10:53:59:560] -Сжатое имя модуля = ОбщийМодуль.ирКлиент.Модуль
[25.06.25 10:53:59:570] -Передача текста модуля 10 мс
[25.06.25 10:53:59:576] -Разбор позици в модуле 6 мс
[25.06.25 10:53:59:577] -Язык: 0, Модуль: ОбщийМодуль.ирКлиент.Модуль, Метод: <Инициация>, Позиция: 939488, Выражение: РежимАвтоВремя.
[25.06.25 10:53:59:577] Обновление поля текста программы 22 мс
[25.06.25 10:53:59:580] Расчет типов контекста 3 мс
[25.06.25 10:53:59:585] Заполнение слов контекста 5 мс
[25.06.25 10:53:59:586] СохранитьЗначениеСеансаКонфигуратора. СеансБазы=38060;ПодключениеИР.Кэш=Соответствие
[25.06.25 10:53:59:588] Время передачи набора слов "" = 1 мс
[25.06.25 10:53:59:589] Время передачи 4 мс
[25.06.25 10:53:59:589] Выражение = РежимАвтоВремя.. Найдено типов 1. Слов передано 5, выведено 5. Основной тип = ПеречислениеРежимАвтоВремя
[25.06.25 10:53:59:590] NeedReleaseModifiers: False
[25.06.25 10:53:59:590] Флаг ContinueKeyEventHandling = False
[25.06.25 10:53:59:590] Set SafeKeyboardMode = False
[25.06.25 10:53:59:590] Замер: Время выполнения скрипта ИРАдаптер->ПриПолученииДанныхТ9: 41 ms
[25.06.25 10:53:59:590] Замер: ShowT9() ПриПолученииДанныхТ9() time = 41ms
[25.06.25 10:53:59:590] Filtering... '', items count = 0
[25.06.25 10:53:59:593] Замер: Add 5 items to T9 time 3 ms
[25.06.25 10:53:59:594] _maxDataGridViewHeight=214
[25.06.25 10:53:59:594] dataGridView1.RowTemplate.Height=19
[25.06.25 10:53:59:594] Height=117
[25.06.25 10:53:59:594] dataGridView1.Height=97
[25.06.25 10:53:59:595] Width=440
[25.06.25 10:53:59:595] Set FirstDisplayedScrollingRowIndex = 0
[25.06.25 10:53:59:596] SetPosition(False)
[25.06.25 10:53:59:596] caretPos=
[25.06.25 10:53:59:596] rect=-8,16,2568,1408
[25.06.25 10:53:59:596] zeroOriginPoint=
[25.06.25 10:53:59:596] hExpected=31
[25.06.25 10:53:59:596] hReal=31
[25.06.25 10:53:59:596] pt=
[25.06.25 10:53:59:596] GetWorkingArea=
[25.06.25 10:53:59:596] _isOverlay=False
[25.06.25 10:53:59:598] T9Form position: Left=521, Top=1045
[25.06.25 10:53:59:598] Set StopCurline =
[25.06.25 10:53:59:598] Замер: ShowT9() Total time = 58ms
[25.06.25 10:53:59:598] Set IsProcess: False
[25.06.25 10:53:59:598] Set ClipCursorPosition =
[25.06.25 10:53:59:598] Set PasteForm.IsVisible = False
[25.06.25 10:53:59:598] Set ProtectedWindow = 0
[25.06.25 10:53:59:599] Queue 1:
[25.06.25 10:53:59:599]
[25.06.25 10:53:59:599] Send
[25.06.25 10:53:59:599] KeyboardHookManagerOnKeyUp(): OemQuestion
[25.06.25 10:53:59:599] Received await = OemQuestion IsProcess=False, IsQueueInProgress=True, (568,0994 ms) fg=3319ec title=Общий модуль ирКлиент: Модуль - Конфигуратор - КомплекснаяАвтоматизация, KeyData=OemQuestion
[25.06.25 10:53:59:599] Key up OemQuestion has passed to window 3319ec
[25.06.25 10:53:59:599] Send queue completed: 1
[25.06.25 10:53:59:599] _needUpdateCurrentText = True
[25.06.25 10:53:59:599] Закрываем оверлей...
[25.06.25 10:53:59:599] ---Общее время T9 = 605ms

Я ничего не менял, если раньше работало быстро, а теперь перестало - проверь на предыдущих платформах, на которых работало быстро, например 8.3.27.1496

Проверил на 8.3.23.2040 - проблема повторяется.

(22) tormozit, пришли лог вызова в начале текста

Скачал версию 6.4.9250.27909 из (15) - там проблемы нет

(23) bolsun, Ссылка скрыта

(24) tormozit, да, эту правку не внесли в текущую версию, поэтому такое поведение.

добавлю

(26) bolsun, Вероятно из-за (17). Может ты хотел там что то доделать?

(28) tormozit, я там ничего не могу доделать, т.к. если подсказка после точки включена, а проверка отключена, то будут возникать ошибки.

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

6.4.9307.25769
https://disk.yandex.ru/d/XRPUNWQtrbwBUw

(31) bolsun, Проверил. Исправлено.

(30) bolsun, тогда пока закрываю
tormozit изменил статус на Закрыто