strange bug, filling syslog

[Patrick von der Hagen <pa...@wudika.de>]

userHi all,

I've been surprised by an nagios-alert that my syslog-partition was
running full. In Fact, in about 18 hours I got 26GB of syslog, all done
by spamassassin. I installed Spamassassin in October and hardly changed
anything since then (just some scores, some additional tests, but
certainly nothing since Christmas).

It started like this:
Jan  2 23:09:17 mail7 spamd[28417]: spamd: checking message
<30...@cisco.com> for exim:427
Jan  2 23:09:17 mail7 spamd[27617]: spamd: got connection over
/opt/antispam/var/socket/spamd
Jan  2 23:09:17 mail7 spamd[28614]: spamd: got connection over
/opt/antispam/var/socket/spamd
Jan  2 23:09:17 mail7 spamd[16004]: __alarm__
Jan  2 23:09:23 mail7 spamd[27617]: spamd: checking message
<18...@clemson.edu> for exim:427
Jan  2 23:09:23 mail7 spamd[31646]: __alarm__
Jan  2 23:09:25 mail7 spamd[13602]: spamd: identified spam (52.4/5.0)
for exim:427 in 63.5 seconds, 2833 bytes.
Jan  2 23:09:25 mail7 spamd[16004]: spamd: copy_config timeout,
respawning child process after 9 messages at
/usr/spamassassin/current/bin/spamd line 96
9.
Jan  2 23:09:25 mail7 spamd[18001]: __alarm__
Jan  2 23:09:25 mail7 spamd[224]: spamd: handled cleanup of child pid
3843 due to SIGCHLD
Jan  2 23:09:25 mail7 spamd[13602]: spamd: result: Y 52 -
BAYES_99,DATE_IN_PAST_24_48,DCC_CHECK,DIGEST_MULTIPLE,DRUGS_ERECTILE,DRUG_DOSAGE,DRUG_ED_CAPS,
HTML_50_60,HTML_FONT_SIZE_LARGE,HTML_MESSAGE,INVALID_DATE,ONLINE_PHARMACY,RAZOR2_CF_RANGE_51_100,RAZOR2_CF_RANGE_E4_51_100,RAZOR2_CF_RANGE_E8_51_100,RAZ
OR2_CHECK,RCVD_IN_BL_SPAMCOP_NET,RCVD_IN_XBL,REPTO_OVERQUOTE_THEBAT,SARE_SUPERVIAGRA,SUBJECT_FUZZY_MEDS,UPPERCASE_25_50,URIBL_AB_SURBL,URIBL_JP_SURBL,UR
IBL_OB_SURBL,URIBL_SBL,URIBL_SC_SURBL,URIBL_WS_SURBL
scantime=63.5,size=2833,user=exim,uid=427,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=
/opt/antispam/var/socket/spamd,mid=<XX...@XXXX>,bayes=1,autolearn=unavailable
Jan  2 23:09:25 mail7 spamd[28614]: spamd: checking message
<16...@ci.springfield.mo.us> for exim:427
Jan  2 23:09:25 mail7 spamd[18001]: spamd: copy_config timeout,
respawning child process after 1 messages at
/usr/spamassassin/current/bin/spamd line 96
9.
Jan  2 23:09:25 mail7 spamd[24573]: spamd: copy_config timeout,
respawning child process after 8 messages at
/usr/spamassassin/current/bin/spamd line 96
9.
Jan  2 23:09:25 mail7 spamd[31646]: spamd: copy_config timeout,
respawning child process after 20 messages at
/usr/spamassassin/current/bin/spamd line 9
69.
Jan  2 23:09:25 mail7 spamd[224]: spamd: server successfully spawned
child process, pid 22119
Jan  2 23:09:25 mail7 spamd[4163]: spamd: identified spam (46.6/5.0) for
exim:427 in 50.9 seconds, 2845 bytes.
Jan  2 23:09:25 mail7 spamd[22119]: spamd: got connection over
/opt/antispam/var/socket/spamd
Jan  2 23:09:25 mail7 spamd[13602]: spamd: got connection over
/opt/antispam/var/socket/spamd
Jan  2 23:09:25 mail7 spamd[26230]: bayes: cannot open bayes databases
/opt/antispam/.spamassassin/bayes_* R/W: lock failed:
Jan  2 23:09:25 mail7 antispam[24573]: Attempt to free unreferenced
scalar during global destruction.


and then it went like this:

Jan  3 16:22:06 mail7 antispam[24573]: Attempt to free unreferenced
scalar during global destruction.
Jan  3 16:22:06 mail7 last message repeated 2 times
Jan  3 16:22:06 mail7 antispam[16004]: syslog: invalid level/facility:
warning at
/usr/spamassassin/3.1.0//lib/site_perl/5.6.1/Mail/SpamAssassin/Logger/Syslog.pm 

line 131
Jan  3 16:22:06 mail7 antispam[24573]: Attempt to free unreferenced
scalar during global destruction.
Jan  3 16:22:06 mail7 last message repeated 2 times
Jan  3 16:22:06 mail7 antispam[16004]: syslog: invalid level/facility:
warning at
/usr/spamassassin/3.1.0//lib/site_perl/5.6.1/Mail/SpamAssassin/Logger/Syslog.pm 

line 131
Jan  3 16:22:06 mail7 antispam[24573]: Attempt to free unreferenced
scalar during global destruction.
Jan  3 16:22:06 mail7 antispam[16004]: syslog: invalid level/facility:
warning at
/usr/spamassassin/3.1.0//lib/site_perl/5.6.1/Mail/SpamAssassin/Logger/Syslog.pm 

line 131


Has anyone seen such a behaviour before? Otherwise, I'd file a bugreport
against it.... having a look at my stats it seems that when Spamassasin
went "bang" CPU-usage and Load exploded, as did context-switches.
Memory-usage, especially SWAP, was perfectly normal. I don't find
anything before spamassassin showed problems, stats are fine, syslog is
ok, no cronjobs or things like that ....



-- 
CU,
    Patrick.