165589 - Add error logging support to Bugzilla

Status: RESOLVED FIXED

(Bugzilla :: Bugzilla-General, enhancement, P2)

Description

[Joel Peshkin]

Bugzilla needs a capability to log "stuff" to either a local file or,
selectably, to a (potentially remote) syslog.

Items of interest....
errors (with all the variables, etc... that caused them)
access violations (with the IP and user info)
mid-air collisions with the info on both changes and what was eventually done

This is for 2 purposes...

1) hack attempt detection (use syslog in case the hack is successfull)
2) responding to user complaints that some change did not "take"

Comment 1

[Joel Peshkin]

Attachment: Rough initial (working) patch, feedback needed

I am attaching the initial patch for feedback.	It works, and logs the entire
environement and $vars to STDERR (normally to the webserver's error log) for
every UserError, CodeError, or TemplateError.

This is really handy information to be able to go over, but I am looking for
suggestions on the following....

1) How should it be formatted, should each LINE of the output be preceeded by
something? (like they type of error and a timestamp?)

2) Should there be any option on WHERE the information is sent?

3) Should this be configurable?  If so, at what granularity?  

4) Should there be a way to get the same information for successfull pages?

Please comment in the bug

Comment 2

[Joel Peshkin]

assigning to me

Comment 3

[Bradley Baetz (:bbaetz)]

This should really be tied into the Bugzilla::Exception stuff that I posted to
the devel list a while back. Don't think I filed a bug on it, though.

It doesn't have to be dependent on that (since it is quite a bit of work), but
if you want to catch generic |die| too...

Comment 4

[Joel Peshkin]

OK... having put this on a site that uses Apache2, STDERR is definitely the
wrong place.

data/errorlog or some combiantion of data/usererrorlog data/codeerrorlog and
data/templateerrorlog might be the right thing. 

Comments?

Comment 5

[Joel Peshkin]

Attachment: Revised patch uses data/errorlog

OK.. this patch now uses data/errorlog in a manner similar to data.sqllog

Comment 6

[J. Paul Reed [:preed]]

Some general thoughts (hey, you asked for 'em ;-)

I don't think syslog is the right place for this, but using a mechanism similar
to syslog (i.e. with differing levels of logging and possibly configurable
output locations) would be good, I think.

I don't like using STDERR because sometimes, you won't have read access to the
error_log (not a big deal), but on a busy site, you might have to sift through a
*lot* of irrelevant error_log to find what they're looking for.

For a pretty complex webapp I have, my logging function logs the date/time (just
a scalar(localtime())), followed by the full listing of CGI.pm's %in hash, plus
whatever message I wanted to log.

Logging the full CGI environment might also be something you could add as an
option, or turn on at higher logging levels.

I haven't looked at the patch (stupid school), so a lot of this may now be
irrelevant...

Comment 7

[Joel Peshkin]

I've been using this patch for a while now and it does seem a bit hard to
quickly scan the log.  Essentially, differrent types of errors need differrent
information to tell if they are an indication of trouble.

I'm considering adding a short summary line that can be grepped for easily. 
Anyone have any good ideas?

Perhaps combining the login, error, and IP on one line.

Comment 8

[Joel Peshkin]

Attachment: Revised patch

Comment 9

[Joel Peshkin]

Attachment: oops - this one

corrected formatting error

Comment 10

[Joel Peshkin]

Attachment: revised... keep it simple and write to the file as atomically as practical

Comment 11

[Jouni Heikniemi]

Comment on attachment 153736 [details] [diff] [review]
revised... keep it simple and write to the file as atomically as practical

Some questions... My problem here is that I'm not certain I understand what are
the circumstances this could be used for. Although I can figure out _some_
situations for this, the rough configurability and lack of filtering makes this
a bit clumsy for everyday use. No judgement in the form of r[+-] before I
understand ;-)

>+    # If a writable data/errorlog exists, log error details there.
>+    if (-w "data/errorlog") {

What's the point here? The user has to manually create the errorlog file if
he/she wants it used? Should we have more configurability here? (the path of
the errorlog as a Param comes to mind - that way we could also create the file
if it doesn't exist)

This log is going to be massively verbose (since stuff like typoed keywords
etc. are going to be logged) on big installations like bmo; how could this be
used for hack attempt detection in that sort of environment? Logging
ThrowUserErrors and ThrowCodeErrors are two entirely different things; should
we differentiate between those?

>+        $mesg .= Bugzilla->user->login  if Bugzilla->user;

Nit: Extra space before if.

>+            $val = "*****" if $param =~ /password/i;

Note that if you're using http basic authentication, the http_pass ENV variable
will contain the user's password (on many platforms). Mask that, too.

Comment 12

[Christian Reis]

[On Params and kittens]
I think a Param is certainly overkill, but I also think we should create the
errorlog as a default. Having it configurable makes debugging someone's
installation that much harder ("find out what your errorlog param is" is one
level of indirection into data/params if Bugzilla's busted) without giving any
extra benefit I see (that symbolic links don't provide already).

[Anyway]
I do think that it would be interesting to have something to separate entries in
this file so you can tell easily (visually) where an error starts or where it ends.

Joel, any chance you could attach the output produced by this over a couple of
errors (I just *know* you've got errors lying around on your tree <wink>) so we
could approve the formatting?

Comment 13

[Joel Peshkin]

Attachment: Example data/errorlog

Here's a controved example.

I am not fond of using the params approach or of enabling it by default because
anybody using this will need to occasionally inspect the files and rotate or
purge them.  Since those are shell operations, it seems prudent to follow the
model of the old sqllog and use the file's existance as the key.

I lived with a variation of this for the past two years that just dumped out
all the variables as a big hash.  Inspecting those files was a bit of a pain. 
In this format, we can easily grep for error.html and see a quick summary or
parse the whole thing easily.

(Once we settle the design issues, I can easily increase the list of obscured
names to address the webserver PASS variables.)

Comment 14

[Jouni Heikniemi]

Comment on attachment 153736 [details] [diff] [review]
revised... keep it simple and write to the file as atomically as practical

Kiko: symlinks are not a solution on Win32 (unless you junction the data
directory as a whole, but nobody knows how to use junctions)

Anyway, I'm fine with the explanations given. Let's enhance this if necessary.
Joel, fix the following:

1. Fix the spacing nit in comment 11
2. Mask HTTP_PASS and AUTH_PASSWORD variables from the ENV
3. Add the separator Kiko was talking about (something like '-'x75 will do just
fine)

I think it's going to be just fine then, but let's see yet another round.

Comment 15

[Joel Peshkin]

Attachment: revised -- make you goys happy

Comment 16

[Jouni Heikniemi]

Comment on attachment 153814 [details] [diff] [review]
revised -- make you goys happy

>+        for (1..75) { $mesg .= "-"; };

Hey, I meant it when I said '-'x75 ;-)

|$mesg .= '-' x 75| is a bit more beautiful way to do it...

r=jouni with that fixed.

Comment 17

[Joel Peshkin]

checked in

Comment 18

[A. Karl Kornel]

Attachment: Patch v1

Adds a paragraph on to the end of the General Advice portion of the
Troubleshooting appendix.

Requesting review from documentation@.

Comment 19

[Colin Ogilvie [:cso]]

Comment on attachment 189242 [details] [diff] [review]
Patch v1

>Index: troubleshooting.xml
>+    <para>
>+      Bugzilla can also be told to log all user and code errors that occur, but
>+      do not generate entries in the web server error log.

This sentence doesn't make much sense to me. I know what you're trying to say
but it just doesn't seem to make sense... Other than that, it looks fine.

Comment 20

[A. Karl Kornel]

Attachment: Docs Patch v1.5

Modification of attachment 189242 [details] [diff] [review], taking into account comment 19.  The first
sentence has been reworked.  I also changed a mean-looking ", and," to use
(gasp!) a semicolon!  Requesting review from documentation@.

(In reply to comment #19)
> (From update of attachment 189242 [details] [diff] [review] [edit])
> >Index: troubleshooting.xml
> >+	<para>
> >+	  Bugzilla can also be told to log all user and code errors that occur,
but
> >+	  do not generate entries in the web server error log.
> 
> This sentence doesn't make much sense to me. I know what you're trying to say

> but it just doesn't seem to make sense... Other than that, it looks fine.

Comment 21

[Colin Ogilvie [:cso]]

Comment on attachment 191931 [details] [diff] [review]
Docs Patch v1.5

What vversion of Bugzilla does this apply to?

Comment 22

[A. Karl Kornel]

Colin: It was a while ago... I believe it was originally for 2.20, but it
applies to both 2.20 and tip.

Comment 23

[Colin Ogilvie [:cso]]

Comment on attachment 191931 [details] [diff] [review]
Docs Patch v1.5

r=colin.ogilvie

Comment 24

[Colin Ogilvie [:cso]]

Docs bit checked in...

2.20:

Checking in docs/xml/troubleshooting.xml;
/cvsroot/mozilla/webtools/bugzilla/docs/xml/troubleshooting.xml,v  <-- 
troubleshooting.xml
new revision: 1.5.4.1; previous revision: 1.5
done

Trunk:

Checking in docs/xml/troubleshooting.xml;
/cvsroot/mozilla/webtools/bugzilla/docs/xml/troubleshooting.xml,v  <-- 
troubleshooting.xml
new revision: 1.6; previous revision: 1.5
done