Автоматизация анализа файлов технологического журнала

08.09.15

База данных - Технологический журнал

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

Скачать исходный код

Наименование Файл Версия Размер
Исполняемый файл
.zip 262,12Kb
79
.zip 262,12Kb 79 Скачать

Приложение позволяет выполнять разбор текстовых файлов технологического журнала с расширением *.log на события и запись этих событий в таблицу базы MS SQL.
Состав свойств ориентирован в основном на запросы и исключения.
Обработка файлов производится в многопоточном режиме, что позволяет загружать большие объемы информации за относительно небольшое время.

Для работы приложения необходим установленный NET Framework 2.0.

Для начала использования приложения требуется:
1) создать на сервере MS SQL новую пустую базу
2) заполнить строку соединения с сервером по шаблону:
для windows-авторизации Data Source=MSSQL1;Server=имя сервера;Database=имя базы;Integrated Security=true;
для обычной авторизации  Data Source=MSSQL1;Server=имя сервера;Database=имя базы;Password=Пароль;User ID=Имя пользователя;
3) нажать кнопку "Создать служебную таблицу", которая подключится к серверу и выполнит создание структуры таблицы для событий

Порядок загрузки файлов:
1) указать строку соединения как описано выше;
2) указать каталог, содержащий файлы тех.журнала с расширением *.log, вложенные каталоги обрабатываются рекурсивно;
3) указать число параллельных потоков, в которых программа будет обрабатывать файлы. Диапазон от 1 до 100, но ставить больше 20-30 нет особого смысла, хотя все зависит от конкретной машины, на которой выполняется запуск.
4) нажать кнопку "Заполнить список файлов" - программа найдет все файлы ТЖ в указанном каталоге и отобразит их список;
5) нажать кнопку "Запустить разбор" - программа начнет параллельное чтение файлов, их разбор и запись полученных событий в структурированном виде в базу данных.

Дополнительные вычисляемые данные

Чтобы сделать данные более полезными для анализа были добавлены 2 вычисляемых поля для событий DBMSSQL и SDBL.

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

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

Чтобы подставить подобный контекст к правильным местам вызова и получить более объекивную картину - требуется выполнить следующий запрос в базе с загруженными данными:

---простановка контекста для DBMSSQL в пределах 50 миллисекунд
SELECT Context, ContextLastRow, DATEADD(ms, - 50, DateTime) as D1, DATEADD(ms, 50, DateTime) as D2, ProcessName, t_clientID, SessionID
INTO #ContextTable
FROM logs
WHERE (EventName = 'Context')

CREATE CLUSTERED INDEX ix_Main ON #ContextTable (ProcessName, t_clientID, SessionID)

SELECT DateTime, EventName, ProcessName, t_clientID, Moment, SessionID, Context, ContextLastRow
INTO #QueriesTable
FROM logs
WHERE (EventName = 'DBMSSQL' AND Context = '' AND ContextLastRow = '')

CREATE CLUSTERED INDEX ix_Main ON #QueriesTable (ProcessName, t_clientID, SessionID)

SELECT DateTime, EventName, ProcessName, t_clientID, Moment, SessionID, Contexts.Context, Contexts.ContextLastRow
INTO #NewData
FROM #QueriesTable AS Queries
OUTER APPLY (SELECT TOP 1 Context, ContextLastRow
				FROM #ContextTable AS A
				WHERE
				(ProcessName = Queries.ProcessName) 
				AND (t_clientID = Queries.t_clientID) 
				AND (SessionID = Queries.SessionID) 
				AND (Queries.DateTime BETWEEN D1 AND D2)) AS Contexts
WHERE NOT Contexts.Context IS NULL AND NOT Contexts.ContextLastRow IS NULL

DROP TABLE #ContextTable
DROP TABLE #QueriesTable

UPDATE T SET T.Context = OT.Context, T.ContextLastRow = OT.ContextLastRow
FROM [logs] T
INNER JOIN
	(SELECT DateTime, EventName, ProcessName, t_clientID, Moment, SessionID, Context, ContextLastRow
		FROM #NewData) OT
ON
    T.[DateTime] = OT.[DateTime]
	AND T.Moment = OT.Moment
	AND T.EventName = OT.EventName
	AND T.ProcessName = OT.ProcessName
	AND T.t_clientID = OT.t_clientID
	AND T.SessionID = OT.SessionID

DROP TABLE #NewData

 

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

Несколько примеров выборки данных

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

SELECT SUM([Duration]) [Общая длительность], AVG([Duration]) [Среднее], SUM(1) [Количество],
      Min(DateTime) [Начало], Max(DateTime) [Окочнание], [ContextLastRow]
FROM [dbo].[logs]
where NOT [ContextLastRow] = '' AND EventName='DBMSSQL' 
GROUP BY [ContextLastRow]
ORDER BY SUM([Duration]) DESC

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

 

Получить список комбинаций таблиц запросов, выполнение которых заняло наибольшее время:

SELECT SUM([Duration]) [Общая длительность], AVG([Duration]) [Среднее], SUM(1) [Количество], 
      Min(DateTime) [Начало], Max(DateTime) [Окончание], TablesList, ProcessName
FROM [dbo].[logs]
where NOT tableslist = '' AND EventName='DBMSSQL' 
GROUP BY TablesList, ProcessName
ORDER BY SUM([Duration]) DESC

 

Исходные коды

Актуальная версия всегда доступна на github - https://github.com/alekseybochkov/tj_loader/

Для работы с исходными кодами требуется Visual Studio 2015 с поддержкой Visual Basic (кстати версия Visual Studio 2015 Community Edition бесплатна!).

Опубликовано по лицензии GNU GPL - https://ru.wikipedia.org/wiki/GNU_General_Public_License

 

UPD 18.02.2012
* добавлена возможность выполнения произвольных запросов к базе с событиями непосредственно из приложения;
* добавлена возможность выгрузки результатов запроса в Excel (проверялось только на русской версии Excel 2010);
* добавлена возможность просмотра структурированного плана запроса MS SQL и его выгрузка в Excel

UPD 08.03.2012
* добавлена галка "Очистить таблицу в СУБД перед загрузкой данных"
* при закрытии приложения происходит сохранение настроек в файле setting.ini. При запуске приложение считывает настройки из файла и использует их.

UPD 21.03.2015
* добавлена загрузка из тех.журналов 8.3 (увеличена точность времени события).
* добавлены исходники для Visual Studio 2013 на vb.net.

UPD 20.07.2015
* добавлено дополнительное вычисляемое поле "TablesList" для событий DBMSSQL, которое заполняется перечнем физических таблиц, участвующих в запросе. Это позволяет группировать однотипные по структуре запросы и получать более ценную информацию о проблемных местах. Без этого группировка невозможна из-за случайных имен временных таблиц, разного количества параметров, разных псевдонимов и т.д.

UPD 08.09.2015
* добавлено дополнительное вычисляемое поле "ContextLastRow"

технологический журнал администрирование производительность

См. также

Магия преобразований Vector, часть 2: технологический журнал

Технологический журнал Мониторинг Абонемент ($m)

Как легко и быстро с помощью специализированных решений собирать, парсить и передавать логи и метрики.

1 стартмани

15.11.2023    836    4    AlexSTAL    0    

8

Магия преобразований: ЖР, ТЖ, RAS/RAC, логи - универсальное решение Vector

Мониторинг Журнал регистрации Технологический журнал Абонемент ($m)

Как легко и быстро с помощью специализированных решений собирать, парсить и передавать логи и метрики.

1 стартмани

13.11.2023    3150    4    AlexSTAL    0    

42

«Монитор» – простой анализ производительности

Администрирование СУБД Технологический журнал Бесплатно (free)

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

21.09.2023    5892    Andreynikus    14    

80

Экспорт технологического журнала 1С в Elastic с помощью Logstash

Технологический журнал Платформа 1С v8.3 Абонемент ($m)

Целью данного решения является организация хранения и анализа данных из технологического журнала 1С с использованием стека Elasticsearch + Logstash + Kibana.

5 стартмани

18.09.2023    3491    huxuxuya    3    

23

Мобильный помощник эксперта 1С (приложение android, позволяющее строить отчеты на СКД по логам технологического журнала и не только)

Технологический журнал Мониторинг Платформа 1С v8.3 Конфигурации 1cv8 Бесплатно (free)

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

16.05.2023    3441    capitan    0    

23

Разбор технологического журнала без боли и страданий

Технологический журнал Абонемент ($m)

Технологический журнал - мощный инструмент логирования, используемый для анализа проблем производительности 1С. Но он обладает одним огромным недостатком, в "сыром виде" он почти не поддается адекватному анализу из-за своей структуры. Существует довольно много способов "разобрать" технологический журнал, но все опробованные способы обладают теми или иными недостатками. Предлагаю вам мой вариант "велосипеда" для разбора ТЖ и хранения разобранного в различных форматах.

1 стартмани

12.12.2022    8367    39    Segate    26    

88

Выполняем в СУБД запрос из ТЖ

Технологический журнал Платформа 1С v8.3 Конфигурации 1cv8 Абонемент ($m)

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

1 стартмани

24.11.2022    2901    3    VKislitsin    1    

17
Комментарии
Подписаться на ответы Инфостарт бот Сортировка: Древо развёрнутое
Свернуть все
1. aspirator23 339 15.02.12 07:36 Сейчас в теме
Ценная вещь. Жалко что к ней не приложена обработка для чтений журнала из MS SQL
Кроме того не все сидят на 8.2.14-15
+
3. Aleksey.Bochkov 3660 15.02.12 13:53 Сейчас в теме
(1) aspirator23, думаю, что можно в это же приложение добавить просмотр загруженных событий с отбором по виду события и сортировкой по длительности.
(2) stal76, похожая, но не совсем. Отличия в том, что мое приложение может загружать любые события с любым составом свойств(но сохраняются, конечно, только те свойства, которые есть в структуре таблицы) в многопоточном режиме, а хранимая процедура squad'a заточена чисто на запросы, грузит в один поток + файлы читаются при каждом обращении.
+
2. stal76 388 15.02.12 09:27 Сейчас в теме
4. Новиков 292 16.02.12 10:14 Сейчас в теме
Плюсую! Нужная весчь!
+
5. Zas1402 21.02.12 10:26 Сейчас в теме
(4) Новиков,
так точно полезная вечь.
+
6. пользователь 21.02.12 13:57
Сообщение было скрыто модератором.
...
7. Babuin 24.02.12 10:58 Сейчас в теме
хм, у меня падает при загрузке логов rphosta почему то
+
8. Aleksey.Bochkov 3660 24.02.12 11:29 Сейчас в теме
(7) с какой ошибкой падает? Если ругается на нехватку памяти, то уменьшите число одновременных потоков.
+
9. Babuin 24.02.12 12:01 Сейчас в теме
(8) нет с памятью все ок, запускал с разными потоками (от 1 до 20)
Какие то логи грузит, на каких то падает

framework ругается
System.ArgumentOutOfRangeException: Value of '14' is not valid for 'Value'. 'Value' should be between 'minimum' and 'maximum'.
Parameter name: Value
at System.Windows.Forms.ProgressBar.set_Value(Int32 value)
at TechJournalLoader.Form1.Timer1_Tick(Object sender, EventArgs e)
at System.Windows.Forms.Timer.OnTick(EventArgs e)
at System.Windows.Forms.Timer.TimerNativeWindow.WndProc(Message& m)
at System.Windows.Forms.NativeWindow.Callback(IntPtr hWnd, Int32 msg, IntPtr wparam, IntPtr lparam)
+
10. Aleksey.Bochkov 3660 24.02.12 12:57 Сейчас в теме
(9) поправил. Скачай программу заново и попробуй еще раз.
+
11. Babuin 24.02.12 13:18 Сейчас в теме
попробовал, на фрейм не ругается, но все равно падает.
Если грузить по одному файлу то нормально. Если все прогрузить по одному и потом опять скопом то тоже проходит.
Еще бы добавить функцию очищать таблицу, и сохранять путь подключения к базе было бы вообще супер!
+
12. Aleksey.Bochkov 3660 24.02.12 13:23 Сейчас в теме
(11) а можешь прислать файлы, при загрузке которых происходит падение и сценарий воспроизведения?
ок, сохранение и опциональную очистку таблицы на выходных сделаю.
+
13. Babuin 24.02.12 13:49 Сейчас в теме
(12) к сожалению не могу, ладно буду грузить по одному.
+
14. NOVOPRO 14.03.12 04:19 Сейчас в теме
У меня такаяже ошибка
от framework
System.ArgumentOutOfRangeException: Value of '14' is not valid for 'Value'. 'Value' should be between 'minimum' and 'maximum'.
Parameter name: Value
at System.Windows.Forms.ProgressBar.set_Value(Int32 value)
at TechJournalLoader.Form1.Timer1_Tick(Object sender, EventArgs e)
at System.Windows.Forms.Timer.OnTick(EventArgs e)
at System.Windows.Forms.Timer.TimerNativeWindow.WndProc(Message& m)
at System.Windows.Forms.NativeWindow.Callback(IntPtr hWnd, Int32 msg, IntPtr wparam, IntPtr lparam)
+
15. GreenFox 28.03.12 00:16 Сейчас в теме
Вещь конечно интересная - надо разбираться. Подобные обработки в области оптимизации интересовали раньше скорее как развлечение, но сейчас "припекло" и приходиться собирать все , что только можно найти в данной области. КИП пока что недоступен по цене, поэтому пользуемся тем что есть.
+
16. igor_gk 49 20.07.17 14:43 Сейчас в теме
Что за "текстовых файлов технологического журнала с расширением *.log" ?
+
17. Andreynikus 1363 26.09.18 12:39 Сейчас в теме
Хорошая вещь! А из 1С можно строить запросы к таблице с данными ТЖ, например через конструктор запросов? Или только прямые запросы к таблицам СУБД?
+
18. user626776_zhiglin 26.10.18 11:10 Сейчас в теме
Собрал логи ТЖ с настройкой
<?xml version="1.0" encoding="UTF-8"?>
<config xmlns="http://v8.1c.ru/v8/tech-log">
<dump create="false"/>
<log location="f:\logs_duration" history="168">
<event>
<ne property="name" value=""/>
</event>
<property name="all"/>
</log>
</config>

Процесс загрузки логов завершился, но в таблице в SQL ничего не появилось.
Платформа 1С:Предприятие 8.3 (8.3.10.2650)
+
19. uncle_Vasya 17.09.21 14:44 Сейчас в теме
Здравствуйте!
Купил эту штуку, она вываливается с ошибкой: см. вложение. Если автор публикации отзовётся, могу предоставить расширенные данные сигнатуры ошибки.
При этом, уже после вывода сообщения о крэше, утилитка продолжает что-то там, якобы, писать в СУБД (атака мертвецов, хехе), но SQL-таблица остаётся пустая. Вряд ли это может быть ошибкой манипуляции с SQL-сервером, ведь таблицу "logs" утилита создаёт вообще на ура.

Может быть, мне требуется какую-то из dll-ек прописать в службы компонентов или по-другому как-то обозначить для ОС её безопасность?
Наш админ, достаточно квалифицированный, пожимает плечами только.
Прикрепленные файлы:
+
Оставьте свое сообщение