6.0.0-beta1
8/12/25

[#12109] Log priority not honored when logging messages from ActiveSync
Summary Log priority not honored when logging messages from ActiveSync
Queue Horde Base
Queue Version 5.0.4
Type Bug
State Resolved
Priority 1. Low
Owners slusarz (at) horde (dot) org
Requester arjen+horde (at) de-korte (dot) org
Created 03/12/2013 (4536 days ago)
Due
Updated 03/12/2013 (4536 days ago)
Assigned 03/12/2013 (4536 days ago)
Resolved 03/12/2013 (4536 days ago)
Github Issue Link
Github Pull Request
Milestone
Patch No

History
03/12/2013 07:52:01 PM Michael Slusarz Taken from Michael Rubinsky
State ⇒ Resolved
 
03/12/2013 07:51:41 PM Git Commit Comment #9 Reply to this comment
Changes have been made in Git (master):

commit 2de95f9a8d3374d495a5548ac4da75f77b9b77a2
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Tue Mar 12 13:50:41 2013 -0600

     Bug #12109: Workaround broken log priority in Horde <= 5.0.5

  framework/Core/lib/Horde/Core/Factory/Logger.php |   14 +++++++++++---
  1 files changed, 11 insertions(+), 3 deletions(-)

http://git.horde.org/horde-git/-/commit/2de95f9a8d3374d495a5548ac4da75f77b9b77a2
03/12/2013 07:51:34 PM Git Commit Comment #8 Reply to this comment
Changes have been made in Git (master):

commit 106e284ef212338d6a4a8f25f0162d91b597b20a
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Tue Mar 12 13:48:28 2013 -0600

     Bug #12109: Fix log level for WARN

  horde/config/conf.xml |    2 +-
  1 files changed, 1 insertions(+), 1 deletions(-)

http://git.horde.org/horde-git/-/commit/106e284ef212338d6a4a8f25f0162d91b597b20a
03/12/2013 07:47:55 PM Michael Slusarz Comment #7 Reply to this comment
I configured logging for level WARNING:

    $conf['log']['priority'] = 'WARNING';
The problem is that there is no 'WARNING' level in Horde_Log.  It is 
'WARN'.  And I can verify that setting the log level to 'WARN" won't 
show 'NOTICE' messages.
03/12/2013 01:38:26 PM arjen+horde (at) de-korte (dot) org Comment #6 Reply to this comment
Also, I just verified this does NOT just happen with ActiveSync/RPC 
requests. I can duplicate this by logging in and out of horde via 
the UI.
I use PAM for authentication to Horde. Could it be that the 
connections IMP (once logged in) makes to the IMAP service do honor 
the $conf['log']['priority'] setting? In that case, I might have 
missed them, since I specifically grep'ped for IMAP related logs and 
wasn't looking for PAM related. In that case I would probably see that 
the initial authentication would also log a message, right?
03/12/2013 01:14:18 PM Michael Rubinsky Comment #5 Reply to this comment
Also, I just verified this does NOT just happen with ActiveSync/RPC 
requests. I can duplicate this by logging in and out of horde via the 
UI.
03/12/2013 01:08:51 PM Michael Rubinsky Comment #4 Reply to this comment
The behaviour is as expected when downgrading to Horde_Core-2.4.1 
and seems to be limited to the above messages only (other log 
messages do seem to honor the priority).
FWIW, prior to 2.4.2, logging was broken for ActiveSync. So while it 
looks like it was "as expected" in reality the reason it wasn't 
logging those messages is because activesync (as well as any RPC 
request) was logging NO message at all other than the messages it was 
logging to it's synclog if it was so configured. ActiveSync code 
doesn't touch the global horde logger at all.
03/12/2013 10:37:08 AM Jan Schneider Summary ⇒ Log priority not honored when logging messages from ActiveSync
Assigned to Michael Slusarz
Assigned to Michael Rubinsky
State ⇒ Assigned
 
03/12/2013 10:19:49 AM arjen+horde (at) de-korte (dot) org Comment #3 Reply to this comment
Does the ticket subject imply that this doesn't happen if you 
configure a different logging backend?
It also happens when logging to file, but I wasn't 100% certain that 
the same priority mechanism is used for 'file' too. Since I changed 
logging to 'syslog' well before the upgrade to Horde_Core-2.4.2 (or 
higher) I'm not sure if these messages were suppressed then.

I did prepended the $priority to $event in the log function in 
/usr/share/php5/PEAR/Horde.php, which indicated that these messages 
are indeed logged with priority 'NOTICE', which lead me to believe 
this has probably the same rootcause as 
http://bugs.horde.org/ticket/12103. It does look like messages below 
the configured level in $conf['log']['priority'] are suppressed (as 
expected) most of the time. I never see these messages when using IMP, 
only when using ActiveSync, these are logged every time a client 
connects.
03/12/2013 10:04:54 AM Jan Schneider Comment #2
State ⇒ Feedback
Reply to this comment
Does the ticket subject imply that this doesn't happen if you 
configure a different logging backend?
03/12/2013 09:09:41 AM arjen+horde (at) de-korte (dot) org Comment #1
Priority ⇒ 1. Low
Type ⇒ Bug
Summary ⇒ Log priority not honored when logging messages to syslog
Queue ⇒ Horde Base
Milestone ⇒
Patch ⇒ No
State ⇒ Unconfirmed
Reply to this comment
Even with Horde_Core-2.4.3, the problem in some PHP installations is
not fixed completely. Although the Addressbook now opens fine from the
Horde portal, there still is an issue with messages that are being
logged incorrectly.

Since the upgrade to Horde_Core-2.4.2, Horde is spamming my syslog
with messages like

Mar 10 21:30:10 mail horde: [imp] Login success for arjen (Horde user
arjen) [192.168.1.126] to {localhost:143 [imap]} [pid 3574 on line 183
of "/srv/www/htdocs/horde/imp/lib/Auth.php"]

The above is from an ActiveSync client by the way and coincides with
PING and SYNC messages in the webserver log.

I configured logging for level WARNING:

    $conf['log']['priority'] = 'WARNING';
    $conf['log']['ident'] = 'horde';
    $conf['log']['name'] = LOG_LOCAL7;
    $conf['log']['type'] = 'syslog';
    $conf['log']['enabled'] = true;

This message is logged with priority 'NOTICE' (I checked that), which
is lower than the 'WARNING' threshold, so these messages should never
have made it to the syslog.

The behaviour is as expected when downgrading to Horde_Core-2.4.1 and 
seems to be limited to the above messages only (other log messages do 
seem to honor the priority).

Saved Queries