Patient Reminders and database logging

yehster wrote on Wednesday, December 14, 2011:

Something I realized is that for patient reminders, every time a reminder is generated, there is a log entry made. The log entry is just the insert statement with out any parameters.  They are all identical, so for folks with thousands of patients, the log will get filled with thousands of pretty useless entries in the log. (The log entries are like this…)
 

INSERT INTO `patient_reminders` (`pid`, `due_status`, `category`, `item`, `date_created`) VALUES (?, ?, ?, ?, NOW())

This isn’t the only thing affecting reminders performance, but it certainly doesn’t help.

My adodb changes could allow it so that we don’t log each individual insert, but maybe log the start of a run and the end of a run.

Make sense at all?
-Kevin Yeh
kevin.y@integralemr.com

bradymiller wrote on Wednesday, December 14, 2011:

Hi,
Another possibility is to make a category for this table in $tables array in library/log.inc and then give user the option turning it on/off in administration/globals/logging .
-brady

yehster wrote on Thursday, December 15, 2011:

Using the ExecuteNoLog, option would give the biggest performance increase.
You’d still be spending extra cycles checking the tables array in log.inc thousands of times. 
Even temporarily flipping “audit_log” off would use some extra computing power as the test to see if audit_log would happen every cycle.
Whether the performance impact with any of these options is real is something we’d just have to test.

bradymiller wrote on Friday, December 16, 2011:

Hi,
For practices that want full forensics in their log, I think useful to have at least the option of logging everything. My guess is that the table array check for each rule check is minimal relative to the hundreds of sql-queries. A poor man test would be to compare the time without logging, with standard logging, and with crazy logging (ie. enable log of SELECT statements).
-brady
www-open-emr.org

yehster wrote on Saturday, December 17, 2011:

I did another test, further disabling logging when generating patient reminders, and my runs of 8 patients, 1 reminder dropped further to 0.6 seconds from 1.3-1.5. 
Even when nothing gets written to the database, the sqlAuditEvent function does a lot of string processing trying to decide if it should write to begin with. 
-Kevin Yeh
kevin.y@integralemr.com

bradymiller wrote on Saturday, December 17, 2011:

wow,
That’s a pretty big performance hit. Are ‘Select’ statements also getting pulled into this code (since it is an option). Even if monitoring select statements is off (which is it by default) I wonder if this is still affecting performance of the other CDR stuff. May be useful to do a performance screen on the CDR reports (automated measures etc.) with and without audit on to assess this.
-brady

yehster wrote on Sunday, December 18, 2011:

My “worst performance” runs have been with default log settings.

Quick profiling of CQM.php
Logging enabled. 5.6 seconds, disabled 2.3 seconds, 8 patients…  Not as dramatic of impact, but certainly significant.

But other interesting data.
With logging on, calls to xl on my system are returning in ~1.5 milliseconds.  However, about 1 millisecond of that time is spent calling sqlAuditEvent.