Robust audit logging
Robust audit logging
I wanted to add something to my logging so that could quickly see at a glance what the actual changes to the data were.
There's an example of logging changes here: https://editor.datatables.net/manual/php/events#Logging-changes
And a related discussion here: https://datatables.net/forums/discussion/44932
I do an additional step to compare the $prevValues and the $values and store the difference in two different fields in the database.
I add each of these events to the instance of Editor:
// Pre functions
->on( 'preEdit', function ( $editor, $id, $values ) {
getPrevValues($editor->db(), $editor->table()[0], $id);
} )
->on( 'preRemove', function ( $editor, $id, $values ) {
getPrevValues($editor->db(), $editor->table()[0], $id);
} )
// Post functions
->on( 'postCreate', function ( $editor, $id, $values, $row ) {
logChange( $editor->db(), $editor->table()[0], 'create', $id, $values );
} )
->on( 'postEdit', function ( $editor, $id, $values, $row ) {
logChange( $editor->db(), $editor->table()[0], 'edit', $id, $values );
} )
->on( 'postRemove', function ( $editor, $id, $values ) {
logChange( $editor->db(), $editor->table()[0], 'delete', $id, $values );
} )
And then I use array_intersect_key()
along with array_diff_assoc()
(in PHP) to find the difference between the two and store that in separate fields:
$prevValues = [];
function getPrevValues ( $db, $table, $id ) {
global $prevValues;
$prevValues = $db->select( $table, '*', [ 'id' => $id ] )->fetch();
}
function logChange ( $db, $table, $action, $id, $values ) {
global $prevValues;
switch ($action) {
case "create":
$old_values = [];
$new_values = $values;
break;
case "edit":
$old_values = array_intersect_key(array_diff_assoc($prevValues,$values),array_diff_assoc($values,$prevValues));
$new_values = array_intersect_key(array_diff_assoc($values,$prevValues),array_diff_assoc($prevValues,$values));
break;
case "delete":
$old_values = $prevValues;
$new_values = [];
break;
}
if (!empty($old_values) || !empty($new_values) ) {
$db->insert( 'ws_log', [
'user' => $_POST['currentUser'],
'when' => date('c'),
'table' => $table,
'row' => $id,
'action' => $action,
'same_values' => json_encode($prevValues),
'old_values' => json_encode($old_values),
'new_values' => json_encode($new_values)
]);
}
}
Now at a glance I can see 1) who made a change, 2) when it was done, 3) what table and row was it done on, 4) what type of action it was (create, edit, or delete), and 5) what the specific changes to the data were. I also have the prev_values
in case I'd like to dig deeper.
Replies
That's awesome - thanks for sharing this with us!
Allan
Please note that array $values have submited form data (as it was entered by user) but if some of fields was disabled for writing then it will not be actually saved.
In order to log proper audit data you should use array $row or read latest data from database.
@imic is completely correct.
Great update for those of us who might have data altered as it enters the database or something like virtual columns.
Here's the updated events to add to each instance of Editor:
This looks awesome, and I am trying to get it to work, but it does not log the changes into my table, and doesn't provide any errors.
Does the update happen via the JSON? because I also don't see the query to insert it. The changes to the source table happen as expected.
my editor code:
```
<?php
include("../lib/DataTables.php");
use
DataTables\Editor,
DataTables\Editor\Field,
DataTables\Editor\Format,
DataTables\Editor\Join,
DataTables\Editor\Mjoin,
DataTables\Editor\Options,
DataTables\Editor\Upload,
DataTables\Editor\Validate,
DataTables\Editor\ValidateOptions;
Editor::inst( $db, 'requirements R', 'R.id' )
->field(
Field::inst( 'R.id' ),
Field::inst( 'R.paSection AS clause' ),
Field::inst( 'R.requirement' ),
Field::inst( 'R.cxStage' ),
Field::inst( 'R.SL1' )
->options( Options::inst()
->table('yesno')
->value('ID')
->label('yesNo')
)
->setFormatter( Format::ifEmpty( null )),
Field::inst( 'R.SL9' )
->options( Options::inst()
->table('yesno')
->value('ID')
->label('yesNo')
)
->setFormatter( Format::ifEmpty( null )),
Field::inst( 'Y.yesNo' ),
Field::inst( 'Y1.yesNo' ),
Field::inst( 'R.test' ),
Field::inst( 'R.ctsComment' ),
Field::inst( 'R.hmqeComment' ),
Field::inst( 'R.hmqeAgree' )
->options( Options::inst()
->table('yesno')
->value('ID')
->label('yesNo')
)
->setFormatter( Format::ifEmpty( null )),
Field::inst( 'Y2.yesNo' ),
Field::inst( 'R.hmqeSL9' )
->options( Options::inst()
->table('yesno')
->value('ID')
->label('yesNo')
)
->setFormatter( Format::ifEmpty( null )),
Field::inst( 'Y3.yesNo' ),
Field::inst( 'R.ctsResponse' ),
)
// Pre functions
->on( 'preEdit', function ( $editor, $id, $values ) {
getPrevValues($editor->db(), $editor->table()[0], $id);
} )
->on( 'preRemove', function ( $editor, $id, $values ) {
getPrevValues($editor->db(), $editor->table()[0], $id);
} )
// Post functions
<?php > ``` ?>->on( 'postCreate', function ( $editor, $id, $values, $row ) {
logChange( $editor->db(), $editor->table()[0], 'create', $id, $row);
} )
->on( 'postEdit', function ( $editor, $id, $values, $row ) {
logChange( $editor->db(), $editor->table()[0], 'edit', $id, $row );
} )
->on( 'postRemove', function ( $editor, $id, $values ) {
logChange( $editor->db(), $editor->table()[0], 'delete', $id, $row );
} )
->leftJoin( 'yesno Y', 'Y.ID', '=', 'R.SL1' )
->leftJoin( 'yesno Y1', 'Y1.ID', '=', 'R.SL9' )
->leftJoin( 'yesno Y2', 'Y2.ID', '=', 'R.hmqeAgree' )
->leftJoin( 'yesno Y3', 'Y3.ID', '=', 'R.hmqeSL9' )
->debug(true)
->process( $_POST )
->json();
My db table is:
Appreciate any help.
Not sure if this is the issue (would depend on your database set up) but you're missing the "changeDate" value on your insert statement.
Yeah, I took that out and have it auto generated in the DB when the record is created using TIMESTAMP.
Ah, ok . . . that makes sense.
Then I don't see anything offhand.
To help troubleshoot, you can do a
var_dump
in both thegetPrevValues
and thelogChange
functions and it will show you the results in the response window where you see the returned JSON.For example:
That will at least show if the
$prevValues
are being retrieved correctly.Another place to check would be in the
logChange
function to see the values of$old_values
and$new_values
before this statement:(!empty($old_values) || !empty($new_values)
If those are both empty then you can use
var_dump
to troubleshoot other variables further up the chain to see what's going on.Also, I've updated the code since I originally posted this, so maybe the new code will give you something to consider? Essentially I've added a
changes
variables to show the difference between the old and the new values. In practice, I only look at this field 99% of the time.I have a generic _logchange.php file:
Which is then included in all my Datatables editor php pages, like this:
That's an awesome bit of help there Loren, let me step through them and get back to you.
Loren,
Still the same issue, I switched to your updated version, but alas no joy.
var_dump of prevValues gives me the JSON response, but not inside the
var_dump of old_values & new_values gave me an empty array for both.
I placed them straight after they are declared.
I then var_dump $prevValues & $row, both show info. prevValue shows entry before edit, row shows entry after edit, as expected. It therefore appears the issue is in this declaration:
the JSON reponse to this:
is:
I feel we are close! I appreciate all the help.
Ok, I think I know what it is. It looks like the joins
1, The joins provide more info into $row that what is in $prevValues because it includes the joined value as well.
I notice the $row also has a "DT_RowId" in its array that $prevValues does not, no idea if that is an issue.
I have fixed the names being different in the two (just in case that causes issues)
So, any idea how to fix it?
Yes, it definitely looks like the joins are the issue since $row is in a different format than $row without the joins.
If you want a solution for just this situation, then I'd recommend doing the comparison against $prevValues and $row['R'].
If you wanted a more generic solution, then I'd recommend inside the logChange function doing another query of the table and row id (like what was done in
getPrevValues
to get the data of just the row without the joins and do the comparison on that.I'll include a code snippet later, but right now I'm working off my phone and without my glasses, so I'm not certain I can pull it off without typos!
Ok, here's option 1, which is to simply compare
$row['R']
with$prevValues
:I believe this will work for your current situation.
However you can make the logChange function more generic by retrieving the row data after the update for the comparison. This will allow the function to be the same regardless of whether joins are used or not.
Here is the complete logChange code with comments:
This should work (although I haven't tested).
Loren, take a bow! You're officially a genius and my hero!
Thank you very much for the support here.
Thanks, rob1st -- glad you're squared away and also glad the code in now improved!
First of all, my thanks to @Loren Maxwell and @rob1st for expanding on the original post. I am implementing this logging method, but I have hit a problem: the logger does not work correctly for multiple updates.
For example, if I have this data:
id |title |name
-------------+--------------------+------
137794 | Title Four |
137793 | Title Three |
137792 | Title Two |
137791 | Title One |
and I select those four rows for a multiple update, the logger result is this:
previous data |new data
------------------------------+---------------------------------------------------------------------
137791 |Title One | |137794 |Title Four |Name applicable to all four titles
137791 |Title One | |137793 |Title Three |Name applicable to all four titles
137791 |Title One | |137792 |Title Two |Name applicable to all four titles
137791 |Title One | |137791 |Title One |Name applicable to all four titles
It looks like an array loop error, whereby the last element overwrites its predecessors,
but that's only a guess. I haven't managed to find the error.
Has any other user of this logging code seen similar results for multi-updates?
P.S. Sorry about the diagram - forum removing the spacing.
Ah yes . . . I remember having this issue as well.
I resolved it by turning off the Editor option for multiple updates, although that's probably not the solution you you were hoping for :-)
For my use case, multiple edits weren't common so it didn't matter and I didn't investigate further then or think too much about it since.
I'm going off memory from a couple of years ago, but I suspected Editor of executing all the
preEdit
calls before any of the actual updates so that$prevValues
was being overwritten by each successive update before any were being written to the database.For example:
- preEdit row 1 (get
$prevValues
)- preEdit row 2 (get
$prevValues
)- preEdit row 3 (get
$prevValues
)- preEdit row 4 (get
$prevValues
) ### <- only last$prevValues
is carried forward- update row 1
- update row 2
- update row 3
- update row 4
- postEdit row 1
- postEdit row 2
- postEdit row 3
- postEdit row 4
@allan or @colin or @sandy (or someone else) would have to give a definitive answer, but that was the suspicion I had but never followed up on.
Hi Loren - thanks for replying.
That's pretty much my best guess as well. Let's see if the devs can shine a light on it for us.
Thanks again.
BELOW HAS NOT BEEN TESTED!!
I was thinking about this last night and one idea is to make
$prevValues
into a multidimensional associative array with the$id
as the initial key since the$id
is unique for each row of the update. This will preserve all the previous values rather than overwriting them.The new
getPrevValues
function:Then the
logChange
function would become:Anyway, not tested but I think it should work . . .
That is exactly what happens. The idea for it is that you can do validation on the rows and exit out before interacting with the database for any if one fails.
@Loren Maxwells suggestion looks good to me!
Another option is to use the
postCreate
/postEdit
events to insert the auditing rather than thepre
events. As long as you have transactions enabled, that would be perfectly safe.Allan
@allan,
I'm confused by this part:
Would the
$prevValues
be available by the time apost
function executes?The
logChange
function is currently only called during thepostCreate
/postEdit
/postRemove
functions, but thegetPrevValues
is called during thepre
events.Thanks, Loren!
I had the same thought last night, but sleep intervened.
I have now implemented the change and thus far everything works fine. My version is rather slimmed-down (e.g. I don't use the array-diff stuff) but it does what I need. If anything untoward turns up I'll report back in here. Thanks again!
Also, thanks Allan.
@tangerine
Did you use Loren's code or did you modify it, be good for those of us who love this function.
My code incorporates the multidimensional associative array for $prevValues as explained by Loren.
Otherwise, I don't use any of the "changes" mechanism, and I have some amendments specific to my application. For example, my function "getPrevValues" defines a $select variable rather than using "*".
Also I'm passing a table name to function "logChange" so I can use it generically.
I suggest you go with Loren's code initially and tailor it to your own needs if you want something different.
Thanks
Yes sorry I wasn't clear on this. Only if you used a lookup index like you suggested earlier - it could be keyed off the primary key. That is probably how I would approach this myself I think.
Allan
A small update to the most recent version that allows for multiple edits.
When a new record is inserted,
$prevValues
is not set, so any reference to$prevValues['id']
throws aUndefined offset: 38804
PHP error.The fix is to use the
??
assignment operator to instead usenull
, as in:The updated portion of the code:
And the complete code:
Nice, thanks for reporting back,
Colin
Making just a tiny change to the code for anyone following this discussion.
The previous code inserts the string
null
for the prev_values on a create. I'm updating it to insert an empty array[]
.Complete code is now:
You don't actually have to query the database for the old values I think. You can have the Editor post the old and new values together so that you can compare directly on the server side. Like:
Now at the server side you can read
$_POST['oldValues']
(of course for editing mode only) which is directly comparable to the$row
parameter of the event listener with onlyarray_diff()
.Correction to my previous post:
array_diff_assoc()
should be used, notarray_diff()
. I think there is no need to save both new and old data while you can (and IMHO you should) save only changes. Here is a much shorter and more performant logger which logs only changes and doesn't require a querying to the DB:Note: This will log only changes if there is an update or only new values if there is a creation or only old values if there is a removal. Because if there is an update, changes are the fields only which are changed; if it is a removal, changes are the data which is deleted, if it is a creation, changes are the newly created values.
Note that for this to work, you need to set
submit
informOptions
toallIfChanged
(see alsoform-options
) to have all data sent to server when there is a change and you also need to send "old" data as well (i.e. before edit), so that you wouldn't need to make an extra query to the DB to fetch it. Like in the previous post I made:Note that this may not work if you are using
cell
scope and notrow
. Anyways, you would want to work on rows if you are interested in logging changes. Now at the server side, listen for proper events like: