Pull to refresh
0
InterSystems
InterSystems IRIS: СУБД, ESB, BI, Healthcare

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

Reading time13 min
Views3.1K
Monet impression sunrise

Введение


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

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


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


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


Составим таблицу того, что нам надо хранить, сразу же напишем, когда возможно получить эти данные — во время компиляции или исполнения программы. Это потребуется при написании второй части системы — макросов, где мы, очевидно, стремимся узнать как можно больше логируемых данных во время компиляции:
Информация Время получения
Тип события Компиляция
Имя класса Компиляция
Имя метода Компиляция
Аргументы, переданные в метод Компиляция
№ строки исх. Кода Выполнение
Имя пользователя Выполнение
Дата/Время Выполнение
Сообщение Выполнение
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:


Улучшения


Написав основу системы логирования, подумаем как её можно улучшить.
Во-первых добавим возможность обработки аргументов-объектов, потому что в данный момент будут записаны только 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      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
}

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


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


Идея этого метода состоит в том, чтобы сделать доступными все аргументы в текущем контексте (в основном — терминала, для отладки приложения). Для этого используется параметр метода 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 и еще одному очень компетентному инженеру, пожелавшему остаться неназванным, за помощь в написании кода.
Tags:
Hubs:
Total votes 5: ↑3 and ↓2+1
Comments4

Articles

Information

Website
www.intersystems.com
Registered
Founded
1978
Employees
1,001–5,000 employees
Location
США