Работа с отладочной информацией
Ядро платформы формирует отладочную информацию, которая отражает происходящие процессы и результаты работы. Данная информация выводится на уровне отладчиков операционной системы, поэтому не доступна в среде разработки «Форсайт. Аналитическая платформа». Доступ к отладочной информации можно получить, используя приложение DebugView, которое входит в пакет программ Sysinternals. Запустите приложение DebugView, проверьте настройку «Capture Win32» в пункте главного меню «Capture». Если настройка выключена, то включите её.
После этого в лог будет выводиться отладочная информация, формируемая ядром инструментов «Форсайт. Аналитическая платформа».
Пример лога DebugView с информацией из «Форсайт. Аналитическая платформа»:
...
1 0.00000000 [9556] INTL-SetLocale: Russian_RUS.1251
2 0.00064479 [9556] LICENSE: Requesting feature "AnalyticsPlatform" v9...
3 0.01438539 [9556] LSDURATION: LSRequest 0.014 s
4 0.01475035 [9556] LICENSE: Accepted request for feature "AnalyticsPlatform" from license.server
5 0.01552302 [9556] INFO: Audit user: FSAUDIT, source: registry HKLM
6 0.02441553 [9556] PREPARED SQL: exec [Warehouse].[dbo].B_SEC_DAT_VALUE :IDS, :RESLO OUT
7 0.02447300 [9556] PARAMS:
8 0.02447300 [9556] IDS = AUDITOR
9 0.02447300 [9556] RESLO =
10 0.02644256 [9556] PREPARED SQL: exec [Warehouse].[dbo].B_SEC_DAT_VALUE :IDS, :RESLO OUT
11 0.02650244 [9556] PARAMS:
12 0.02650244 [9556] IDS = PSWSTR,ROLESTR,CHPSW
13 0.02650244 [9556] RESLO =
14 0.04149621 [9556] PREPARED SQL: USE Warehouse
15 0.04322175 [9556] PREPARED SQL: select b.name from Warehouse.dbo.sysusers b where b.sid = SUSER_SID(N'SA')
16 0.04322175 [9556]
17 0.04471623 [9556] PREPARED SQL: select schema_name()
18 0.04471623 [9556]
19 0.04580421 [9556] PREPARED SQL: select schema_id(:schemaname)
20 0.04580421 [9556]
21 0.04585506 [9556] PARAMS:
22 0.04585506 [9556] schemaname = dbo
23 0.04680163 [9556] PREPARED SQL: select FILEGROUP_NAME( i.groupid ) from sysobjects o,sysindexes i where o.parent_obj = OBJECT_ID(:TableName) and o.xtype='PK' and o.name=i.name and o.parent_obj=i.id
24 0.04680163 [9556]
25 0.04684676 [9556] PARAMS:
26 0.04684676 [9556] TableName = dbo.B_OBJ
27 0.04976620 [9556] MB: SessionId for log = [2F8C0C99BA9740C5]
28 0.05006377 [9556] SETUP: [2F8C0C99BA9740C5] Key: HKEY_LOCAL_MACHINE\Software\Foresight\Foresight Analytics Platform\10.0\Service\Mbs\WAREHOUSE Value: endpoint = , NOT SET
29 0.05034991 [9556] PREPARED SQL: [2F8C0C99BA9740C5] set :A=SYSUTCDATETIME()
30 0.05039955 [9556] PARAMS: [2F8C0C99BA9740C5]
31 0.05039955 [9556] A =
32 0.05215339 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select max(a.VER) as VER from dbo.B_LAST a
33 0.05215339 [9556]
34 0.05301119 [9556] PREPARED SQL: [2F8C0C99BA9740C5] insert into dbo.B_LOGSEQ(V) values(1);set :A=cast(scope_identity() as int);
35 0.05306024 [9556] PARAMS: [2F8C0C99BA9740C5]
36 0.05306024 [9556] A =
37 0.05447739 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select :A=max(a.STAMP) from dbo.B_SEC a where a.SEC = 0
38 0.05452252 [9556] PARAMS: [2F8C0C99BA9740C5]
39 0.05452252 [9556] A =
40 0.05565323 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select a.BIN, a.BIN_HASH from dbo.B_SEC a where a.SEC = 0
41 0.05565323 [9556]
42 0.09871852 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select a.OBJ, a.CLS, a.ID, a.NAM, a.DES, a.PAR, a.STAMP, a.SD, a.ITL, a.SHC, a.LIN, a.APP, a.DEF, a.TRACK_DEP, a.MBSOURCE, a.VER , a.ONS from dbo.B_OBJ a where (a.OBJ = :A)
43 0.10037968 [9556]
44 0.10557197 [9556] PARAMS: [2F8C0C99BA9740C5]
45 0.10572121 [9556] A = 69949
46 0.10586804 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select a.OBJ, a.CLS, a.ID, a.NAM, a.DES, a.PAR, a.STAMP, a.SD, a.ITL, a.SHC, a.LIN, a.APP, a.DEF, a.TRACK_DEP, a.MBSOURCE, a.VER , a.ONS from dbo.B_OBJ a where (a.OBJ = :A)
47 0.10600735 [9556]
48 0.10614996 [9556] PARAMS: [2F8C0C99BA9740C5]
49 0.10630311 [9556] A = 122079
50 0.10648153 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select a.BIN from dbo.B_SD a where a.SD = :A
51 0.10662596 [9556]
52 0.10676978 [9556] PARAMS: [2F8C0C99BA9740C5]
53 0.10690878 [9556] A = 103051
54 0.10714136 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select a.OBJ, a.CLS, a.ID, a.NAM, a.DES, a.PAR, a.STAMP, a.SD, a.ITL, a.SHC, a.LIN, a.APP, a.DEF, a.TRACK_DEP, a.MBSOURCE, a.VER , a.ONS from dbo.B_OBJ a where (a.OBJ = :A)
55 0.10744585 [9556]
56 0.10759148 [9556] PARAMS: [2F8C0C99BA9740C5]
57 0.10773139 [9556] A = 88053
58 0.10789055 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select a.BIN from dbo.B_SD a where a.SD = :A
59 0.10824861 [9556]
60 0.10909408 [9556] PARAMS: [2F8C0C99BA9740C5]
61 0.10934471 [9556] A = 142941
62 0.10948492 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select a.BIN from dbo.B_SD a where a.SD = :A
63 0.10962844 [9556]
64 0.10982672 [9556] PARAMS: [2F8C0C99BA9740C5]
65 0.10996723 [9556] A = 142868
66 0.11013422 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select a.DAT, a.ID, a.VI, a.VS from dbo.B_SEC_DAT a
67 0.11028346 [9556]
68 0.11044714 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select a.STA, a.ID, a.TYP, a.DOM, a.ACC from dbo.B_SEC_STA a where a.TYP = :T and a.DOM = :D
69 0.11058734 [9556]
70 0.11072846 [9556] PARAMS: [2F8C0C99BA9740C5]
71 0.11087228 [9556] T = 1
72 0.11103987 [9556] D = 0
73 0.11124447 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select a.CER_K, a.FLG, a.ID, a.NAM, a.DAT from dbo.B_CER_V a
74 0.11162538 [9556]
75 0.11177522 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select SUSER_SNAME(b.sid) from Warehouse.dbo.sysusers b where upper(b.name) = 'DBO'
76 0.11191212 [9556]
77 0.11207159 [9556] PREPARED SQL: [2F8C0C99BA9740C5] exec dbo.B_LOGNSUC :USRLO, :USRSTA, :USRDOM, :RESLO OUT
78 0.11220999 [9556] PARAMS: [2F8C0C99BA9740C5]
79 0.11235863 [9556] USRLO = admin
80 0.11251780 [9556] USRSTA = IVANOV
81 0.11266041 [9556] USRDOM = WORK
82 0.11279912 [9556] RESLO =
83 0.11293933 [9556] PREPARED SQL: [2F8C0C99BA9740C5] insert into dbo.B_JLO(SES, STAMP, STAMP_OUT, US_SID, US_NAM, US_DES, US_STA, US_OS, US_IP, ALLO,CMNT,SES_ID, US_MAC) values(:A, :B, :C, :D, :E, :F, :G, :H, :I, :J,:CMNT, @@SPID, :K)
84 0.11308074 [9556] PARAMS: [2F8C0C99BA9740C5]
85 0.11322336 [9556] A = 307526
86 0.11336507 [9556] B = 27.03.2024 07:46:30.808
87 0.11354470 [9556] C = 22.12.2026 07:46:30.808
88 0.11368731 [9556] D = PS-1-1
89 0.11383475 [9556] E = ADMIN
90 0.11397555 [9556] F = Пользователь ADMIN
91 0.11412871 [9556] G = IVANOV
92 0.11461674 [9556] H = ivan.ivanov
93 0.11475875 [9556] I = 192.168.1.1;
94 0.11489866 [9556] J = 1
95 0.11503947 [9556] CMNT = Версия платформы: 10.4.10087.0 Master x64 Веб приложение
96 0.11518539 [9556] K = 94de806959dd
97 0.11533042 [9556] PREPARED SQL: [2F8C0C99BA9740C5] select a.SD, a.BIN from dbo.B_SD a where a.HSH = :A
...
Описание структуры лога представлено ниже.
Вывод дополнительной отладочной информации
По умолчанию в лог выводится следующая информация:
загружаемые и выгружаемые библиотеки платформы;
запросы к серверу СУБД;
сообщения компилятора Fore;
сообщения, выводимые в консоль среды разработки из прикладного кода;
время выполнения каких-либо операций;
ошибки.
При необходимости объем выводимой информации может быть расширен за счёт вывода отладочной информации.
При работе в ОС Linux вывод отладочной информации доступен только в файл. Для включения вывода отладочной информации используйте переменную окружения PP_LOG, установите для неё значение 1. Отладочная информация будет выводиться в файл /var/log/apache2-fp10.x/error.log.
Для расширения объема выводимой информации при работе в ОС Windows могут быть добавлены следующие ключи в реестре:
в ветке [HKEY_CURRENT_USER\Software\Foresight\Foresight Analytics Platform\10.0\Debug]:
Параметр GCTrace типа REG_DWORD со значением «1» - для вывода сообщений сборщика мусора среды разработки;
Параметр MsDump типа REG_DWORD со значением «1», «2» или «3» - для вывода сообщений при расчёте задач моделирования;
Параметр RdsSelectLog типа REG_DWORD со значением «1» - для вывода запросов, формируемых при работе с табличными справочниками НСИ.
в ветке [HKEY_CURRENT_USER\Software\Foresight\Foresight Analytics Platform\10.0\Scheduler]:
Параметр Trace типа REG_DWORD со значением «3» - для вывода отладочной информации планировщика задач.
в ветке [HKEY_CURRENT_USER\Software\Foresight\Foresight Analytics Platform\10.0\DevEnv]:
Параметр DevEnvDebug типа REG_DWORD со значением 1 - для получения сообщений о создании компонентов среды разработки;
Параметр DevEnvParserDebug типа REG_DWORD со значением 1 - для получения сообщений парсера среды разработки.
Отладочная информация может быть выведена в отдельный файл. Для этого в ветке реестра [HKEY_CURRENT_USER\SOFTWARE\Foresight\Foresight Analytics Platform\10.0] создайте подраздел Log. В подразделе создайте строковый параметр FileName, укажите в нём путь и наименование файла, в который будет выводиться отладочная информация.
При работе с BI-сервером «Форсайт. Аналитическая платформа» все указанные выше ключи создаются в ветке реестра [HKEY_LOCAL_MACHINE].
Важно. Включение вывода дополнительной отладочной информации может привести к замедлению работы системы и дополнительным затратам ресурсов. После завершения отладочных работ необходимо отключить вывод, задав соответствующим ключам значение 0 или удалив их из реестра. Также для повышения производительности можно полностью отключить вывод отладочной информации, для этого в ветке реестра [HKEY_CURRENT_USER\SOFTWARE\Foresight\Foresight Analytics Platform\10.0\Log] параметру WriteToDebugOutput установите значение 0. При работе в ОС Linux удалите/закомментируйте переменную окружения PP_LOG.
Более подробная информация о доступных флагах, их назначении и допустимых значениях представлена в подразделе базы знаний «Дополнительные настройки «Форсайт. Аналитическая платформа»».
Структура лога
Для понимания, что отражено в отладочной информации, все сообщения помечаются тегами, которые определяют каким блоком сгенерировано сообщение или какую информацию в себе несёт. Тег и само сообщение разделяются символом «:».
При подключении к репозиторию генерируется уникальный идентификатор сессии:
MB: SessionId for log = [2F8C0C99BA9740C5]
Последующие действия также включают в себя данный идентификатор. Это позволяет разделять запросы, отправляемые в рамках различных подключений к репозиториям. Также в начале сессии выводится информация о пользователе, который осуществляет подключение:
78 0.11220999 [9556] PARAMS: [2F8C0C99BA9740C5]
79 0.11235863 [9556] USRLO = admin
80 0.11251780 [9556] USRSTA = IVANOV
81 0.11266041 [9556] USRDOM = WORK
82 0.11279912 [9556] RESLO =
83 0.11293933 [9556] PREPARED SQL: [2F8C0C99BA9740C5] insert into dbo.B_JLO(SES, STAMP, STAMP_OUT, US_SID, US_NAM, US_DES, US_STA, US_OS, US_IP, ALLO,CMNT,SES_ID, US_MAC) values(:A, :B, :C, :D, :E, :F, :G, :H, :I, :J,:CMNT, @@SPID, :K)
84 0.11308074 [9556] PARAMS: [2F8C0C99BA9740C5]
85 0.11322336 [9556] A = 307526
86 0.11336507 [9556] B = 27.03.2024 07:46:30.808
87 0.11354470 [9556] C = 22.12.2026 07:46:30.808
88 0.11368731 [9556] D = PS-1-1
89 0.11383475 [9556] E = ADMIN
90 0.11397555 [9556] F = Пользователь ADMIN
91 0.11412871 [9556] G = IVANOV
92 0.11461674 [9556] H = ivan.ivanov
93 0.11475875 [9556] I = 192.168.1.1
94 0.11489866 [9556] J = 1
95 0.11503947 [9556] CMNT = Версия платформы: 10.4.10087.0 Master x64 Веб приложение
96 0.11518539 [9556] K = 94de806959dd
В дальнейшем используются следующие теги для обозначения сообщений:
Основные типы отладочных сообщений:
SQL или PREPARED SQL. Запрос, выполняемый к серверу СУБД;
PARAMS. Набор параметров, передаваемых вместе с запросом;
FORE. Сообщения, выводимые компилятором языка Fore;
$DBG. Сообщения, выводимые при выполнении прикладного кода на Fore с помощью методов класса Debug;
EXCEPTION. Различные виды ошибок;
DURATION. Время выполнения какого-либо метода или действия.
Инструменты, с которыми связано отладочное сообщение:
[ms$]. Сообщение, сгенерированное при работе инструментов моделирования и прогнозирования, алгоритмов расчёта;
[eax$]. Сообщение, сгенерированное при работе с экспресс-отчётами;
ADHOC. Сообщение, сгенерированное при работе с аналитическими панелями;
INMEM. Выполнение каких-либо действий, связанных с кэшированием In-Memory: получение данных из кэша, сохранение данных в кэш и другие;
JAVA. Сообщения, связанные с выполнением кода на Java;
Python. Сообщения, связанные с выполнением кода на Python;
VCS. Сообщения, связанные с работой системы управления версиями.
Разбор лога
В первую очередь проверьте наличие сообщений об ошибках. Для этого воспользуйтесь поиском по тексту ключевого слова Exception. Для поиска используйте стандартное сочетание клавиш CTRL+F, для продолжения поиска - F3. Пример возможной ошибки:
...
[15612] EXCEPTION_CLASS: CPiException
[15612] EXCEPTION: TEXT: Обращение к еще не созданному объекту
[15612] EXCEPTION: Caught ..\Mod\Fore\Frt\FrtBindableObjects.cpp(2297) at long __cdecl CForeBindableSub::Invoke(void)
[15612] EXCEPTION: Caught ..\Mod\Fore\Frt\kxInterpreterObjects.cpp(1288) at long __cdecl CEventSink::Invoke(long,const struct _GUID &,unsigned long,unsigned short,struct tagDISPPARAMS *,struct tagVARIANT *,struct tagEXCEPINFO *,unsigned int *)
[15612] CPiException caught in CPiApp::Run. Recovering...
[15612] UXEVENT: 2167614:9280:Menu: Start WM_COMMAND event: 1
[15612] UXEVENT: 2167614:9280:Menu: Finish WM_COMMAND event: 1, Total time: 4.00005374103785
[15612] EXCEPTION: Обращение к еще не созданному объекту
[15612] Класс ошибки: CPiException
[15612] Источник: OBJ60945, строка 11
[15612] ___________________________________
[15612] Стек вызовов:
[15612] Caught ..\Mod\Fore\Frt\FrtBindableObjects.cpp(2297) at long __cdecl CForeBindableSub::Invoke(void)
[15612] Caught ..\Mod\Fore\Frt\kxInterpreterObjects.cpp(1288) at long __cdecl CEventSink::Invoke(long,const struct _GUID &,unsigned long,unsigned short,struct tagDISPPARAMS *,struct tagVARIANT *,struct tagEXCEPINFO *,unsigned int *)
[15612]
[15612] UXEVENT: Start EXCEPTION
[15612] UXEVENT: Обращение к еще не созданному объекту
[15612] Класс ошибки: CPiException
[15612] Источник: OBJ60945, строка 11
[15612] ___________________________________
[15612] Стек вызовов:
[15612] Caught ..\Mod\Fore\Frt\FrtBindableObjects.cpp(2297) at long __cdecl CForeBindableSub::Invoke(void)
[15612] Caught ..\Mod\Fore\Frt\kxInterpreterObjects.cpp(1288) at long __cdecl CEventSink::Invoke(long,const struct _GUID &,unsigned long,unsigned short,struct tagDISPPARAMS *,struct tagVARIANT *,struct tagEXCEPINFO *,unsigned int *)
[15612]
[15612] UXEVENT: End EXCEPTION
...
Ошибки могут быть:
На стадии компиляции. Если ошибка возникла на стадии компиляции, то она также будет отражена в окне сообщений компилятора. При этом по ней может быть вызвана справка. Сводный список ошибок, возникающих на стадии компиляции, представлен в подразделе «Сообщения компилятора Fore»;
На стадии выполнения. Если ошибка вызвана на стадии выполнения кода, то изучите текст ошибки, место её возникновения: идентификатор модуля и номер строки. В большинстве случаев по тексту можно понять причину возникновения ошибки и внести необходимые изменения. Если причину ошибки определить не удалось, то скопируйте и сохраните в файл блок лога от запуска приложения до ошибки. Полученный файл с описанием производимых действий отправьте в техническую поддержку по адресу support@fsight.ru или через сервисы технической поддержки, которые доступны после регистрации на сайте.
В редких случаях может возникнут ошибка с текстом Access Violation. Данная ошибка свидетельствует о наличии необработанной исключительной ситуации во внутреннем коде продукта «Форсайт. Аналитическая платформа». Сообщите в техническую поддержку при каких условиях возникла данная ошибка, чтобы в дальнейшем была возможность внести критические изменения в код продукта.
Кроме ошибок в лог выводятся информационные сообщения, отражающие процесс работы приложения. Рассмотрим отдельно по инструментам возможные сообщения, их содержание и интерпретацию для оценки и планирования дальнейших действий.
[ms$]. Моделирование
и прогнозирование, алгоритмы расчёта
