gifts2017

Логирование в 1С

Опубликовал Сергей Рудюк (rudjuk) в раздел Администрирование - Системное

Часто бывает необходимо отслеживать состояние часто повторяющихся регламентных заданий. Например, синхронизация данных с IP-телефонией, которая может производиться каждую минуту, синхронизация с сайтами, синхронизация данных с различными системами.
Использовать для этих целей логирование 1С чрезвычайно неэффективно и не удобно.
В таких случаях удобно использовать подход, применяемый в Unix-системах: писать логи в обычные текстовые файлы, а потом делать их обработку через эффективно работающие Unix-команды: grep, tail, cat, less и т.п.

Итак, рассмотрим программную реализацию в 1С:

Название модуля — К2_Лог

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


/////////////////////////////////////////////
// Общесистемные процедуры и функции
/////////////////////////////////////////////

// Определяем платформу операционной системы
Функция ОпределитьПлатформу ()Экспорт 
	
	СисИнф = Новый СистемнаяИнформация;
	Если  СисИнф.ТипПлатформы = ТипПлатформы.Windows_x86 Или  СисИнф.ТипПлатформы = ТипПлатформы.Windows_x86_64  Тогда
		Значение = "Wind"; // Лучше выдавала бы Win - так логичнее
	ИначеЕсли  СисИнф.ТипПлатформы = ТипПлатформы.Linux_x86 Или  СисИнф.ТипПлатформы = ТипПлатформы.Linux_x86_64  Тогда 
		Значение = "Lin";
	ИначеЕсли  СисИнф.ТипПлатформы = ТипПлатформы.MacOS_x86 Или  СисИнф.ТипПлатформы = ТипПлатформы.MacOS_x86_64  Тогда 
		Значение = "Mac";
	Иначе
		Значение = Неопределено;
	КонецЕсли;
	   Возврат Значение;
   КонецФункции
   
// Функция возвращает является ли данная система Windows или нет   
Функция IsWin() Экспорт
	Возврат ОпределитьПлатформу()="Wind";
КонецФункции

Функция РазностьВремени(Время1, Время2);
	Возврат (Время2 - Время1);
КонецФункции



////////////////////////////////////////////
// Функции логирования
////////////////////////////////////////////

// Сохраняет информацию в лог
Процедура Лог(ИмяФайла, ЛогСтрока, ДатаВремя, ЭтоНачало=Истина) Экспорт
	
	// Определение даты и времени
	Сейчас=ДатаВремя;
	Разница=0;
	Если ЭтоНачало Тогда
		ДатаВремя=ТекущаяДата();
		Сейчас=ДатаВремя;
	Иначе	
		ДатаВремя2=ТекущаяДата();
		Разница=РазностьВремени(ДатаВремя,ДатаВремя2);
		Сейчас=ДатаВремя2;
	КонецЕсли;
	
	
	// Если полный путь не указан, то пишем в c:\log
	Если Найти(ИмяФайла, "\") = 0 тогда
  		ИмяФайла = "C:\Log\"+ ИмяФайла;
	КонецЕсли;
	
    // Если не указано расширение - указываем
	Если Найти(ИмяФайла, ".") = 0 тогда
        ИмяФайла = ИмяФайла+".txt";
	КонецЕсли;
	
	
	// Форматирую разницу в секнды, минуты, часы
	Если Разница<60 Тогда
		Разница = Строка(Разница)+" сек";
	ИначеЕсли Разница<3600 Тогда	
		Разница = Строка(Окр(Разница/60,2))+" мин";
	Иначе 
		Разница = Строка(Окр(Разница/3600,2))+" часов";
	КонецЕсли;		
	
	
	ЛогСтрока=""+Сейчас+"|"+ПараметрыСеанса.ТекущийПользователь+"|"+ЛогСтрока+"|"+Разница;
	
	Попытка
	
		Если IsWin() Тогда
	
				fso=Новый COMОбъект("Scripting.FileSystemObject");	
		
				Если Не fso.FileExists(ИмяФайла) Тогда
					file=fso.CreateTextFile(ИмяФайла, -1, 0); //создать файл, перезаписывая существующий.
					file.WriteLine(ЛогСтрока); 
					file.Close(); 
				Иначе
					file=fso.OpenTextFile(ИмяФайла, 8, 0); //дополнить файл
					file.WriteLine(ЛогСтрока); 
					file.Close(); 
				КонецЕсли;
			
		Иначе
			ЗапуститьПриложение("echo "+ЛогСтрока+">>"+ИмяФайла);
		КонецЕсли;		
		
	Исключение
		Попытка
			ЗапуститьПриложение("echo _LogErr>>C:\Log\_err.txt");
		Исключение
		КонецПопытки;
	КонецПопытки;
			

КонецПроцедуры	 


// Формирует лог сообщений
Процедура ЛогСообщений(Модуль, ЛогСтрока, ДатаВремя, ЭтоНачало=Истина) Экспорт
	 Лог(Модуль, ЛогСтрока, ДатаВремя,ЭтоНачало);	 
	 //Лог("_Сообщения", Модуль+" - "+ЛогСтрока, ДатаВремя,ЭтоНачало);	 
КонецПроцедуры


// Формирует лог обработок
Процедура ЛогОбработок(НазваниеОбработки, ЛогСтрока, ДатаВремя, ЭтоНачало=Истина) Экспорт
	 Лог("Обр_"+НазваниеОбработки, ЛогСтрока, ДатаВремя, ЭтоНачало);
	 //Лог("_Обработки", НазваниеОбработки+" - "+ЛогСтрока, ДатаВремя, ЭтоНачало);
КонецПроцедуры	

// Формирует лог обмена
Процедура ЛогОбмен(НазваниеОбработки, ЛогСтрока, ДатаВремя, ЭтоНачало=Истина) Экспорт
	 Лог("Обмен_"+НазваниеОбработки, ЛогСтрока, ДатаВремя, ЭтоНачало);
	 //Лог("_Обмен", НазваниеОбработки+" - "+ЛогСтрока, ДатаВремя, ЭтоНачало);
КонецПроцедуры	


// Формирует лог регламентных заданий
Процедура ЛогРегламентныхЗаданий(НазваниеРегламентногоЗадания,ЛогСтрока, ДатаВремя, ЭтоНачало=Истина)
	  Лог("РЗ_"+НазваниеРегламентногоЗадания,ЛогСтрока, ДатаВремя, ЭтоНачало);
	  //Лог("_РегламентныеЗадания",НазваниеРегламентногоЗадания+" - "+ЛогСтрока, ДатаВремя, ЭтоНачало);
КонецПроцедуры	



// Выдает сообщение на экран и записывает в файл
Процедура Сообщ(Модуль, ТестСообщения) Экспорт
	  ДатаВремя=ТекущаяДата();
	  ЛогСообщений(Модуль, ТестСообщения, ДатаВремя);
	  //Сообщить(ТестСообщения);	
КонецПроцедуры	

// Начало произвольного сообщения со счетчиком
Процедура СообщНач(Модуль, ТестСообщения, ДатаВремя) Экспорт
	  ЛогСообщений(Модуль, ТестСообщения, ДатаВремя, Истина);
	  //Сообщить(ТестСообщения);	
КонецПроцедуры	

// Конец произвольного сообщения со счетчиком
Процедура СообщКон(Модуль, ТестСообщения, ДатаВремя) Экспорт
	  ЛогСообщений(Модуль, ТестСообщения, ДатаВремя, Ложь);
	  //Сообщить(ТестСообщения);	
КонецПроцедуры	



// Фиксация начала выполнения обработки
Процедура ЛогОбрНач(НазваниеОбработки, ЛогСтрока, ДатаВремя) Экспорт
	 ЛогОбработок(НазваниеОбработки, ЛогСтрока+" Нач", ДатаВремя, Истина);
КонецПроцедуры	

// Фиксация конца выполнения обработки
Процедура ЛогОбрКон(НазваниеОбработки, ЛогСтрока, ДатаВремя) Экспорт
	 ЛогОбработок(НазваниеОбработки, ЛогСтрока+" Кон", ДатаВремя, Ложь);
КонецПроцедуры	

// Фиксация сообщения в обработке (без вывода сообщения на экран)
Процедура ЛогОбрСообщ(НазваниеОбработки, ЛогСтрока, ДатаВремя) Экспорт
	 ЛогОбработок(НазваниеОбработки, ЛогСтрока, ДатаВремя, Ложь);
КонецПроцедуры	



// Фиксация начала регламентной задачи
Процедура ЛогРЗНач(НазваниеРегламентногоЗадания,ЛогСтрока, ДатаВремя) Экспорт 
	  ЛогРегламентныхЗаданий(НазваниеРегламентногоЗадания,ЛогСтрока+" Нач", ДатаВремя, Истина);
КонецПроцедуры	

// Фиксация окончания регламентной задачи
Процедура ЛогРЗКон(НазваниеРегламентногоЗадания,ЛогСтрока, ДатаВремя) Экспорт 
	  ЛогРегламентныхЗаданий(НазваниеРегламентногоЗадания,ЛогСтрока+" Кон", ДатаВремя, Ложь);
КонецПроцедуры	

// Фиксация сообщений в регламентных заданиях
Процедура ЛогРЗСообщ(НазваниеРегламентногоЗадания,ЛогСтрока, ДатаВремя) Экспорт 
	  ЛогРегламентныхЗаданий(НазваниеРегламентногоЗадания,ЛогСтрока, ДатаВремя, Ложь);
КонецПроцедуры	



// Фиксация начала регламентной задачи
Процедура ЛогОбменНач(НазваниеОбмена,ЛогСтрока, ДатаВремя) Экспорт 
	  ЛогОбмен(НазваниеОбмена,ЛогСтрока+" Нач", ДатаВремя, Истина);
КонецПроцедуры	

// Фиксация окончания регламентной задачи
Процедура ЛогОбменКон(НазваниеОбмена,ЛогСтрока, ДатаВремя) Экспорт 
	  ЛогОбмен(НазваниеОбмена,ЛогСтрока+" Кон", ДатаВремя, Ложь);
КонецПроцедуры	

// Фиксация сообщений в регламентных заданиях
Процедура ЛогОбменСообщ(НазваниеОбмена,ЛогСтрока, ДатаВремя) Экспорт 
	  ЛогОбмен(НазваниеОбмена,ЛогСтрока, ДатаВремя, Ложь);
КонецПроцедуры	



// Сохраняет сообщение в лог
Процедура СообщЛог(Модуль, ТестСообщения) Экспорт
   ДатаВремя=ТекущаяДата();
   Лог(Модуль, ТестСообщения, ДатаВремя);
КонецПроцедуры

// Процедура фиксации ошибок в логе ошибок
Процедура Ошибка(ТестСообщения) Экспорт
   ДатаВремя=ТекущаяДата();
   Лог("_err", ТестСообщения, ДатаВремя, Ложь);
КонецПроцедуры	

// Процедура фиксации ошибок с указанием текущей даты
Процедура ОшибкаД(ТестСообщения, ДатаВремя) Экспорт
   Лог("_err", ТестСообщения, ДатаВремя, Ложь);
КонецПроцедуры	



Процедура ОшибкаС(ТестСообщения) Экспорт
   ДатаВремя=ТекущаяДата();
   Лог("_err", ТестСообщения, ДатаВремя, Ложь);  
 
   Сообщить(ТестСообщения);
КонецПроцедуры	

// Фиксирует ошибку в логе и выдает сообщение о ошибке.
// Так же, вызывает исключение о ошибке.
Процедура ОшибкаСообщить(ТестСообщения, Отказ = Ложь) Экспорт
   ДатаВремя=ТекущаяДата();
   Лог("_err", ТестСообщения, ДатаВремя, Ложь);
   
   ОбщегоНазначения.СообщитьОбОшибке(ТестСообщения, Отказ);
   
   //Сообщить(ТестСообщения);
КонецПроцедуры	


Процедура ПодклЛог(ТестСообщения) Экспорт
   ДатаВремя=ТекущаяДата();
   Лог("_conn", ТестСообщения, ДатаВремя, Ложь);
КонецПроцедуры	


Процедура Отладка(Модуль,ТестСообщения) Экспорт
   ДатаВремя=ТекущаяДата();
   Лог(Модуль, ТестСообщения, ДатаВремя, Ложь);
КонецПроцедуры	


	
Процедура ОтладкаС(Модуль,ТестСообщения) Экспорт
   ДатаВремя=ТекущаяДата();
   Лог(Модуль, ТестСообщения, ДатаВремя, Ложь);
   Сообщить(ТестСообщения);
КонецПроцедуры	


// Формирует лог веб-процессов
Процедура ЛогWeb(НазваниеWeb,ЛогСтрока, ДатаВремя, ЭтоНачало=Истина)
	  Лог("Web_"+НазваниеWeb,ЛогСтрока, ДатаВремя, ЭтоНачало);
	  //Лог("_РегламентныеЗадания",НазваниеРегламентногоЗадания+" - "+ЛогСтрока, ДатаВремя, ЭтоНачало);
КонецПроцедуры	



// Фиксация начала веб-процесса
Процедура ЛогWebНач(НазваниеWeb,ЛогСтрока, ДатаВремя) Экспорт 
	  ЛогWeb(НазваниеWeb,ЛогСтрока+" Нач", ДатаВремя, Истина);
КонецПроцедуры	

// Фиксация окончания веб-процесса
Процедура ЛогWebКон(НазваниеWeb,ЛогСтрока, ДатаВремя) Экспорт 
	  ЛогWeb(НазваниеWeb,ЛогСтрока+" Кон", ДатаВремя, Ложь);
КонецПроцедуры



Фиксация времени выполнения регламентных задач:

Процедура ЗагрузкаКаталогаОмеги() Экспорт
		
	Перем ТаблицаРС;	
	
	// Rudjuk 08.09.2015
	Перем ДатаВремя;
	К2_Лог.ЛогРЗНач("ЗагрузкаКаталогаОмеги","ЗагрузкаКаталогаОмеги", ДатаВремя);

......

    // Rudjuk 08.09.2015
	К2_Лог.ЛогРЗКон("ЗагрузкаКаталогаОмеги","ЗагрузкаКаталогаОмеги", ДатаВремя);
	
	
КонецПроцедуры

В данном примере мы фиксируем время выполнения регламентного задания и записываем данное время в лог. Причем, записываем и начало регламентного задания и окончания. Таким образом, если регламентное задание не завершилось — мы видим, что 2-я строка не записалась.

Фиксация ошибок

В регламентном задании, сообщения не выдаются на экран. Но, их можно писать в лог. Таким образом, если возникают ошибки, имеет смысл их фиксировать в логе.


Попытка
	Перемещение.Записать(); //РежимЗаписиДокумента.Проведение
Исключение	
	К2_Лог.Ошибка("АвтоматическоеФормированиеПеремещенийПоСвозуНеликвидов.Перемещение.Записать()." + ОписаниеОшибки());					
КонецПопытки;	


Анализ логов с помощью команд Linux

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

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

Для того, чтоб команды Linux поддерживались в Windows, необходимо сделать ряд вещей:

Необходимо распаковать в системный каталог, доступный в путях пакет UnxUpdates: http://unxutils.sourceforge.net/

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

Вывод на экран последних поступающих строк в логе:

tail -f НазваниеЛога

Данная команда полезна для мониторинга поступающих строк в лог-файл.

Поиск нужной строки в логе:

cat НазваниеЛога | grep ЧтоИщем

 

Вывод на экран строк по заданному слову

tail -f НазваниеЛогФайла | grep ЧтоИщем

 

 

Автор: Рудюк С . А. http://corp2.net

См. также

PowerTools от 1 000
Подписаться Добавить вознаграждение

Комментарии

1. Юрий Былинкин (ardn) 18.05.16 11:13
Почему
Использовать для этих целей логирование 1С чрезвычайно неэффективно и не удобно.
?
На мой взгляд, более неудобно городить свою систему логирования для некоторых процессов.
oldfornit; invertercant; dabu-dabu; shalimski; mihey; AlexSvt; CSiER; Сурикат; +8 Ответить 2
2. Сергей Рудюк (rudjuk) 18.05.16 11:36
(1) ardn, Да. Городится "логирование" для тех процессов, которые хочется отслеживать. И это отлично работает и не засоряет базу. Т.к. данные логи легко удаляются и так же легко наблюдаются процессы. Очень полезная вещь - видеть в реальном времени состояние процессов.
3. Сергей (Che) Коцюра (CheBurator) 19.05.16 23:32
и что даст состояние процессов? логично видеть проблемы/гарушения, все остальное - видеть не очень интересно
4. Сергей Рудюк (rudjuk) 20.05.16 07:38
(3) CheBurator, Состояние процессов ничего особо не даст. Поэтому и цепляется логирование на те процессы, которые нужно отслеживать. Например, на часто выполняемые регламентные задания ip-телефонии, на процессы успешности записи на диск, успешности передачи по ftp и т.п. В логах комментарии всегда пишутся так, чтоб можо было определить процедуру и место процедуры, в которой возникла проблема.
Данное логирование не предназначено для отслеживания всего и вся. А предназначено для отслеживания успешности выполнения важных для работы или для отладки мест конфигурации.
5. Sergey Andreev (starik-2005) 20.05.16 08:00
А что, объект ЗаписьТекста религия не позволяет использовать и нужны эти танцы с бубном вокруг определения типа платформы?

Да и вообще, если уж логировать таким образом, то куда лучше использовать какой-нибудь elasticsearch, данные из которого можно связать с системами работы с логами и визуализаторами.
oldfornit; chek.e.l@mail.ru; Bronislav; mihey; JohnyDeath; +5 Ответить 1
6. Сергей Рудюк (rudjuk) 20.05.16 16:07
(5) starik-2005, Записать текст блокирует файл. Как результат, при совместных обращениях к одному и тому же логу будет писаться сообщение о блокировке. Решение работает и в Linux и в Windows. Но подходы к реализации в данных операционных системах - разные.
По поводу визуализации - прекрасно все визуализируется командами Linux. tail, grep, cat :)
Вполне достаточно для наблюдения за процессами вплоть до реального времени.
7. Sergey Andreev (starik-2005) 20.05.16 18:26
(6) rudjuk, ну кто ж спорит-то. Я запись файла вообще использую для механизма мьютекса. Можно повисеть в попытке/исключении, т.к. ОС тоже в один файл не может одновременно писать - все-равно ждет завершения предыдущей файловой операции. Иначе была бы мешанина между символами строк, записываемых разными потоками одновременно )))

Мне кажется, что в идеале сделать регистр сведений, в который пишется лог, а потом регламентом регистр блокируется, читается, очищается и пишется в текст. Но при этом, конечо, и лог 1С растет, если не отключить регистрацию.
8. Сергей Рудюк (rudjuk) 20.05.16 18:54
(7) starik-2005, Нет. В том то и дело, что регистр сведений - плохой вариант. Впрочем, как и что-угодно, что пишет в базу. В том то и выгода текстовых логов, что их легко удалить и очень быстро. А с помощью команд Linux - очень эффективно анализировать.
9. Евгений Мартыненков (JohnyDeath) 25.05.16 09:38
10. Артём Андриянов (CSiER) 25.05.16 09:47
Думаю, что смысл логирования в nix (гуру поправят, если ошибаюсь) - не в том, что данные хранятся в текстовых файлах, а в самом процессе журналирования (когда приложения пишут в лог через специальный демон). Если настраивать приложения так, чтобы логи писались в режиме debug или info - тогда без awk и т.п. не обойтись. Если warn и выше - тогда можно открыть нужные журналы через tain -n.
Использовать для этих целей логирование 1С чрезвычайно неэффективно и не удобно.

неэффективно использовать те системы логирования, которые не просматриваются :) Думаю, что писать логи непосредственно в журналы windows при таком подходе будет более правильно - в этом случае вероятность обнаружить ошибку повышается.
11. Алексей Совит (AlexSvt) 25.05.16 09:53
Добрый день!
Присоединяюсь к вопросу в (1).
На мой взгляд, утверждать о "чрезвычайной неэффективности" не совсем корректно.
Вы пишете пути записи логов и имя лог-файла в коде. А что будет если Вы развернете еще одну базу, например, тестовую из бэкапа, на той же машине и в ней запустится запись лога процесса?
Благодарю за статью.
12. Сергей Рудюк (rudjuk) 25.05.16 13:06
(11) AlexSvt, Никто не мешает изменять код. Иногда, нужно в одном логе наблюдать процессы в нескольких базах. Иногда - наоборот. Поэтому, исходите из заач.
13. Сергей Рудюк (rudjuk) 25.05.16 13:09
(10) CSiER, В том то и смысл, чтоб все в одну кошелку не ложить...
14. aspirator 23 (aspirator23) 28.05.16 14:00
Для отладки, настройки логировать в файл удобнее.
15. Алексей Лапицкий (Lapitskiy) 29.05.16 04:09
Да, текстовые логи значительно удобнее 1с-журнала регистрации - с ним вообще невозможно работать по-человечески.
16. Сергей Лесовой (Synoecium) 31.05.16 09:29
(15) Lapitskiy, А как насчет выгружать ЖР в формат XML средствами платформы, а потом делать уже с ним все, что хочется сторонними программами?
17. Сергей Рудюк (rudjuk) 31.05.16 12:15
(16) Synoecium, XML - избыточный. Не целесообразно логи вести в нем. Тем более, что время на обработку XML не то. Текстовые логи - для анализа информации в режиме реального времени.
18. Vladimir Glumov (Vovan58) 31.05.16 17:05
Идея хороша, только писать log с помощью создания com-объекта для каждой строки - это очень "от души"... ("Формула любви")
19. Сергей Рудюк (rudjuk) 31.05.16 19:08
(18) Vovan58, К сожалению, так приходится делать, т.к. обычные команды 1С блокируют текстовый файл. И одновременные обращения к одному и тому же файлу вызывают в этом случае ошибки.
Для написания сообщения необходимо авторизоваться
Прикрепить файл
Дополнительные параметры ответа