5.3.0-git
2014-11-21

[#7829] Improve / standarize / clean up log messages
Summary Improve / standarize / clean up log messages
Queue Horde Base
Queue Version HEAD
Type Enhancement
State Accepted
Priority 1. Low
Owners
Requester thomas (at) gelf (dot) net
Created 2009-01-07 (2144 days ago)
Due
Updated 2009-02-05 (2115 days ago)
Assigned
Resolved
Milestone
Patch No

History
2009-02-05 14:01:49 Duck Comment #9 Reply to this comment
It will be useful to log even the host name for vhost installations.
2009-02-01 18:33:52 Chuck Hagenbuch State ⇒ Accepted
 
2009-01-21 22:33:47 Chuck Hagenbuch Comment #8 Reply to this comment
What's your opinion regarding my "log line format coding
standard"-suggestion?
I haven't really had a chance to think about it. Something like that 
seems reasonable, but my prior statement about patches still applies. :)
2009-01-14 12:05:44 thomas (at) gelf (dot) net Comment #7 Reply to this comment
Sorry for my late reply, I've been really busy last days as we 
finished and released our beautiful great new DIMP-based Webmail ;-) I 
opened a new ticket 7845 with a patch for Horde's syslog handler some 
minute ago.



What's your opinion regarding my "log line format coding standard"-suggestion?



Regards,

Thomas
2009-01-12 01:45:23 Chuck Hagenbuch Comment #6
Version ⇒ HEAD
Queue ⇒ Horde Base
Reply to this comment
Let's start with feedback on what I already said; in general, patches 
are going to make you much more persuasive than otherwise here.
2009-01-09 19:13:50 Chuck Hagenbuch Comment #5
State ⇒ Feedback
Reply to this comment
It's also great to see that Horde logger is going to look like ZF's
one! Will it be possible to configure multiple
observers/listeners/handlers with different filters in Horde's config
files? And to add other handlers at runtime / using hooks?
Sure.
I also had a quick look at Horde_Log_Handler_Syslog - if interested
you could add some improvements from my Zend_Log_Writer_Syslog
proposal:
http://framework.zend.com/wiki/display/ZFPROP/Zend_Log_Writer_Syslog+-+Thomas+Gelf
If you wanted to submit a patch that would be wonderful.
2009-01-07 19:32:49 thomas (at) gelf (dot) net Comment #4 Reply to this comment
One more comment:



IMP::loginLogMessage() is doing a great job for most tasks, however it 
is not handling all events I'm interested in ;-) What I noticed is 
that when using the _username_hook_frombackend-Hook, 
IMP::loginLogMessage() is logging the "wrong" username, it is using 
data from $_SESSION['imp']['user'] (Auth::getAuth() is showing the 
corrected one).



To be more precise, I'm applying String::lower() in my 
_username_hook_frombackend, and I'm also adding our main domain if no 
domain has been given. I agree that it would be interesting to also 
have the "original" username in my logs, but this could be an 
addition. If a User is logging in as Joe I would like to have
Login success for joe@mycompany.tld [1.2.3.4]...
or
Login success for joe@mycompany.tld (Joe) [1.2.3.4]...
but not just
Login success for Joe [1.2.3.4]...
to be written to my logs.


2009-01-07 19:06:27 thomas (at) gelf (dot) net Comment #3 Reply to this comment
Hmmm... After grepping around through Horde 4 code (GIT repository) I 
discovered that some mentioned issues are already going to be 
addressed there :-)



It's also great to see that Horde logger is going to look like ZF's 
one! Will it be possible to configure multiple 
observers/listeners/handlers with different filters in Horde's config 
files? And to add other handlers at runtime / using hooks?



I also had a quick look at Horde_Log_Handler_Syslog - if interested 
you could add some improvements from my Zend_Log_Writer_Syslog proposal:

http://framework.zend.com/wiki/display/ZFPROP/Zend_Log_Writer_Syslog+-+Thomas+Gelf

It is able to handle multiple parallel syslog handler instances with 
different facilities and ident's and currently to be found in ZF's 
Standard Incubator (class skeleton on the proposal's site could be 
outdated).



Btw: PHP docs are not correct (I gave a quick look at PHP's source 
code), syslog, openlog and closelog will never fail and return 
"false", even if you completely remove your log device.



Cheers,

Thomas


2009-01-07 18:40:43 thomas (at) gelf (dot) net Comment #2 Reply to this comment
(please change ticket version to "HEAD")
2009-01-07 18:28:30 thomas (at) gelf (dot) net Comment #1
State ⇒ New
Patch ⇒ No
Milestone ⇒
Queue ⇒ Horde Groupware Webmail Edition
Summary ⇒ Improve / standarize / clean up log messages
Type ⇒ Enhancement
Priority ⇒ 1. Low
Reply to this comment
Scenario

--------

Most of "my" servers / applications are logging to syslog, and syslog 
is sent to central log servers. All logs are then going to be being 
parsed / aggregated / archieved / rotated / whatever. This work is 
done either by generic or personalized log parsers and log aggregation 
daemons.



I'm going to put our beautiful new (D)IMP-based webmail into 
production next week, and right now one of my open tasks is adding 
Horde/IMP support to our log environment. Doing so I discovered that 
this is a "not-so-funny"-task.



Problem description

-------------------

Main problems when trying to parse Horde log lines are:

- localized / translated log lines

- log lines completely missing essential information like client ip 
and username



Examples

--------

The following are unsorted examples to give you some idea what I'm 
trying to talk about:

- on line 748 of imp/lib/Compose.php: 'Failed to add recipient: ...' 
-> no username, no ip

- on line 195 of imp/lib/IMAP/Cache.php: '[CLOSED] IMAP connection 
broken...' -> IDEM

- on line 67 of imp/login.php: '1.2.3.4 Ihre Webmail-Session ist 
abgelaufen...' -> should not be German

- on line 67 of imp/login.php: '1.2.3.4 Ihre Internetadresse hat sich 
geƤndert...' -> IDEM, and: if logout occurs because of a changed IP, 
there should be mentioned 'old ip', 'new ip' and 'username'



Solution

--------

The reason for string translation in login.php is that the "logout 
reason" string is going to be passed as an URL parameter for usage as 
notification and also log string. Logging should not occur here, it 
should happen where the problem got detected, before issueing the 
redirect.



I would suggest some "log line format coding standard", all Horde apps 
should wherever possible try to follow a common pattern. Some 
suggestions for such rules:



- Client IP MUST be logged whenever available

- Username MUST be logged whenever available

- Log entries MUST NOT be translated

- English log lines SHOULD NOT be changed between minor releases

- Log line components (ip, user, other values, text message) SHALL 
always use: your preferred  AVP-syntax (for example: key=val[, 
key="val ue"]...)



Horde 4 would be a great chance to introduce such changes, as changing 
log format in Horde 3.x is probably a not so good idea. Feedback is 
welcome!



Best regards,

Thomas Gelf



NB: As I've been unsure which queue to choose, I've chosen the one 
containing most components - please feel free to move this issue where 
it fits best in your believes ;-)