SA Bugzilla – Bug 393
Add date and cross reference (msgid) to -D (debug output)
Last modified: 2002-06-11 15:48:53 UTC
Make the -D (debug) output more usefull by datestamping and grabbing the msgid from the message at hand. Hopefully this would facilitate going through log output with a msgid in hand to see how spammassasin reported that message.
You're in luck, I should propose a patch tonight that does this and more
I agree on msgid, disagree on timestamp. I think better would be to change spamd to intercept warn() with a #SIG{__WARN__} handler and redirect Mail::SpamAssassin::dbg() calls to syslog which will then provide the date/time stamp.
I disagree with: Craigs comment - "I think better would be to change spamd to intercept warn() with a #SIG{__WARN__} handler and redirect Mail::SpamAssassin::dbg() calls to syslog which will then provide the date/time stamp." Yes, if it goes to syslog then no need of timestamp, but one of the beauties spamd is that by leaving out the -d (daemonize) and using -D debug, the output can be redirected in any normal shell rule sort of way. Always nice to have a `clean' log and not involve syslog if so desired. Especially when involved in heavy debugging. So, I guess the best would be to have no timestamp on syslog redirect but to allow time stamping at user request (an additional (-t?) flag, that is inactive if -d is engaged.
Subject: Re: [SAdev] Add date and cross reference (msgid) to -D (debug output) bugzilla-daemon@hughes-family.org wrote: > http://www.hughes-family.org/bugzilla/show_bug.cgi?id=393 > > > > > > ------- Additional Comments From reader@newsguy.com 2002-06-05 06:44 ------- > I disagree with: > Craigs comment - "I think better would be to change spamd to intercept > warn() with a #SIG{__WARN__} handler and redirect Mail::SpamAssassin::dbg() > calls to syslog which will then provide the date/time stamp." > > Yes, if it goes to syslog then no need of timestamp, but one of the beauties > spamd is that by leaving out the -d (daemonize) and using -D debug, the output > can be redirected in any normal shell rule sort of way. Always nice to have a > `clean' log and not involve syslog if so desired. Especially when involved in > heavy debugging. > So, I guess the best would be to have no timestamp on syslog redirect but to > allow time stamping at user request (an additional (-t?) flag, that is inactive > if -d is engaged. Personally I think we should use Log::Dispatch::Config (and use LDC's alternate config system to pick up the config from SpamAssassin config files). It's incredibly flexible in it's logging, and I can attest to it's reliability. Matt.
Subject: Re: [SAdev] Add date and cross reference (msgid) to -D (debug output) bugzilla-daemon@hughes-family.org wrote: > http://www.hughes-family.org/bugzilla/show_bug.cgi?id=393 > > > > > > ------- Additional Comments From reader@newsguy.com 2002-06-05 06:44 ------- > I disagree with: > Craigs comment - "I think better would be to change spamd to intercept > warn() with a #SIG{__WARN__} handler and redirect Mail::SpamAssassin::dbg() > calls to syslog which will then provide the date/time stamp." > > Yes, if it goes to syslog then no need of timestamp, but one of the beauties > spamd is that by leaving out the -d (daemonize) and using -D debug, the output > can be redirected in any normal shell rule sort of way. Always nice to have a > `clean' log and not involve syslog if so desired. Especially when involved in > heavy debugging. > So, I guess the best would be to have no timestamp on syslog redirect but to > allow time stamping at user request (an additional (-t?) flag, that is inactive > if -d is engaged. Personally I think we should use Log::Dispatch::Config (and use LDC's alternate config system to pick up the config from SpamAssassin config files). It's incredibly flexible in it's logging, and I can attest to it's reliability. Matt. _______________________________________________________________ Don't miss the 2002 Sprint PCS Application Developer's Conference August 25-28 in Las Vegas -- http://devcon.sprintpcs.com/adp/index.cfm _______________________________________________ Spamassassin-devel mailing list Spamassassin-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/spamassassin-devel
Checked in a $SIG{__WARN__} handler one-liner for spamd. Leaving this bug open pending me taking a look at Log::Dispatch::Config
I actually realized after adding the WARN handler that syslog only give second-level time resolution, so I think using the timestamp stuff that was in that massive 4-thing patch submitted yesterday on bug #399 might be useful. I'll see about making use of that.
Ok, so bug #399 is now done. *** This bug has been marked as a duplicate of 399 ***
Subject: Re: Add date and cross reference (msgid) to -D (debug output) bugzilla-daemon@hughes-family.org writes: > http://www.hughes-family.org/bugzilla/show_bug.cgi?id=393 > > craig@hughes-family.org changed: > > What |Removed |Added > ---------------------------------------------------------------------------- > Status|NEW |RESOLVED > Resolution| |DUPLICATE > > > > ------- Additional Comments From craig@hughes-family.org 2002-06-10 03:25 ------- > Ok, so bug #399 is now done. > > *** This bug has been marked as a duplicate of 399 *** > Sorry Folks but the confusing setup at bugzilla wouldn't allow me to insert this further comment. I inserted `393 in a query and then tried to insert comments in the comments box. It gives an error: Only the owner or submitter of the bug, or a sufficiently empowered user, may make that change to the short_desc field. Old value: Fixed RBLs / RBL timeouts / Time logging / Debug framework New value: Fixed RBLs / RBL timeouts / Time logging/ Debug framework Somewhat confusing since I made no attempt to change anything and the alleged change is not a change at all anyway. My further comment is: As the originator of bug 393, I wasn't able to tell what 399 is supposed to do from reading the 399 chain of events and description. Will the message id of a processed message now be part of the DEBUG output? Will debug output (outside of syslog) have a time stamp?
Subject: Re: [SAdev] Re: Add date and cross reference (msgid) to -D (debug output) Yes, 399 is a full superset of 393, so MsgID and timestamp are now logged, if you use the -D flag to either spamd or spamassasin, or if you instantiate the scanner object with 'debug' => 1
Ok, now that my patch has been included (I wasn't sure if all of it would be, or what modifications would be applied), I can offer a bit more info: Technically this is a different request than what I did in 399. My timelog function allows you to log the major functions of SA and see how long they took. This all gets saved to a file that contains the message-ID of the message that was processed. However, my patch does not redirect dbg calls to send them to timelog. That said, if you feel you want to run SA in dbg mode and production, you could trivially edit one line in the dbg function and send the prints from dbg to the timelog function. It will also conveniently save the dbg info to a different file for each incoming message. We *could* make this an option if Craig and others think it might be useful to others, or you could simply edit your source to send the dbg print to timelog. Would that be good enough, or do you think SA should support this as an option that you can turn on from local.cf? I have to submit a small folloup patch on 399 for the cf files so that the rules can now take advantage of the new framework that was just introduced (Craig, I'll try to send a patch tonight. Bear with me, I just got laser eye surgery, so I'm not really supposed to be using a computer at all right now :)
Subject: Re: Add date and cross reference (msgid) to -D (debug output) bugzilla-daemon@hughes-family.org writes: > http://www.hughes-family.org/bugzilla/show_bug.cgi?id393 > ------- Additional Comments From craig@hughes-family.org 2002-06-11 09:41 ------- > Subject: Re: [SAdev] Re: Add date and cross reference (msgid) to > -D (debug output) > > Yes, 399 is a full superset of 393, so MsgID and timestamp are now logged, if > you use the -D flag to either spamd or spamassasin, or if you instantiate the > scanner object with 'debug' => 1 Using cvs of yesterday showing version 2.21 and running spamd like this: /usr/bin/spamd -D -L -S >> /var/log/spamd_debug.log 2>&1 & I see no indication of a timestamp or any record of a message-id in spamd_debug.log Several people have said that 399 includes 393, but I don't see the things that were presented in 393 bug report or its later discussion. I see no mention of a timestamp switch in the most recent man page. (That I have) Specifically: A switch to turn on timestamping for the above kind of redirect. Logging message-id as part of -D (debug) output Here is some example output of the above redirect: (wrapped for mail) [...] Possible unintended interpolation of @pop in string at (eval 20) line 503, <STDIN> line 77. Failed to run header SpamAssassin tests, skipping some: Global symbol "@pop" requires explicit package name at (eval 20) line 503, <STDIN> line 77. [...] I suspect this is related to local.cf entry I made: header From_Pop From =~ /@pop\./ describe From_pop From: header contains @pop\. in address score From_Pop 1.5 Maybe not, but I can't really tell much from the debug output. I've searched the debug output of several messages. They begin with something like: logmsg: connection from localhost [ 127.0.0.1 ] at port 42157 Then some 72 lines of ouput, ending with: logmsg: clean message (1.4/5.0) for reader:500 in 0 seconds, 3710 bytes. I'm probably blind, but I'll be damned if I can find a message-id anywhere in between. And as I mentioned that is with a cvs version of yesterday around noon. But just to make sure it isn't just that I haven't got the recent changes. Let me check out a version now and try it out..... cd /usr/local/src/spamassassin make distclean cvs update make make test (all tests passed) make install service spamassassin restart After retrieving several runs of mail I see no evidence in the log ouput of timestamping or message id.
You're not blind, the current CVS code does not add mesgid or a timestamp to debug messages, see my previous comment.