You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@spamassassin.apache.org by Clunk Werclick <ma...@googlemail.com> on 2009/09/08 08:32:54 UTC

A silly logging question

This is probably a dumb question, but my looking through the docs is
just confusing me.

Can I get SpamAssassin to fully log what it is doing? The best I can
ever get is something like this;

Mon Aug  3 06:27:57 2009 [4290] info: logger: removing stderr method
Mon Aug  3 06:27:58 2009 [4292] info: spamd: server started on port
783/tcp (running version 3.2.5)
Mon Aug  3 06:27:58 2009 [4292] info: spamd: server pid: 4292
Mon Aug  3 06:27:58 2009 [4292] info: spamd: server successfully spawned
child process, pid 4293
Mon Aug  3 06:27:58 2009 [4292] info: spamd: server successfully spawned
child process, pid 4294
Mon Aug  3 06:27:58 2009 [4292] info: prefork: child states: SI
Mon Aug  3 06:27:58 2009 [4292] info: prefork: child states: II
Mon Aug  3 06:34:31 2009 [4292] info: spamd: server killed by SIGTERM,
shutting down


But never any actual information on the mail scanning process. The
problem, from my perspective, is I reject with a milter at the SMTP
stage - so I never get to see any blocked messages. I have a few in my
logs that Fetchmail has picked up from a pop account, before dumping
them into Postfix - and I have no Spamassassin log I can view to see
what they caught on and if I need to take any action.

I had a look at:
Mail::SpamAssassin::Logger - SpamAssassin logging module

But I'm not entirely sure how to invoke that or if I can get it to give
me what I need. It is very terse in information.

Perhaps I can start SA differently to produce a log of the scanning it
is doing? I'm sure this is a beginners question and I feel very stupid
having to ask - but I cannot find the obvious answer.

-- 
-----------------------------------------------------------
C Werclick



Re: A silly logging question

Posted by Karsten Bräckelmann <gu...@rudersport.de>.
> On Tue, 8 Sep 2009, Clunk Werclick wrote:
> > > On Tue, 8 Sep 2009, Clunk Werclick wrote:
> > > > I have it now - the only disappointment for me is it does not log the
> > > > 'to' or 'from' or client ip.

Blew away most of this thread already, before it started getting my
attention. Anyway, just checked archives, and there appears to be
something fishy that needs to be dealt with -- before we start barking
up the tree for custom logs.

The log snippet you did show us, and which you claimed is *all* you ever
got, is not what SA logs. Basically, it is "starting", "stopping" and
the prefork log messages.

Granted, you killed spamd just a few minutes after starting. But since
you said you never saw anything else, I'll go by that. This is, what SA
actually logs per message -- both.
  http://wiki.apache.org/spamassassin/SpamdSyslogFormat

Better?  There you got all rules hit. You're missing out on that.


> > Sadly, no. As Fetchmail is polling a remote POP3 server, the only part 
> > of the system to see *all* of the information, is Spamassassin. The MTA 
> > only sees 'localhost' from Fetchmail. Postfix parses out some 
> > information, but the client IP is missing. If I could change the way 
> > Spamassassin logs and what it logs, I would be - how do you put it - 
> > 'cooking on gas'.

In some other post you said, you want to log the last external hop.
Well, frankly, since you are feeding spamd (at least partially) from
fetchmail, it is not exactly SA's fault that your MTA doesn't know about
the last-external, handing-over client.

Now, there would be quite a lot of possibilities. Cause SA does know.

Since the last external IP and rDNS are available as templates (see the
Conf docs), it is trivial to have SA add them as a custom Last-External
header. However, you also said you Reject spam [1], so you don't deliver
these anywhere. Yet, you want the info.

If there is (or would be) procmail somewhere in that chain, which is
easy to do for the fetchmail chunk only, logging that specific header is
trivial. Along with other information.

Also, there's the possibility to either patch spamd to log more (see
above), or preferably, to hack a custom logging plugin. This of course
should have access to the metadata, and thus the last external hop.

However, as a pre-requisite, you need to sort out your logging. Again,
see the link above and compare to your actual logs. As long as you don't
get those, any solution *within* SA is a lost battle.

  guenther


[1] Something that's quite disturbing. You are not rejecting fetchmail
    fetched spam, are you? These have been accepted by the MX SMTP
    already. Hope you do not bounce that spam back to the *forged*
    sender...

-- 
char *t="\10pse\0r\0dtu\0.@ghno\x4e\xc8\x79\xf4\xab\x51\x8a\x10\xf4\xf4\xc4";
main(){ char h,m=h=*t++,*x=t+2*h,c,i,l=*x,s=0; for (i=0;i<l;i++){ i%8? c<<=1:
(c=*++x); c&128 && (s+=h); if (!(h>>=1)||!t[s+h]){ putchar(t[s]);h=m;s=0; }}}


Re: A silly logging question

Posted by John Hardin <jh...@impsec.org>.
On Tue, 8 Sep 2009, Clunk Werclick wrote:

> On Tue, 2009-09-08 at 09:34 -0700, John Hardin wrote:
>> On Tue, 8 Sep 2009, Clunk Werclick wrote:
>>
>>> I have it now - the only disappointment for me is it does not log the
>>> 'to' or 'from' or client ip.
>>
>> You may be able to determine that if you correlate more than one log. SA
>> logs the message-ID, and the MTA log should give you enough information to
>> determine the client IP address given the message-ID.
>
> Sadly, no. As Fetchmail is polling a remote POP3 server, the only part 
> of the system to see *all* of the information, is Spamassassin. The MTA 
> only sees 'localhost' from Fetchmail. Postfix parses out some 
> information, but the client IP is missing. If I could change the way 
> Spamassassin logs and what it logs, I would be - how do you put it - 
> 'cooking on gas'.

And I don't suppose you can get the logs from the MTA fetchmail is 
retrieving from.

Do you have your trust list set up to trust that MTA?

-- 
  John Hardin KA7OHZ                    http://www.impsec.org/~jhardin/
  jhardin@impsec.org    FALaholic #11174     pgpk -a jhardin@impsec.org
  key: 0xB8732E79 -- 2D8C 34F4 6411 F507 136C  AF76 D822 E6E6 B873 2E79
-----------------------------------------------------------------------
   It is criminal to teach a man not to defend himself when he is the
   constant victim of brutal attacks.              -- Malcolm X (1964)
-----------------------------------------------------------------------
  9 days until the 222nd anniversary of the signing of the U.S. Constitution

Re: A silly logging question

Posted by Clunk Werclick <ma...@googlemail.com>.
On Tue, 2009-09-08 at 09:34 -0700, John Hardin wrote:
> On Tue, 8 Sep 2009, Clunk Werclick wrote:
> 
> > I have it now - the only disappointment for me is it does not log the
> > 'to' or 'from' or client ip.
> 
> You may be able to determine that if you correlate more than one log. SA 
> logs the message-ID, and the MTA log should give you enough information to 
> determine the client IP address given the message-ID.
Sadly, no. As Fetchmail is polling a remote POP3 server, the only part
of the system to see *all* of the information, is Spamassassin. The MTA
only sees 'localhost' from Fetchmail. Postfix parses out some
information, but the client IP is missing. If I could change the way
Spamassassin logs and what it logs, I would be - how do you put it -
'cooking on gas'.

-- 
-----------------------------------------------------------
C Werclick .Lot
Technical incompetent
Loyal Order Of The Teapot.

This e-mail and its attachments is intended only to be used as an e-mail
and an attachment. Any use of it for other purposes other than as an
e-mail and an attachment will not be covered by any warranty that may or
may not form part of this e-mail and attachment. 




Re: A silly logging question

Posted by John Hardin <jh...@impsec.org>.
On Tue, 8 Sep 2009, Clunk Werclick wrote:

> I have it now - the only disappointment for me is it does not log the
> 'to' or 'from' or client ip.

You may be able to determine that if you correlate more than one log. SA 
logs the message-ID, and the MTA log should give you enough information to 
determine the client IP address given the message-ID.

-- 
  John Hardin KA7OHZ                    http://www.impsec.org/~jhardin/
  jhardin@impsec.org    FALaholic #11174     pgpk -a jhardin@impsec.org
  key: 0xB8732E79 -- 2D8C 34F4 6411 F507 136C  AF76 D822 E6E6 B873 2E79
-----------------------------------------------------------------------
   Homeland Security: Specializing in Tactical Band-aids for Strategic
   Problems.                       -- Eric K. in Bruce Schneier's blog
-----------------------------------------------------------------------
  9 days until the 222nd anniversary of the signing of the U.S. Constitution

Re: A silly logging question

Posted by Clunk Werclick <ma...@googlemail.com>.
On Tue, 2009-09-08 at 09:08 -0700, John Hardin wrote:
> On Tue, 8 Sep 2009, Clunk Werclick wrote:
> 
> > Can I get SpamAssassin to fully log what it is doing? The best I can
> > ever get is something like this;
> >
> > Mon Aug  3 06:27:57 2009 [4290] info: logger: removing stderr method
> > Mon Aug  3 06:27:58 2009 [4292] info: spamd: server started on port
> > 783/tcp (running version 3.2.5)
> > Mon Aug  3 06:27:58 2009 [4292] info: spamd: server pid: 4292
> > Mon Aug  3 06:27:58 2009 [4292] info: spamd: server successfully spawned
> > child process, pid 4293
> > Mon Aug  3 06:27:58 2009 [4292] info: spamd: server successfully spawned
> > child process, pid 4294
> > Mon Aug  3 06:27:58 2009 [4292] info: prefork: child states: SI
> > Mon Aug  3 06:27:58 2009 [4292] info: prefork: child states: II
> > Mon Aug  3 06:34:31 2009 [4292] info: spamd: server killed by SIGTERM,
> > shutting down
> 
> That looks like the system log file (/var/log/messages). Have you looked 
> in the mail log file (typically /var/log/maillog) ?
I have it now - the only disappointment for me is it does not log the
'to' or 'from' or client ip. I understand this is not a function of
Spamassassin, but it would have been so useful. It's an odd situation
perhaps. Blocking at the SMTP stage using a milter in response to a
Fetchmail hash feeding Postfix. The result is you see nothing very
useful in the logs to identify the blocked message. I trust the set up
entirely, but I love my logs too :-)

It's not the fault of SpamAssassin - I'm clear on that, but as it is
scanning the entire message retrieved by Fetchmail, it would be really
useful to get it to log the client ip, to and from as well. There may
even be a hack to do this someone is aware of? 


-- 
-----------------------------------------------------------
C Werclick .Lot
Technical incompetent
Loyal Order Of The Teapot.

This e-mail and its attachments is intended only to be used as an e-mail
and an attachment. Any use of it for other purposes other than as an
e-mail and an attachment will not be covered by any warranty that may or
may not form part of this e-mail and attachment. 




Re: A silly logging question

Posted by John Hardin <jh...@impsec.org>.
On Tue, 8 Sep 2009, Clunk Werclick wrote:

> Can I get SpamAssassin to fully log what it is doing? The best I can
> ever get is something like this;
>
> Mon Aug  3 06:27:57 2009 [4290] info: logger: removing stderr method
> Mon Aug  3 06:27:58 2009 [4292] info: spamd: server started on port
> 783/tcp (running version 3.2.5)
> Mon Aug  3 06:27:58 2009 [4292] info: spamd: server pid: 4292
> Mon Aug  3 06:27:58 2009 [4292] info: spamd: server successfully spawned
> child process, pid 4293
> Mon Aug  3 06:27:58 2009 [4292] info: spamd: server successfully spawned
> child process, pid 4294
> Mon Aug  3 06:27:58 2009 [4292] info: prefork: child states: SI
> Mon Aug  3 06:27:58 2009 [4292] info: prefork: child states: II
> Mon Aug  3 06:34:31 2009 [4292] info: spamd: server killed by SIGTERM,
> shutting down

That looks like the system log file (/var/log/messages). Have you looked 
in the mail log file (typically /var/log/maillog) ?

-- 
  John Hardin KA7OHZ                    http://www.impsec.org/~jhardin/
  jhardin@impsec.org    FALaholic #11174     pgpk -a jhardin@impsec.org
  key: 0xB8732E79 -- 2D8C 34F4 6411 F507 136C  AF76 D822 E6E6 B873 2E79
-----------------------------------------------------------------------
   Homeland Security: Specializing in Tactical Band-aids for Strategic
   Problems.                       -- Eric K. in Bruce Schneier's blog
-----------------------------------------------------------------------
  9 days until the 222nd anniversary of the signing of the U.S. Constitution

Re: A silly logging question

Posted by Mark Martinec <Ma...@ijs.si>.
On Tuesday September 8 2009 12:10:41 Clunk Werclick wrote:
> I'm using syslog-ng, but despite listening to;
> unix-stream("/dev/log");
> It gets nothing - but I don't expect it to as the default spamassassin
> conf has this line;
>
> OPTIONS="--create-prefs --max-children 5 --username spamd
> --helper-home-dir ${SAHOME} -s /var/log/spamassassin/spamd.log"
>
> Since August, it's produced empty logs here.

See spamd man page. The -s option is supposed to take a
syslog facility name, not a filename.

  Mark

Re: A silly logging question

Posted by Clunk Werclick <cl...@wibblywobblyteapot.co.uk>.
On Tue, 2009-09-08 at 11:50 +0300, Jari Fredriksson wrote:
> > This is probably a dumb question, but my looking through
> > the docs is just confusing me.
> > 
> > Can I get SpamAssassin to fully log what it is doing? The
> > best I can ever get is something like this;
> > 
> > Mon Aug  3 06:27:57 2009 [4290] info: logger: removing
> > stderr method Mon Aug  3 06:27:58 2009 [4292] info:
> > spamd: server started on port 783/tcp (running version
> > 3.2.5) 
> > Mon Aug  3 06:27:58 2009 [4292] info: spamd: server pid:
> > 4292 
> > Mon Aug  3 06:27:58 2009 [4292] info: spamd: server
> > successfully spawned child process, pid 4293
> > Mon Aug  3 06:27:58 2009 [4292] info: spamd: server
> > successfully spawned child process, pid 4294
> > Mon Aug  3 06:27:58 2009 [4292] info: prefork: child
> > states: SI 
> > Mon Aug  3 06:27:58 2009 [4292] info: prefork: child
> > states: II 
> > Mon Aug  3 06:34:31 2009 [4292] info: spamd: server
> > killed by SIGTERM, shutting down
> > 
> > 
> > But never any actual information on the mail scanning
> > process. The problem, from my perspective, is I reject
> > with a milter at the SMTP stage - so I never get to see
> > any blocked messages. I have a few in my logs that
> > Fetchmail has picked up from a pop account, before
> > dumping them into Postfix - and I have no Spamassassin
> > log I can view to see what they caught on and if I need
> > to take any action.  
> > 
> > I had a look at:
> > Mail::SpamAssassin::Logger - SpamAssassin logging module
> > 
> > But I'm not entirely sure how to invoke that or if I can
> > get it to give me what I need. It is very terse in
> > information. 
> > 
> > Perhaps I can start SA differently to produce a log of
> > the scanning it is doing? I'm sure this is a beginners
> > question and I feel very stupid having to ask - but I
> > cannot find the obvious answer. 
> 
> SA logs to local3.info, not mail.info, in my configuration. I do not recall changing that, it may be default. Does your logger catch local3.info?
> 
> 
I'm using syslog-ng, but despite listening to;
unix-stream("/dev/log");
It gets nothing - but I don't expect it to as the default spamassassin
conf has this line;

OPTIONS="--create-prefs --max-children 5 --username spamd
--helper-home-dir ${SAHOME} -s /var/log/spamassassin/spamd.log"

Since August, it's produced empty logs here.


Re: A silly logging question

Posted by Jari Fredriksson <ja...@iki.fi>.
> This is probably a dumb question, but my looking through
> the docs is just confusing me.
> 
> Can I get SpamAssassin to fully log what it is doing? The
> best I can ever get is something like this;
> 
> Mon Aug  3 06:27:57 2009 [4290] info: logger: removing
> stderr method Mon Aug  3 06:27:58 2009 [4292] info:
> spamd: server started on port 783/tcp (running version
> 3.2.5) 
> Mon Aug  3 06:27:58 2009 [4292] info: spamd: server pid:
> 4292 
> Mon Aug  3 06:27:58 2009 [4292] info: spamd: server
> successfully spawned child process, pid 4293
> Mon Aug  3 06:27:58 2009 [4292] info: spamd: server
> successfully spawned child process, pid 4294
> Mon Aug  3 06:27:58 2009 [4292] info: prefork: child
> states: SI 
> Mon Aug  3 06:27:58 2009 [4292] info: prefork: child
> states: II 
> Mon Aug  3 06:34:31 2009 [4292] info: spamd: server
> killed by SIGTERM, shutting down
> 
> 
> But never any actual information on the mail scanning
> process. The problem, from my perspective, is I reject
> with a milter at the SMTP stage - so I never get to see
> any blocked messages. I have a few in my logs that
> Fetchmail has picked up from a pop account, before
> dumping them into Postfix - and I have no Spamassassin
> log I can view to see what they caught on and if I need
> to take any action.  
> 
> I had a look at:
> Mail::SpamAssassin::Logger - SpamAssassin logging module
> 
> But I'm not entirely sure how to invoke that or if I can
> get it to give me what I need. It is very terse in
> information. 
> 
> Perhaps I can start SA differently to produce a log of
> the scanning it is doing? I'm sure this is a beginners
> question and I feel very stupid having to ask - but I
> cannot find the obvious answer. 

SA logs to local3.info, not mail.info, in my configuration. I do not recall changing that, it may be default. Does your logger catch local3.info?