message-id: +1.  I really agree this is a good plan.

memory size: not so easy -- we can't actually get that info reliably on all
platforms :(

awl/bayes: it should already be doing that. hmm

Subject: Re:  Spamc/d should log memory and message-id after processing

On Fri, May 06, 2005 at 10:23:48AM -0700, bugzilla-daemon@bugzilla.spamassassin.org wrote:
> message-id: +1.  I really agree this is a good plan.

Don't we do this already?

May  1 04:14:04 eclectic spamd[3094]: processing message
<200505010814.j418E3512935@franz.videotron.net> for timex:507. 

I think the idea is to log the Message-ID on errors and warns, too.
that way the log that now contains:

spamd [5304]: 30 second timeout while trying to CHECK

will be:

spamd [5304]: id=<20050430072654.GA24823@stripey.com>: 30 second timeout while
trying to CHECK

In other words, attach the message-id to every error message.

I think an admin could probably take the process-ID and work backwards to find
the corresponding Message-ID in the "processing message" line, but this makes
things a bit easier.

Subject: Re:  Spamc/d should log memory and message-id after processing

> memory size: not so easy -- we can't actually get that info reliably on
all
> platforms :(

My impression of "unreliable" is that it may tend to over/under report,
depending on the platform.

However, that is immaterial.  It is the difference between two reports that
is interesting.  And no matter how badly the memory report is mangled, it is
highly improbable that it would show a decrease when top would show an
increase.

The idea is that when someone complains that spamd is taking 800 megs, being
able to track the reported number of "800" (whatever the "real" number might
be) back to some initial number that is probably in the 20-60 meg range.

Subject: Re:  Spamc/d should log memory and message-id after processing

> I think the idea is to log the Message-ID on errors and warns, too.
> that way the log that now contains:
>
> In other words, attach the message-id to every error message.

That might be a good idea, but it wasn't what I had originally suggested.
My proginal suggestion was for a new log entry that said something like
(format it as you will):

    Spamd pid 1234: 14:32:51 Processed message <> ram <nn>.

If you want to add in a processing time for the message, that would be a
bonus.

If you want to combine the memory report with an existing "completed
processing" message, that would be fine, AS LONG as the report shows up in
the same format for all messages, no matter how the processing turned out.
And AS LONG as the memory report also appears on bayes/awl update
completions.

The idea is simply to track spamd memory usage per message, also showing the
message processing sequence, on the assumption that memory growth is related
more to the sequence than to an individual message.

Note: It now occurs to me that since spamd can get aborted, it might make
sense to report "started processing message <> ram nn", so that a log entry
will show up even if a message aborts.  In this case you obviously wouldn't
need a message at the end of processing, since the previous message
presumably ended with the amount of ram this one is starting at.

no, on some platforms you could only get it by parsing "ps" output -- which is
slow, heavyweight, and kludgy.

fwiw, it appears we can get the process size easily enough on linux:
/proc/self/status contains

VmSize:     1868 kB
VmLck:         0 kB
VmRSS:       648 kB
VmData:      160 kB
VmStk:        84 kB

etc. easily parseable.  the Apache::SizeLimit CAVEATS section lists a few more
platform-specific tricks.

Logging memory usage is fine and all, but we should just start a new child
when memory usage goes over a certain point.

Subject: Re:  Spamc/d should log memory and message-id after processing

> Logging memory usage is fine and all, but we should just start a new child
> when memory usage goes over a certain point.

I certainly won't object to that.  :-)  However, that still requires looking
at the momry usage, and deciding what that limit is.  Which might be a tad
hard to do with a single constant, as various systems seem to have different
ideas of memory usage values.

Still though I think logging it should also be done, so that it might be
possible to find out WHY memory usage goes Boom! (as one recent thread had
it) and then maybe fix the root cause, rather than just having a handy rifle
to shoot the offenders.

yeah, restarting if RAM usage goes over a certain size would be the #1 useful
feature that would fall out of this.  but as Loren says, being able to figure
out which message caused the RAM explosion -- or at least that message's
Message-Id -- allows us to receive bug reports ;) and would be very handy.

ok, I can add a plugin that'd do this pretty easily; a couple of hooks in spamd
is all it'd take.   Mail::SpamAssassin::Plugin::SpamdSizeLimit... sound useful?

Triage: Based on the recorded discussion, at least some of these ideas should be
implemented.  Those that aren't yet in 3.1.0 probably should be targeted for 3.1.1.

actually, I think this is major enough to be bumped to 3.2.

This is now eminently implementable in plugins; the 'set_spamd_result_item'
API on PerMsgStatus allows arbitrary name=value pairs to be added to the spamd
"result" line logged to syslog, and the 'spamd_child_post_connection_close'
plugin hook allows a plugin to run code after each message scanned by a child.  

Moving away from the 3.2.0 milestone, since it's now not limited by code in SVN,
just by someone stepping up to write it ;)

Closing ancient stale bug.