Article
· Apr 18, 2017 9m read

Tracking Data Changes - Audit Log - 1 of 2

Introduction

The common requirement in many applications is logging of data changes in a database - which data has changed, who changed them and when (audit logging). There are many articles about this question and there are different approaches on how to do that in Caché.

I'm sharing a mechanism that can help you implement your framework to track and record data changes. This mechanism creates a trigger through an "objectgenarator" method once your persistent class inherits from the "Audit Abstract Class" (Sample.AuditBase). Since your persistent class inherits Sample.AuditBase, when you compile your persistent class the trigger for auditing changes will be generated automatically.


Audit Class  

This is the class where the changes will be recorded.

Class Sample.Audit Extends %Persistent
{
          Property Date As %Date;

          Property UserName As %String(MAXLEN = "");

          Property ClassName As %String(MAXLEN = "");

          Property Id As %Integer;

          Property Field As %String(MAXLEN = "");

          Property OldValue As %String(MAXLEN = "");

          Property NewValue As %String(MAXLEN = "");
}

Audit Abstract Class  

This is the abstract class that your persistent class will inherits from. This class contains the trigger method (objectgenerator) that knows how to identify which field has been modified, who changed that, what are the old and new values, etc., besides writing the changes in the audit table (Sample.Audit).

Class Sample.AuditBase [ Abstract ]
{

Trigger SaveAuditAfter [ CodeMode = objectgenerator, Event = INSERT/UPDATE, Foreach = row/object, Order = 99999, Time = AFTER ]
{
          #dim %compiledclass As %Dictionary.CompiledClass
          #dim tProperty As %Dictionary.CompiledProperty
          #dim tAudit As Sample.Audit

          Do %code.WriteLine($Char(9)_"; get username and ip adress")
          Do %code.WriteLine($Char(9)_"Set tSC = $$$OK")
          Do %code.WriteLine($Char(9)_"Set tUsername = $USERNAME")

          Set tKey = ""
          Set tProperty = %compiledclass.Properties.GetNext(.tKey)
          Set tClassName = %compiledclass.Name

          Do %code.WriteLine($Char(9)_"Try {")
          Do %code.WriteLine($Char(9,9)_"; Check if the operation is an update - %oper = UPDATE")
          Do %code.WriteLine($Char(9,9)_"if %oper = ""UPDATE"" { ")

          While tKey '= "" {
                    set tColumnNbr = $Get($$$EXTPROPsqlcolumnnumber($$$pEXT,%classname,tProperty.Name))
                    Set tColumnName = $Get($$$EXTPROPsqlcolumnname($$$pEXT,%classname,tProperty.Name))

                    If tColumnNbr '= "" {

                              Do %code.WriteLine($Char(9,9,9)_";")
                              Do %code.WriteLine($Char(9,9,9)_";")
                              Do %code.WriteLine($Char(9,9,9)_"; Audit Field: "_tProperty.SqlFieldName)
                              Do %code.WriteLine($Char(9,9,9)_"if {" _ tProperty.SqlFieldName _ "*C} {")
                              Do %code.WriteLine($Char(9,9,9,9)_"Set tAudit = ##class(Sample.Audit).%New()")
                              Do %code.WriteLine($Char(9,9,9,9)_"Set tAudit.ClassName = """_tClassName_"""")
                              Do %code.WriteLine($Char(9,9,9,9)_"Set tAudit.Id = {id}")
                              Do %code.WriteLine($Char(9,9,9,9)_"Set tAudit.UserName = tUsername")
                              Do %code.WriteLine($Char(9,9,9,9)_"Set tAudit.Field = """_tColumnName_"""")
                              Do %code.WriteLine($Char(9,9,9,9)_"Set tAudit.Date = +$Horolog")

                              Do %code.WriteLine($Char(9,9,9,9)_"Set tAudit.OldValue = {"_tProperty.SqlFieldName_"*O}")
                              Do %code.WriteLine($Char(9,9,9,9)_"Set tAudit.NewValue = {"_tProperty.SqlFieldName_"*N}")

                              Do %code.WriteLine($Char(9,9,9,9)_"Set tSC = tAudit.%Save()")
                              do %code.WriteLine($Char(9,9,9,9)_"If $$$ISERR(tSC) $$$ThrowStatus(tSC)")

                              Do %code.WriteLine($Char(9,9,9)_"}")
                    }
                    Set tProperty = %compiledclass.Properties.GetNext(.tKey)
          }

          Do %code.WriteLine($Char(9,9)_"}")

          Do %code.WriteLine($Char(9)_"} Catch (tException) {")

          Do %code.WriteLine($Char(9,9)_"Set %msg = tException.AsStatus()")
          Do %code.WriteLine($Char(9,9)_"Set %ok = 0")
          Do %code.WriteLine($Char(9)_"}")

          Set %ok = 1
}

}

Data Class (Persistent Class)

This is the user data class that the user (application) make changes, create records, delete records, do whatever you allow him to do. :). In summary, this is usually your %Persistent class.

To start traking and record changes you will need to inherits the Persistent Class from the Abstract Class (Sample.AuditBase).

Class Sample.Person Extends (%Persistent, %Populate, Sample.AuditBase)
{
          Property Name As %String [ Required ];

          Property Age As %String [ Required ];

          Index NameIDX On Name [ Data = Name ];
}

Testing

Since you have inherited the data class Sample.Person) from the Audit Abstract Class (Sample.AuditBase) you are able to insert data, make changes and look at the changes recorded on the Audit Class (Sample. Audit).

In order to test that you will need to create a Test() class method on the Sample.Person class or any other class of your choice.

ClassMethod Test(pKillExtent = 0)
{
          If pKillExtent '= 0 {
                    Do ##class(Sample.Person).%KillExtent()
                    Do ##class(Sample.Audit).%KillExtent()
          }

          &SQL(INSERT INTO Sample.Person (Name, Age) VALUES ('TESTE', '01'))
          Write "INSERT INTO Sample.Person (Name, Age) VALUES ('TESTE', '01')",!
          Write "SQLCODE: ",SQLCODE,!!!

          Set tRS = $SYSTEM.SQL.Execute("SELECT * FROM Sample.Person")
          Do tRS.%Display()

          &SQL(UPDATE Sample.Person SET Name = 'TESTE 2' WHERE Name = 'TESTE')
          Write !!!
          Write "UPDATE Sample.Person SET Name = 'TESTE 2' WHERE Name = 'TESTE'",!
          Write "SQLCODE:",SQLCODE,!!!

          Set tRS = $SYSTEM.SQL.Execute("SELECT * FROM Sample.Person")
          Do tRS.%Display()

          Quit
}

Run the Test() method:

d ##class(Sample.Person).Test(1)

Parameter 1 will kill extent from Sample.Person and Sample.Audit classes.

 

The Test class method does the following:

  • Insert a new person with name "TEST";
  • Shows the insert result;
  • Update the person "TEST" to "TEST ABC";
  • Show the update result;

Now you can check the audit log table. In order to do that open the System Managment Portal->System Explore->SQL. (Do not forget to switch to your namespace)

Run the following SQL command and check the results:

SELECT * FROM Sample.Audit 

 

Note that the OldValue is "TEST" and the NewValue is "TEST ABC". From now on you can make your own tests by changing the name of "TEST ABC" to "Your own name" and or change the Age values, for example. See:

UPDATE Sample.Person SET Name = 'Fabio Goncalves' WHERE Name = 'TEST ABC'

 


Generated Code

Considering that you have implemented the auditing mechanism bellow, on your computer launch the Studio (or Atelier), open the Persistent Class (Sample.Person) and inspect the intermediate code generated after compiling Sample.Person class. To do so type Ctrl + Shift + V (View Other Source Code) - inspect .INT. Scroll down up to zSaveAuditAfterExecute label and take a look at the generated code:

 

Advantages

It is simple to implement audit logging based on rolling out old data. You do not need additional tables. Maintenance is simple, too. If you decide to remove old data, then it is the matter of one SQL.

If you need to implement audit logging in more tables, just inherits from the Abstract Class (Sample.AuditBase)

Make changes according to your need. e.g.: record changes on Streams.

Record just modified fields. Do not save the entire record changed.

Disadvantages

The problem can be that when data changes, then the whole record is copied, i.e. also data which does not change.

If table person has a column "photo" with binary data (stream) containing the photography then each and every time yhe user changes the picture  the role stream is recorded (consuming disk space). 

Another disadvantage is that the complexity of each table supporting audit logging increases. You must have in mind all the time that retrieving the records can not be simple. You always have to use the SELECT clause with condition: "...WHERE Status = active" or considering some "DATE INTERVAL"

All data changes are logged in a common table.

Think about transcation an rollbacks.


Aduting is an important requirement for some applications to be efficient. Typically, to determine data changes, application developers must implement a custom tracking method in their applications by using a combination of triggers, timestamp columns, and additional tables. Creating these mechanism usually involves a lot of work to implement, leads to schema updates, and often carries a high performance overhead. This is a simple example that can help you to start creating your own framework.  

Take a look at the next article

Discussion (9)2
Log in or sign up to continue

Great article, Fabio!

The problem can be that when data changes, then the whole record is copied, i.e. also data which does not change.

That can be solved by checking m%<property> value. It has false positives sometimes (when you change value back, i.e.: a-b-a) and calling log code only if property value has changed.

Forgot that it's only about object access. Still, you have old and new value, so:

Do %code.WriteLine($Char(9,9,9)_"Set tOldValue = {"_tProperty.SqlFieldName_"*O}")
Do %code.WriteLine($Char(9,9,9)_"Set tNewValue = {"_tProperty.SqlFieldName_"*N}")
Do %code.WriteLine($Char(9,9,9)_"if {" _ tProperty.SqlFieldName _ "*C},tOldValue'=tNewValue {")

 

All data changes are logged in a common table.

Why not generate a separate log table for each class, inheriting from logged class, so 1 change == 1 record in log table. It also gives you the possibility of writing "easy" diff tool, so audit results can be displayed conveniently.

If table person has a column "photo" with binary data (stream) containing the photography then each and every time yhe user changes the picture  the role stream is recorded (consuming disk space). 

That problem can be solved by creating immutable stream-containing class.

/// Immutable wrapper for stream
Class User.Document Extends %Persistent
{

/// Global identifier to give to user (prevent id traversal)
Property guid As %String [ InitialExpression = {$system.Util.CreateGUID()}, Required ];

/// Creation date time
Property createDateTime As %TimeStamp [ InitialExpression = {$ZDATETIME($ZTIMESTAMP, 3, 1, 3)};

/// File name as supplied by user (only for display purposes)
Property fileName As %String(MAXLEN =1000) [ Required ];

/// File stream
Property content As %FileBinaryStream;

/// User who uploaded the file
Property user As %String [ InitialExpression = {$username} ];

/// Add new stream
/// realName - real name of a stored file
/// suppliedName - name supplied by user, used only for display purposes
/// stream - stream with data
Method %OnNew(realName As %String = "", suppliedName As %String = "", stream As %Stream.Object = {##class(%FileBinaryStream).%New()}) As %Status [ Private, ServerOnly = 1 ]
{
    #dim sc As %Status = $$$OK
    set ..fileName = ##class(%File).GetFilename(suppliedName)
    set ..content.Filename = realName
    set sc = ..content.CopyFromAndSave(stream)
    quit sc
}

/// Serve file on web
Method serve() As %Status
{
    #dim sc As %Status = $$$OK
    #dim %response As %CSP.Response
    kill %request.Data
    set %request.Data("STREAMOID",1)= ##class(%CSP.StreamServer).Encrypt(..content.%Oid())
    if ##class(%CSP.StreamServer).OnPreHTTP() {
        set %response.Headers("Content-Disposition")="attachment; filename*=UTF-8''"_##class(%CSP.Page).EscapeURL(..fileName,"UTF8")
        set st = ##class(%CSP.StreamServer).OnPage()
    }

    quit sc
}

That way your audit log table would contain only id references.

This is great stuff, many thanks Fabio.

Is there a way to get child tables created as array property projections (due to a property in a persistent class that's 'as array of' a %SerialObject class) to inherit  the generated trigger, as well as the parent persistent class inheriting this? Or is there a way otherwise to capture the result of inserts/updates/deletes into member rows of these collections via the generated trigger call in %SQLAfterTriggers?  

For direct 'as [%SerialObject class]' properties (not collection 'as array of'), this generated 'elseif property type=serial' logic works for me to create entries in a child audit table devoted to fieldname, old value, new value (note it checks disk against old, as pNew values still match pOld for the serial objects at this point in the aftersave):

 While tKey '= "" {
    set tColumnNbr = $Get($$$EXTPROPsqlcolumnnumber($$$pEXT,%classname,tProperty.Name))
    set tColumnName = $Get($$$EXTPROPsqlcolumnname($$$pEXT,%classname,tProperty.Name)) 
    set tPropertyType = $Get($$$EXTPROPtype($$$pEXT,%classname,tProperty.Name))
    set tPropertyTypeCategory = $Get($$$EXTPROPtypecategory($$$pEXT,%classname,tProperty.Name))
    set tPropertyOnDisk = $Get($$$EXTPROPondisk($$$pEXT,%classname,tProperty.Name))
    set tPropertyOnDisk = $replace(tPropertyOnDisk,"(id)","({id})")

    If tColumnNbr '= "" {
        Do %code.WriteLine($Char(9,9,9)_"if {" _ tProperty.SqlFieldName _ "*C} {") 
 
                 //%code.WriteLine logic from your example

        Do %code.WriteLine($Char(9,9,9)_"}elseif ("""_tPropertyTypeCategory_"""=""serial"") { ")
        Do %code.WriteLine($Char(9,9,9,9)_"if ##class(%Dictionary.CompiledClass).%ExistsId("""_tPropertyType_""") {")
        Do %code.WriteLine($Char(9,9,9,9,9)_"set (tOld,tNew)="""",(ptr,tChildCounter)=0")
        Do %code.WriteLine($Char(9,9,9,9,9)_"set tChildList = "_tPropertyOnDisk)
        Do %code.WriteLine($Char(9,9,9,9,9)_"if $listvalid(tChildList) {")
        Do %code.WriteLine($Char(9,9,9,9,9,9)_"while $listnext(tChildList,ptr,value) {")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9)_"set tChildCounter=tChildCounter+1")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9)_"set tNew(tChildCounter)=value")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9)_"set tOld(tChildCounter)=$listget({"_tProperty.SqlFieldName_"*O},tChildCounter)")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9)_"if tOld(tChildCounter)'=tNew(tChildCounter) {")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9,9)_"set tChildObj=##class(%Dictionary.CompiledClass).%OpenId("""_tPropertyType_""")")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9,9)_"if $ISOBJECT(tChildObj) {")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9,9,9)_"Set tAuditDelta = ##class(Sample.AuditDelta).%New(ParentId)") 
        Do %code.WriteLine($Char(9,9,9,9,9,9,9,9,9)_"do tAuditDelta.AuditParentSetObjectId(ParentId)")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9,9,9)_"set tAuditDelta.AuditDeltaField = tChildObj.Properties.GetObjectIdAt((tChildCounter+1))")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9,9,9)_"set tAuditDelta.AuditDeltaOldValue = tOld(tChildCounter)")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9,9,9)_"set tAuditDelta.AuditDeltaNewValue = tNew(tChildCounter)")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9,9,9)_"set tSC = $$$ADDSC(tSC,tAuditDelta.%Save())") 
        D%code.WriteLine($Char(9,9,9,9,9,9,9,9,9)_"if $$$ISERR(tSC) $$$ThrowStatus(tSC)") 
        Do %code.WriteLine($Char(9,9,9,9,9,9,9,9)_"}")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9,9)_"kill tChildObj")
        Do %code.WriteLine($Char(9,9,9,9,9,9,9)_"}")
        Do %code.WriteLine($Char(9,9,9,9,9,9)_"}")
        Do %code.WriteLine($Char(9,9,9,9,9)_"}")  
        Do %code.WriteLine($Char(9,9,9,9)_"}")
        Do %code.WriteLine($Char(9,9,9)_"}") 

 

I kept the if-elseif in the generated code (rather than generating conditionally) because object %Save satisfies the trigger syntax *C (pChanged) check, but SQL update to properties in the serial object doesn't in my tests (the former dumps the full serial object list from the pOld and pNew arrays  into the child audit table's old value and new value fields, versus the serial list creating a child entry for each field updated in the serial object).  The GetObjectIdAt(counter+1) isn't really feasible based on key not always equaling list location, but it's a place holder until I refine it.