Audit Logging and ATNA - patch submitted

visolveemr wrote on Wednesday, January 27, 2010:

Hi Team,

Audit Logging and ATNA patch is placed in the sourceforge tracker at https://sourceforge.net/tracker/?func=detail&aid=2939284&group_id=60081&atid=1245239.

Do share your views.

Thanks
ViCarePlus Team

sunsetsystems wrote on Thursday, January 28, 2010:

Would be nice to see a demo of this… can’t say much just from looking at the code.

Rod
www.sunsetsystems.com

bradymiller wrote on Thursday, January 28, 2010:

(couldn’t test but here is a read through review):
1) Not sure if this is useful information, but here are other places that database stuff happens (these are where I had to place SET UTF8 statements to ensure UTF8 worked trhoughout openemr):
-postpuke calendar stuff:  openemr/interface/main/calendar/includes/pnAPI.php
-php-gacl access controls: openemr/gacl/gacl.class.php
2) Instead of formtrim, in the future, use other functions in formdata.inc.php:
http://www.openmedsoftware.org/wiki/Development_Policies#Input_Collection

interface/logview/logview.php
-Date widgets need their strings wrapped in xl()
-$event_types=array(“select”, “update”, “insert”, “delete”, “replace”); could be simplified by creation and use of a list (more for the labeling and internationalization aspect):
http://www.openmedsoftware.org/wiki/Development_Policies#Creating_a_list_in_list_options
-272 in patch top.session() stuff (not sure needed since can’t see entire file):
http://www.openmedsoftware.org/wiki/Development_Policies#PHP_Sessions_and_Browser_Windows

/library/adodb/adodb.inc.php
–some charset issues in comments on line 612-614 of patch

library/log.inc
–assuming not yet done with this since-> /* TODO - EventTypeCode */

sql/3_2_0-to-3_3_0_upgrade.sql
use #IfMissingColumn function
(also test this script on a previous version twice consecutively (that way you test the upgrade and test to ensure nothing happens on second attempted upgrade)

-brady

visolveemr wrote on Monday, February 15, 2010:

Hi Brady,

Auditing postnuke and php-gacl are already included. The suggestions are incorporated and the modified patch is placed in the tracker.  The contents are:-

a. Modified patch
b. Patch to take the backup of the ‘log’ table
c. Diff between previous version and this version for easy review

Hope this helps.  Will send the demo url in a separate email.

Thanks
ViCarePlus Team
.

bradymiller wrote on Saturday, February 20, 2010:

wow,
This thing is really cool on initial testing. Plan to do a detailed review later today.
-brady

bradymiller wrote on Saturday, February 20, 2010:

Review on this patch:
http://sourceforge.net/tracker/?func=detail&aid=2939284&group_id=60081&atid=1245239

1)Couldn’t get checksums to show up in the log
2)I see it in the log, but I can’t figure out how your getting the php-gacl queries or all the postpuke queries? (enlighten my stupidity here)

openemr/Documentation/README-Log-Backup.txt
—see openemr/interface/main/backuplog.php feedback

openemr/interface/main/backuplog.php
—Would this be more clear if collected the tmp-directory from globals.php (see openemr/interface/main/backup.php feedback where i suggest explicitly setting this in globals.php)? Then no need to modify parameter settings in cron script.
—Consider providing an error mechanism, so do not manipulate the database at all if the backup file mechanism does not work

openemr/interface/main/backuplog.sh
—see openemr/interface/main/backuplog.php feedback

openemr/interface/globals.php
—More description needed. Explain settings (1 is on, and 0 is off) and quickly explain what the general auditlog functionality is.
—Put it at the bottom of the file with your other settings

openemr/interface/logview/logview.php
—Consider use of formdata.inc.php functions if applicable (just ensure you understand the functions in formdata.inc.php; I’ll let you use your own judgment whether these functions will be applicable in this script)

openemr/interface/main/backup.php
—Don’t use translated words in the algorithms(line 97 of backup patch); use another mechanism that does not rely on the value (which gets translated). For example, do what the TEXT_IMPORT stuff does and make a button with a different ‘name’ in the html tag.
—Remove trailing spaces in xl functions at line 113 in backup patch.
—in line 113, not entirely clear what line means; Perhaps somehting like this will be more clear “Please refer to the README-Log-Backup.txt file in the Documentation directory to learn how to automate the process of creating log backups”. Also, this message seems to steal the screen (main function of this screen is to provide a backup of data, which gets overridden by the formatting and placement of this message. Please make it more subtle, and make it so it is obviously only associated with the ‘Create Eventlog Backup’ button.)
—Is the ‘temporary directory’ really the best place for this stuff? Storing confidential stuff in the php tmp directory seems very insecure. Seem more appropriate to have users explicitly set the log backup directory in globals.php, which can also be used by your cron script.
—Provide an error mechanism, so do not manipulate the database at all if the backup file mechanism does not work
—Remove trailing space in xl function at line 166 in backup patch (second one I’ve noticed; please check all your xl functions to ensure no leading or trailing whitespaces in them. Read developer policies in wiki if need refresher in the xl stuff)

openemr/library/log.inc
—when matching for sql command in the sql_checksum_of_modified_row functon, would it make more sense to use a php matching function to deal better with caps vs not caps (ie, no need to look for SET, set, Set, SeT).
—It is an OpenEMR no-no to call native mysql function. please use the sql.inc wrapper functions (line 869 and 870 of patch). Gives more flexibility in future if want to support other databases etc.
—What are the soundex fucntions for checking for breakglass user? Does this functionality work.

openemr/library/sql.inc
—ok

openemr/library/adodb/adodb.inc.php
—ok

openemr/sql/3_2_0-to-3_3_0_upgrade.sql
—ok

openemr/sql/database.sql
—ok

thanks,
brady

bradymiller wrote on Saturday, February 20, 2010:

VicarePlus Team and Rod,
Overall, this is really cool stuff. Also, as long as Rod agrees(Rod, if you can, just quickly peruse for potential pitfalls; I couldn’t find any pitfalls), this stuff can be committed to SF cvs. I’d like to see the temp directory issue from the openemr/interface/main/backup.php script (not the cron related script stuff since not critical to openemr function/security) dealt with before the first commit; otherwise, everything else can be done after commit.
-brady

sunsetsystems wrote on Monday, February 22, 2010:

Yes commit to CVS sounds fine, especially as the previous logging code was awful.  :slight_smile:

But looking at the log page, I see a few things that need some work.  I think some of these are areas that were problematic before and I was hoping this rewrite would be a chance to clean them up:

(1) There is a bug where if you click “Logs” in the menu and then the mouse is positioned in the area where the logs are displayed, that line is left highlighted after your mouse leaves it and is forever in the wrong highlight state.

(2) It doesn’t seem very useful to record and show the complete SELECT statement for each query.  There ought to be some more concise and user-understandable ways to show what was done.

(3) There are many cases where the same log entry is repeated.  I think this may be happening when scripts in multiple frames are responding to some user action and get the same information at the same time.  This is another area where logging at too low a level will be confusing to the user.

(4) There’s an awful lot of logging and over time this can make the database quite large.  This also touches on the same point where it would be nicer to log events at a higher level.

(5) The log viewer should be pageable, especially due to (4), the size of a day’s logs can be huge.

Rod
www.sunsetsystems.com

visolveemr wrote on Monday, February 22, 2010:

Hi Rod & Brady,

Thanks for your views here.

Brady

The checksums would be displayed when “Include checksum” option is chosen.

php-gacl and postnuke queries are retrived by inserting the function’auditSQLEvent’ in “library/adodb/adodb.inc.php”

soundex function is used to check for the emergency users (users whose name start with “emergency” or “breakglass”) so that the auditing will not be disabled at any case . It is working fine.

We’ve used mysql_query function because we don’t want to print the error statements in case if we are not able to calculate the checksum. We’ll perform some customization in the existing sqlstatement in order to achieve this.

We’re working on the other suggestions.

Rod

1. We are not facing any issues. The highlighting gets changed when we move the mouse. What browser are you using?

2. Are you referring to “SELECT” statements alone or all the “SQL” statements?
For database update, currently we are updating all the values to the database for a single column change, so it would be too difficult to exactly identify what value has changed. If we have this flexibility, we can certainly provide some meaningful information by parsing the queries.

3 & 4

The large set of logging happens particularly for the “select” queries. We can make set audit_events to 0 to ignore ‘select’ statements. Only the required audit events can be enabled for logging through globals.php

2 & 5 - Can be considered as enhancements

Thanks
ViCarePlus Team
www.vicareplus.com

sunsetsystems wrote on Monday, February 22, 2010:

Re the highlighting problem, I am using Firefox 3.0.17 for Ubuntu.  But I doubt that matters.  Try this: in the Log viewer, click  and then before the screen redraws, start moving your mouse around continuously in the area where log events will be listed.  I think you’ll see the problem.

For the other stuff I’d encourage some creative thinking as to how the logs can be made more user-friendly and helpful.  And I’d say logging of SELECTs should be off by default,if they are not already.  Also it should be easy to omit duplicate log messages that occur at or near the same time.

Rod
www.sunsetsystems.com

visolveemr wrote on Monday, February 22, 2010:

Hi Rod,

I think we can consider the changes suggested (given below)  as Phase-II enhancements where we can submit the current audit changes to sourceforge CVS.  Do share your views here.

a. Making the log messages more user friendly
b. Omitting duplicate log messages
c. Pagination for the log viewer
d. The issue you’d mentioned with the log viewer

Thanks
ViCarePlus Team
www.vicareplus.com

sunsetsystems wrote on Monday, February 22, 2010:

Yes, as I said it’s OK to commit your updates and then work on these things later.  Thanks!

Rod
www.sunsetsystems.com

visolveemr wrote on Friday, March 05, 2010:

Hi Rod/Brady,

The following suggestions are incorporated and the modified patch 'Visolve_Audit_Mar5.tgz 'is placed in https://sourceforge.net/tracker/?func=detail&aid=2939284&group_id=60081&atid=1245239

a. Globals.php variables to bottom
b. Setting the query option by default to 0
c. Using functions in formdata.php (logview.php)
d. Using php matching functions in log.inc
e. Changed direct myql_query to pass via sql.inc in log.inc
f. Changes to backuplog.php as suggested

Future enhancements

(1) Issue faced by Rod - There is a bug where if you click “Logs” in the menu and then the mouse is positioned in the area

where the logs are displayed, that line is left highlighted after your mouse leaves it and is forever in the wrong highlight

state.

(2) User understandable way of reporting

(3) Avoiding duplicate log entries display

(4) Log viewer pageable

Hope this helps. Do share your views.

Thanks
ViCarePlus Team

bradymiller wrote on Saturday, March 06, 2010:

hey,

This is ready to be committed. I have some minor issues, which can be done after you commit this current code to SF (sounds like John needs this stuff in the tip for other work, so good to get it in now).

openemr/interface/globals.php
—We should at least pretend to support a windows user. There’s a mechanism already in place to give directories for both linux and windows users (the end of the globals.php then has algorithm to choose correct one). (this is simple and we can do this after you commit the current code to SF)
—Make sure your settings are above this line (this can be done after you commit current code to SF):
// Don’t change anything below this line. ////////////////////////////

openemr/interface/logview/logview.php
—(As an aside, please ensure you understand the point of the functions in formdata.inc.php; check out the comments in the script and the wiki developer policies page)
—It works, but getting “File does not exist: /var/www/html/library, referer:…” whenever clicking on any links in this page. (can be dealt with after you commit current code to SF)

-brady

visolveemr wrote on Monday, March 08, 2010:

Hi Brady,

I’ve committed the audit patch to the sourceforge tracker and performed the following changes also:-
a. backup_log_dir options for windows users too
b. Modified the location of audit configurations in the globals.php

We are not facing the issue mentioned by you, ““File does not exist: /var/www/html/library, referer:…””. More details please?

Thanks
ViCarePlus Team
(www.vicareplus.com)

bradymiller wrote on Tuesday, March 09, 2010:

hey,

I committed two minor changes to globals.php:

First is just simple changes to make the OS specific settings more clear:
http://openemr.cvs.sourceforge.net/viewvc/openemr/openemr/interface/globals.php?r1=1.125&r2=1.126

Second is to not allow the backup log files to go to the php temp directory, since it’s meant to be a temporary directory, and seems insecure (the primary backup uses this because the backup file is deleted after it is uploaded to the user). Seems best to have user hard-code where they are saving these logs, so they know where they are:
http://openemr.cvs.sourceforge.net/viewvc/openemr/openemr/interface/globals.php?r1=1.126&r2=1.127

Seemed like simple changes, so committed them now. Let me know if any problems with this.

Regarding the “File does not exist:” error. You’re likely masking it on your server if your interface/globals.php ‘web_root’ variable is blank. Check out the cvs demo here (there is also a link to the php error file here), where you will note an error in the log if click on any buttons/links in the administration->log screen:
http://www.openmedsoftware.org/wiki/Development_Demo

-brady

bradymiller wrote on Thursday, March 11, 2010:

Visolveemr,
I think there is a potential bug lurking in your code somewhere, check out the tracker artifact:
https://sourceforge.net/tracker/index.php?func=detail&aid=2968409&group_id=60081&atid=493001#
Let me know your thoughts?
-brady

visolveemr wrote on Thursday, March 11, 2010:

Hi Brady,

Currently we are troubleshooting this. Will keep you posted.

Thanks
ViCarePlus Team

bradymiller wrote on Friday, March 12, 2010:

Visolveemr,

Please make this a high priority. This appears to be a global error affecting many things that involve counters making the current cvs codebase broken.

thanks,
-brady

visolveemr wrote on Friday, March 12, 2010:

Hi Brady,

We are working on this and resolving this is our HIGHEST priority now.

ISSUE
This issue happens because the function “LAST_INSERT_ID” is used across the openemr codebase for determining ids like encounter ids, form ids, drug ids etc.

This function “LAST_INSERT_ID” returns the last automatically generated value that was inserted into an AUTO_INCREMENT column irrespective of any table.

Suppose if the log table gets incremented (it has an autoincrement column)  to 905 prior to calling this function, it returns 905.

In openemr code, we found that few of the table ids are based on the LAST_INSERT_ID.

Since currently we are monitoring the database calls  (through audit)  and “log” table has an auto increment column,  the value returned by the “LAST_INSERT_ID” is affected by the log entries.

This causes the wrong insertion of certain ids like form-ids, encounter-ids etc.

SOLUTION
Quick solution - to make the auditing disabled by default in the CVS till we come with the work around.
$GLOBALS=0;

Currently analyzing on -
a. Alternate option for auto increment column so that the LAST_INSERT_ID function will not be affected by the log entries

Do share your views here.

Thanks
ViCarePlus Team