Пишем систему логирования в InterSystems Caché

image

Введение

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

Система логирования

Это нужный и полезный инструмент для протоколирования работы приложения. Значительно экономит время, затрачиваемое на отладку и вылавливание различных багов. Система состоит из двух частей:

  • Класс хранения логов
  • Набор макросов для автоматического добавления новой записи в лог

Класс хранения логов

Составим таблицу того, что нам надо хранить, сразу же напишем, когда возможно получить эти данные – во время компиляции или исполнения программы. Это потребуется при написании второй части системы – макросов, где мы, очевидно, стремимся узнать как можно больше логируемых данных во время компиляции:

Информация Время получения
Тип события Компиляция
Имя класса Компиляция
Имя метода Компиляция
Аргументы, переданные в метод Компиляция
№ строки исх. Кода Выполнение
Имя пользователя Выполнение
Дата/Время Выполнение
Сообщение Выполнение
IP адрес Выполнение

Создадим класс App.Log. В нём создадим все вышеперечисленные свойства. При создании объекта класса App.Log свойства Имя пользователя, Дата/Время, IP адрес заполняются автоматически.

Класс App.Log

Class App.Log Extends %Persistent

{


/// Замещение несуществующих значений

Parameter Null = “Null”;


/// Тип события

Property EventType As %String(MAXLEN 10VALUELIST “,NONE,FATAL,ERROR,WARN,INFO,STAT,DEBUG,RAW”);


/// Имя класса

Property ClassName As %String(MAXLEN 256);


/// Имя метода

Property MethodName As %String(MAXLEN 128);


/// Строка int кода

Property Source As %String(MAXLEN 2000);


/// Имя пользователя

Property UserName As %String(MAXLEN 128) [ InitialExpression = {$username} ];


/// Аргументы, переданные в метод

Property Arguments As %String(MAXLEN 32000TRUNCATE 1);


/// Дата/время

Property TimeStamp As %TimeStamp InitialExpression = {$zdt($h, 3, 1)} ];


/// Произвольное сообщение

Property Message As %String(MAXLEN 32000TRUNCATE 1);


/// Сетевой адрес пользователя

Property ClientIPAddress As %String(MAXLEN 32) [ InitialExpression = {..GetClientAddress()} ];

Index idxEventType On EventType [ Type = bitmap ];

Index idxUserName On UserName [ Type = bitmap ];

Index idxClassName On ClassName [ Type = bitmap ];

Index idxTimeStamp On TimeStamp [ Type = bitslice ];

Index idxClientIPAddress On ClientIPAddress;


/// Определяем сетевой адрес пользователя

ClassMethod GetClientAddress()

{

// Если существует сессия CSP, то возьмём оттуда

#dim %request As %CSP.Request

If ($d(%request)) {

Return %request.CgiEnvs(“REMOTE_ADDR”)

}

Return $system.Process.ClientIPAddress()

}


/// Добавление события.

/// Использовать не напрямую, а через макросы $$$LogEventTYPE().

ClassMethod AddRecord(ClassName As %String “”MethodName As %String “”Source As %String “”EventType As %String “”Arguments As %String “”Message As %String “”)

{

Set record = ..%New()

Set record.Arguments Arguments

Set record.ClassName ClassName

Set record.EventType EventType

Set record.Message Message

Set record.MethodName MethodName

Set record.Source Source

Do record.%Save()

}

}

Макросы логирования

Обычно макросы выделяют в отдельные inc файлы, где хранятся только сами определения макросов. Подключают необходимые файлы к классам командой Include MacroFileName. В данном случае Include App.LogMacro.
Для начала определим основной макрос, котором пользователь будет добавлять в код своего приложения:
#define LogEvent(%type, %message) Do ##class(App.Log).AddRecord($$$CurrentClass, $$$CurrentMethod, $$$StackPlace, %type,
$$$MethodArguments, %message)

На вход данный макрос принимает 2 аргумента – Тип события и Сообщение. Сообщение пользователь задаёт сам, а вот для передачи типа события напишем дополнительные макросы, отличающиеся названиями и передающие Тип события без необходимости каких-либо действий со стороны пользователя:

Макросы LogTYPE

#define LogNone(%message)         $$$LogEvent(“NONE”%message)

#define LogError(%message)         $$$LogEvent(“ERROR”%message)

#define LogFatal(%message)         $$$LogEvent(“FATAL”%message)

#define LogWarn(%message)         $$$LogEvent(“WARN”%message)

#define LogInfo(%message)         $$$LogEvent(“INFO”%message)

#define LogStat(%message)         $$$LogEvent(“STAT”%message)

#define LogDebug(%message)         $$$LogEvent(“DEBUG”%message)

#define LogRaw(%message)         $$$LogEvent(“RAW”%message)

Таким образом пользователю для использования логирования достаточно установить макрос $$$LogError(“Дополнительное сообщение”) в коде приложения.
Осталось определить макросы $$$CurrentClass, $$$CurrentMethod, $$$StackPlace, $$$MethodArguments. Начнём с первых трёх:
#define CurrentClass     ##Expression($$$quote(%classname))

#define CurrentMethod     ##Expression($$$quote(%methodname))

#define StackPlace         $st($st(-1),“PLACE”)

Переменные %classname,%methodname описаны в документации макросов. Для получения номера строки int кода используется функция $stack.
Для получения списка аргументов методов и их значений воспользуемся пакетом %Dictionary. Там хранятся все описания классов, в том числе и описания методов. В частности на интересует класс %Dictionary.CompiledMethod и его свойство FormalSpecParsed – $lb структура следующего вида: $lb($lb(“Название”,“Класс”,“Тип(Output/ByRef)”,“Значение по умолчанию”),…)
соответствующая сигнатуре метода. К примеру у метода ClassMethod Test(As %Integer 1ByRef 2Output c) будет следующий FormalSpecParsed:
$lb(
$lb(“a”,“%Library.Integer”,“”,“1”),
$lb(“b”,“%Library.String”,“&”,“2”),
$lb(“c”,“%Library.String”,“*”,“”))

В результате выполнения макроса $$$MethodArguments нужно получить следующий код (для метода Test): “a=”_$g(a,“Null”)_“; b=”_$g(b,“Null”)_“; c=”_$g(c,“Null”)_“;”

Для этого на этапе компиляции нужно:

  • Получить имя класса и имя метода
  • Открыть соответствующий экземпляр класса %Dictionary.CompiledMethod и получить свойство FormalSpec
  • Преобразовать его в строку исходного кода

Добавим соответствующие методы в класс App.Log:

Методы GetMethodArguments, GetMethodArgumentsList, ArgumentsListToString

ClassMethod GetMethodArguments(ClassName As %StringMethodName As %StringAs %String

{

Set list = ..GetMethodArgumentsList(ClassName,MethodName)

Set string = ..ArgumentsListToString(list)

Return string

}

ClassMethod GetMethodArgumentsList(ClassName As %StringMethodName As %StringAs %List

{

Set result “”

Set def ##class(%Dictionary.CompiledMethod).%OpenId(ClassName “||” MethodName)

If ($IsObject(def)) {

Set result def.FormalSpecParsed

}

Return result

}

ClassMethod ArgumentsListToString(List As %ListAs %String

{

Set result “”

For i=1:1:$ll(List{

Set result result $$$quote($s(i>1=0:“”,1:“; “) _ $lg($lg(List,i))_“=”)

“_$g(” $lg($lg(List,i)) _ “,”_$$$quote(..#Null)_“)_”

_$s(i=$ll(List)=0:“”,1:$$$quote(“;”))

}

Return result

}

Теперь определим макрос $$$MethodArguments как:#define MethodArguments ##Expression(##class(App.Log).GetMethodArguments(%classname,%methodname))

Пример использования

Создадим класс App.Use с методом Test для демонстрации возможностей системы логирования

App.Use

Include App.LogMacro

Class App.Use CompileAfter App.Log ]

{

/// Do ##class(App.Use).Test()

ClassMethod Test(As %Integer 1ByRef 2)

{

$$$LogWarn(“Текст”)

}

}

В результате макрос $$$LogWarn(“Текст”) в int коде преобразуется в строку:
Do ##class(App.Log).AddRecord(“App.Use”,“Test”,$st($st(-1),“PLACE”),“WARN”,“a=”_$g(a,“Null”)_“; b=”_$g(b,“Null”)_“;”, “Текст”)

После выполнения этого кода создается новый объект класса App.Log:
image

Улучшения

Написав основу системы логирования, подумаем как её можно улучшить.
Во-первых добавим возможность обработки аргументов-объектов, потому что в данный момент будут записаны только oref объектов.
Во-вторых добавим возможность открытия контекста – в том случае, из хранимых значений аргументов восстанавливать контекст (аргументы) метода.

Обработка аргументов-объектов

Генерация строки, которая записывает значение аргумента в лог происходит в методе ArgumentsListToString и выглядит как: “_$g(” $lg($lg(List,i)) _ “,”_$$$quote(..#Null)_“)_”. Произведём рефакторинг и выделим её в отдельный метод GetArgumentValue, который на вход будет принимать имя переменной и её класс (а всё это нам известно из FormalSpecParsed) а на выходе будет код преобразующий переменную в строку. Для типов данных это будет уже существующий код, объекты будем преобразовывать в JSON методами SerializeObject (для вызова из клиентского кода) и WriteJSONFromObject (для конвертации объекта в JSON):

Методы GetArgumentValue, SerializeObject и WriteJSONFromObject:

ClassMethod GetArgumentValue(Name As %StringClassName As %Dictionary.CacheClassnameAs %String

{

If $ClassMethod(ClassName“%Extends”“%RegisteredObject”{

// it’s an object

Return “_##class(App.Log).SerializeObject(“_Name “)_”

Else {

// it’s a datatype

Return “_$g(” Name “,”_$$$quote(..#Null)_“)_”

}

}

ClassMethod SerializeObject(ObjectAs %String

{

Return:’$IsObject(ObjectObject

Return ..WriteJSONFromObject(Object)

}

ClassMethod WriteJSONFromObject(ObjectAs %String ProcedureBlock = 0 ]

{

// Create a string that we will redirect to

Set Str “”

Use $io::(“^”_$ZNAME)

// Enable redirection

Do ##class(%Device).ReDirectIO(1)

// Any write statements here will be redirected to the labels defined below

Do ##class(%ZEN.Auxiliary.jsonProvider).%ObjectToJSON(Object)

// Disable redirection

Do ##class(%Device).ReDirectIO(0)

Return Str

// Labels that allow for IO redirection

// Read Character – we don’t care about reading

rchr(c)      Quit

// Read a string – we don’t care about reading

rstr(sz,to)  Quit

// Write a character – call the output label

wchr(s)      Do output($char(s))  Quit

// Write a form feed – call the output label

wff()        Do output($char(12))  Quit

// Write a newline – call the output label

wnl()        Do output($char(13,10))  Quit

// Write a string – call the output label

wstr(s)      Do output(s)  Quit

// Write a tab – call the output label

wtab(s)      Do output($char(9))  Quit

// Output label – this is where you would handle what you actually want to do.

// in our case, we want to write to Str

output(s)    Set Str = Str_Quit

}

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

Открытие контекста

Идея этого метода состоит в том, чтобы сделать доступными все аргументы в текущем контексте (в основном – терминала, для отладки приложения). Для этого используется параметр метода ProcedureBlock, если установить его равным 0, то все переменные объявленные внутри такого метода, будут доступны и после выхода их метода. Наш метод, соответственно, будет открывать объект класса App.Log и десериализировать свойство Arguments.

Методы LoadContext и DeserializeObject

ClassMethod LoadContext(IdAs %Status ProcedureBlock = 0 ]

{

Return:’..%ExistsId(Id$$$OK

Set Obj = ..%OpenId(Id)

Set Arguments Obj.Arguments

Set List = ..GetMethodArgumentsList(Obj.ClassName,Obj.MethodName)

For i=1:1:$Length(Arguments,“;”)-1 {

Set Argument $Piece(Arguments,“;”,i)

Set @$lg($lg(List,i)) = ..DeserializeObject($Piece(Argument,“=”,2),$lg($lg(List,i),2))

}

Kill Obj,Arguments,Argument,i,Id,List

}

ClassMethod DeserializeObject(StringClassNameAs %String

{

If $ClassMethod(ClassName“%Extends”“%RegisteredObject”{

// it’s an object

Set st ##class(%ZEN.Auxiliary.jsonProvider).%ConvertJSONToObject(String,,.obj)

Return:$$$ISOK(stobj

}

Return String

}

В терминале это выглядит следующим образом:

zw
>
do ##class(App.Log).LoadContext(9)
zw
>a=3
>b=<OBJECT REFERENCE>[2@%ZEN.proxyObject]
zw b
>
+----------------- general information ---------------
|      oref value: 2
|      class name: %ZEN.proxyObject
| reference count: 2
+----------------- attribute values ------------------
|           %changed = 1
|         %data("A") = 1
|         %data("B") = "stringvalue"
|             %index = ""

Что дальше?

Основное улучшение, которое здесь можно сделать – это добавление ещё одного аргумента в основной макрос с произвольным списком переменных, созданных уже внутри метода.

Выводы

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

Ссылки

Часть I. Макросы
GitHub репозиторий системы логирования
Классы системы логирования

Автор выражает благодарность хабраюзерам @Daimor, @Greyder и еще одному очень компетентному инженеру, пожелавшему остаться неназванным, за помощь в написании кода.

Добавить комментарий

Ваш e-mail не будет опубликован. Обязательные поля помечены *