6.0.0-beta1
8/28/25

[#10773] Improve logging in Horde_Db
Summary Improve logging in Horde_Db
Queue Horde Framework Packages
Queue Version Git master
Type Enhancement
State Resolved
Priority 1. Low
Owners mrubinsk (at) horde (dot) org
Requester slusarz (at) horde (dot) org
Created 11/17/2011 (5033 days ago)
Due
Updated 02/02/2017 (3129 days ago)
Assigned 12/16/2011 (5004 days ago)
Resolved 02/02/2017 (3129 days ago)
Milestone
Patch No

History
02/02/2017 04:08:51 PM Michael Rubinsky Assigned to Michael Rubinsky
State ⇒ Resolved
 
02/02/2017 04:06:04 PM Git Commit Comment #6 Reply to this comment
Changes have been made in Git (master):

commit 5021b913bf85d28af9caa5fceab999e0c27f4eaf
Author: Michael J Rubinsky <mrubinsk@horde.org>
Date:   Thu Feb 2 10:58:16 2017 -0500

     Ticket: 10773 Improve Horde_Db logging options.

       * Ability to switch on/off query logging
       * Never log Horde_Db_Value_Binary or stream resource data.

  framework/Db/lib/Horde/Db/Adapter/Base.php     | 50 
++++++++++++++++++++------
  framework/Db/lib/Horde/Db/Adapter/Mysql.php    | 16 +++++----
  framework/Db/lib/Horde/Db/Adapter/Mysqli.php   | 16 +++++----
  framework/Db/lib/Horde/Db/Adapter/Oci8.php     | 14 ++++----
  framework/Db/lib/Horde/Db/Adapter/Pdo/Base.php | 22 ++++++------
  5 files changed, 77 insertions(+), 41 deletions(-)

http://github.com/horde/horde/commit/5021b913bf85d28af9caa5fceab999e0c27f4eaf
08/27/2013 11:27:07 AM Jan Schneider Summary ⇒ Improve logging in Horde_Db
 
08/27/2013 11:26:47 AM Jan Schneider Priority ⇒ 1. Low
State ⇒ Accepted
Type ⇒ Enhancement
 
12/16/2011 10:56:28 AM Jan Schneider Comment #5 Reply to this comment

[Show Quoted Text - 10 lines]
Agreed.
2. Logging as <Stream> now prevents us from EVER debugging the 
contents of the data values.  Just because it is a stream doesn't 
mean we shouldn't log it (a stream could contain 1 byte of data).
AFAIU request 10805, streams would only be used for binary data, 
because this is where we expect the largest byte streams. And logging 
those wouldn't make sense.

[Show Quoted Text - 10 lines]
This sounds to me like overcomplicating things. I suggest we only:
- add the option to disable query logging in Horde_Db
- enable this option in the factory when using DEBUG logging
- don't log Horde_Db_Value_Binary
- don't log streams when we implement this in the future
12/16/2011 05:59:40 AM Michael Slusarz Comment #4 Reply to this comment
I think the solution here is to implement Request 10805, and then 
when logging queries, log Stream resources as <Stream> rather than 
their contents. Any objections?
Unfortunately, I don't think that solves this issue.  Two major 
problems jump out to me:

1. Someone can still pass in a multi-MB string.  It is perfectly 
valid. and will always remain valid, according to the API.  This 
solution maintains the status quo on this case.
2. Logging as <Stream> now prevents us from EVER debugging the 
contents of the data values.  Just because it is a stream doesn't mean 
we shouldn't log it (a stream could contain 1 byte of data).

I still believe the solution needs to be a way of controlling the log 
level at the DB package level, as opposed to the Log package level.   
E.g. an option that can be passed to the Db library that allows three 
levels of data logging:

* ALL: Log all entries
* MAX_SIZE: Log all entries smaller than a certain size (1KB? 
configurable?; use placeholders (e.g. "<Stream>", "<String>") otherwise
* NEVER: Never log entries; always use placeholders
12/16/2011 05:21:19 AM Chuck Hagenbuch Comment #3
State ⇒ Feedback
Reply to this comment
I think the solution here is to implement Request 10805, and then when 
logging queries, log Stream resources as <Stream> rather than their 
contents. Any objections?
11/17/2011 06:05:07 AM Michael Slusarz Comment #2 Reply to this comment
Resolving Ticket #10774 has helped alleviate this some, by reducing 
the query size on PostgreSQL installations.
11/17/2011 05:21:44 AM Michael Slusarz Comment #1
Priority ⇒ 3. High
Type ⇒ Bug
Summary ⇒ Crippling Memory Usage for certain Log entries
Queue ⇒ Horde Framework Packages
Milestone ⇒
Patch ⇒ No
State ⇒ Unconfirmed
Reply to this comment
Due to the design of the Log class, we ALWAYS generate the log message 
and send it to the Log class, even if the log level means it will 
never be output to any handler.

However, this is crippling in the case of large log outputs.  Not only 
do we need to allocate memory for the string itself, but the memory 
needs are at a minimum doubled since we generate a debug_backtrace() 
in the Horde Core log handler, and this debug_backtrace will include 
the entire contents of the log message.

My example: attaching a 2 MB file to an email message is taking 
upwards of 80+ MB /regardless/ of the Log setting.  Totally disabling 
logging in the DB library lowers the memory usage to around 50 MB.   
This 30 MB difference is because the DB logger is logging the ENTIRE 
query string sent to the server.  In my case, because I am using 
postgres, the data string size is quadrupled due to bytea escaping so 
the log message is 9MB.

Even for DEBUG logging, this is ridiculous.  And for those not using 
debug logging, they have to pay this penalty for no reasons.  Several 
thoughts:

1) A way to pre-query the logger to see if we should even go through 
the trouble of creating a log message.  Useful in cases where log 
message generation is potentially expensive.
2) Remove query logging in Db library, even for DEBUG level.  Add 
parameter to specifically request full query logging.

Saved Queries