Koozali.org: home of the SME Server

Spamassassin - Log Clarification

Offline grattman

  • ***
  • 122
  • +0/-0
Spamassassin - Log Clarification
« on: March 27, 2007, 10:30:23 PM »
Okay.....my server is inundated with spam...(damn spammers), to the point that sometimes my server just hangs. This server is a dual Xeon 2.4Ghz with 8Gb RAM.

So I started to poke through the spamd/current log and found something odd. I have attached several spams for review. In each it states that it cannot create a lockfile and at the end says autolearn=failed.

Does this mean that the Bayesian is not working? Just curious. Thanks,
Grattman

-----------------------------------------------
2007-03-24 11:17:31.883615500 [3136] info: prefork: child states: II
2007-03-24 11:18:39.071876500 [17244] info: spamd: connection from localhost [127.0.0.1] at port 34231
2007-03-24 11:18:39.082483500 [17244] info: spamd: checking message <319C1503048EB2F.3A9F84AF8A@tpnet.pl> for qpsmtpd:1005
2007-03-24 11:18:45.352312500 [17244] error: bayes: locker: safe_lock: cannot create lockfile /var/spool/spamd/.spamassassin/bayes.mutex: Permission denied
2007-03-24 11:18:45.356007500 [17244] info: spamd: identified spam (123.5/4.0) for qpsmtpd:1005 in 6.3 seconds, 7724 bytes.
2007-03-24 11:18:45.356350500 [17244] info: spamd: result: Y 123 - DRUGS_ERECTILE,FROM_LOCAL_NOVOWEL,HTML_IMAGE_ONLY_24,HTML_MESSAGE,RAZOR2_CF_RANGE_51_100,RAZOR2_CF_RANGE_E8_51_100,RAZOR2_CHECK,RCVD_IN_BL_SPAMCOP_NET,RCVD_IN_DSBL,RCVD_IN_NJABL_DUL,RCVD_IN_PBL,SUBJECT_DRUG_GAP_C,URIBL_AB_SURBL,URIBL_BLACK,URIBL_JP_SURBL,URIBL_SBL,URI_NOVOWEL,USER_IN_BLACKLIST scantime=6.3,size=7724,user=qpsmtpd,uid=1005,required_score=4.0,rhost=localhost,raddr=127.0.0.1,rport=34231,mid=<319C1503048EB2F.3A9F84AF8A@tpnet.pl>,autolearn=failed
2007-03-24 11:18:45.413888500 [3136] info: prefork: child states: II
2007-03-24 11:19:55.633391500 [17244] info: spamd: connection from localhost [127.0.0.1] at port 34237
2007-03-24 11:19:55.651408500 [17244] info: spamd: checking message <715919.32328.qm@web60821.mail.yahoo.com> for qpsmtpd:1005
2007-03-24 11:19:59.914264500 [17244] info: spamd: identified spam (4.5/4.0) for qpsmtpd:1005 in 4.3 seconds, 18207 bytes.
2007-03-24 11:19:59.914525500 [17244] info: spamd: result: Y 4 - DNS_FROM_RFC_ABUSE,DNS_FROM_RFC_WHOIS,HTML_MESSAGE,HTML_TINY_FONT,INVALID_DATE scantime=4.3,size=18207,user=qpsmtpd,uid=1005,required_score=4.0,rhost=localhost,raddr=127.0.0.1,rport=34237,mid=<715919.32328.qm@web60821.mail.yahoo.com>,autolearn=no
2007-03-24 11:19:59.977570500 [3136] info: prefork: child states: II
2007-03-24 11:21:32.419660500 [17244] info: spamd: connection from localhost [127.0.0.1] at port 34256
2007-03-24 11:21:32.433445500 [17244] info: spamd: checking message <D816D7C7810D3E2.F35407A492@waw.pl> for qpsmtpd:1005
2007-03-24 11:21:38.635273500 [17244] error: bayes: locker: safe_lock: cannot create lockfile /var/spool/spamd/.spamassassin/bayes.mutex: Permission denied
2007-03-24 11:21:38.636422500 [17244] info: spamd: identified spam (18.4/4.0) for qpsmtpd:1005 in 6.2 seconds, 7529 bytes.
2007-03-24 11:21:38.636853500 [17244] info: spamd: result: Y 18 - HTML_IMAGE_ONLY_24,HTML_IMAGE_RATIO_02,HTML_MESSAGE,RAZOR2_CF_RANGE_51_100,RAZOR2_CF_RANGE_E8_51_100,RAZOR2_CHECK,RCVD_IN_BL_SPAMCOP_NET,RCVD_IN_NJABL_DUL,RCVD_IN_PBL,URIBL_AB_SURBL,URIBL_BLACK,URIBL_JP_SURBL,URIBL_SBL,URI_NOVOWEL scantime=6.2,size=7529,user=qpsmtpd,uid=1005,required_score=4.0,rhost=localhost,raddr=127.0.0.1,rport=34256,mid=<D816D7C7810D3E2.F35407A492@waw.pl>,autolearn=failed
2007-03-24 11:21:38.697960500 [3136] info: prefork: child states: II
2007-03-24 11:22:31.350056500 [17244] info: spamd: connection from localhost [127.0.0.1] at port 34270
2007-03-24 11:22:31.357654500 [17244] info: spamd: checking message <C894EDD8C25AEDB.FD3C8D06FC@prtelecom.hu> for qpsmtpd:1005
2007-03-24 11:22:37.481785500 [17244] error: bayes: locker: safe_lock: cannot create lockfile /var/spool/spamd/.spamassassin/bayes.mutex: Permission denied
2007-03-24 11:22:37.482850500 [17244] info: spamd: identified spam (17.0/4.0) for qpsmtpd:1005 in 6.1 seconds, 1859 bytes.
2007-03-24 11:22:37.483169500 [17244] info: spamd: result: Y 16 - DNS_FROM_RFC_ABUSE,DNS_FROM_RFC_POST,HTML_MESSAGE,MIME_HTML_ONLY,RAZOR2_CF_RANGE_51_100,RAZOR2_CF_RANGE_E4_51_100,RAZOR2_CF_RANGE_E8_51_100,RAZOR2_CHECK,URIBL_BLACK,URIBL_JP_SURBL,URIBL_SBL,URIBL_SC_SURBL scantime=6.1,size=1859,user=qpsmtpd,uid=1005,required_score=4.0,rhost=localhost,raddr=127.0.0.1,rport=34270,mid=<C894EDD8C25AEDB.FD3C8D06FC@prtelecom.hu>,autolearn=failed
2007-03-24 11:22:37.540393500 [3136] info: prefork: child states: II
2007-03-24 11:24:34.201587500 [17244] info: spamd: connection from localhost [127.0.0.1] at port 34277
2007-03-24 11:24:34.212051500 [17244] info: spamd: checking message <F247A59E7814C84.D653196815@t-dialin.net> for qpsmtpd:1005
2007-03-24 11:24:36.355180500 [17244] error: bayes: locker: safe_lock: cannot create lockfile /var/spool/spamd/.spamassassin/bayes.mutex: Permission denied
2007-03-24 11:24:36.356324500 [17244] info: spamd: identified spam (25.2/4.0) for qpsmtpd:1005 in 2.2 seconds, 7802 bytes.
2007-03-24 11:24:36.356754500 [17244] info: spamd: result: Y 25 - DIGEST_MULTIPLE,DNS_FROM_RFC_WHOIS,DRUGS_ERECTILE,HTML_IMAGE_ONLY_24,HTML_MESSAGE,PYZOR_CHECK,RAZOR2_CF_RANGE_51_100,RAZOR2_CF_RANGE_E8_51_100,RAZOR2_CHECK,RCVD_IN_NJABL_DUL,RCVD_IN_PBL,RCVD_IN_SORBS_DUL,URIBL_AB_SURBL,URIBL_BLACK,URIBL_JP_SURBL,URIBL_SBL,URI_NO_WWW_INFO_CGI scantime=2.2,size=7802,user=qpsmtpd,uid=1005,required_score=4.0,rhost=localhost,raddr=127.0.0.1,rport=34277,mid=<F247A59E7814C84.D653196815@t-dialin.net>,autolearn=failed
2007-03-24 11:24:36.416667500 [3136] info: prefork: child states: II
2007-03-24 11:25:23.614703500 [17244] info: spamd: connection from localhost [127.0.0.1] at port 34281
2007-03-24 11:25:23.621901500 [17244] info: spamd: checking message <CA9BC3CA34CC8A1.5AB323197D@t-dialin.net> for qpsmtpd:1005
2007-03-24 11:25:29.953869500 [17244] info: spamd: identified spam (6.8/4.0) for qpsmtpd:1005 in 6.3 seconds, 2340 bytes.
2007-03-24 11:25:29.954180500 [17244] info: spamd: result: Y 6 - BODY_ENHANCEMENT2,DNS_FROM_RFC_WHOIS,RAZOR2_CHECK,RCVD_IN_NJABL_DUL,RCVD_IN_PBL,RCVD_IN_SORBS_DUL,URIBL_SBL scantime=6.3,size=2340,user=qpsmtpd,uid=1005,required_score=4.0,rhost=localhost,raddr=127.0.0.1,rport=34281,mid=<CA9BC3CA34CC8A1.5AB323197D@t-dialin.net>,autolearn=no
2007-03-24 11:25:30.016700500 [3136] info: prefork: child states: II
2007-03-24 11:26:18.092205500 [17244] info: spamd: connection from localhost [127.0.0.1] at port 34284
2007-03-24 11:26:18.105463500 [17244] info: spamd: checking message <f87201c76e28$c1b01c80$2cb81234@bgholleyucio> for qpsmtpd:1005
2007-03-24 11:26:24.309489500 [17244] error: mkdir /var/service/qpsmtpd/.spamassassin: Permission denied at /usr/lib/perl5/vendor_perl/5.8.5/Mail/SpamAssassin.pm line 1536
2007-03-24 11:26:24.602525500 [17244] info: spamd: identified spam (11.1/4.0) for qpsmtpd:1005 in 6.5 seconds, 17098 bytes.
2007-03-24 11:26:24.602880500 [17244] info: spamd: result: Y 11 - EXTRA_MPART_TYPE,FUZZY_OCR,HTML_MESSAGE,SPAMMY_XMAILER,TVD_FW_GRAPHIC_NAME_LONG scantime=6.5,size=17098,user=qpsmtpd,uid=1005,required_score=4.0,rhost=localhost,raddr=127.0.0.1,rport=34284,mid=<f87201c76e28$c1b01c80$2cb81234@bgholleyucio>,autolearn=no
2007-03-24 11:26:24.661495500 [3136] info: prefork: child states: II
2007-03-24 11:28:00.973973500 [17244] info: spamd: connection from localhost [127.0.0.1] at port 34289
2007-03-24 11:28:00.982982500 [17244] info: spamd: checking message <001501c76b7c$75bc7430$078f6e34@billgates> for qpsmtpd:1005
2007-03-24 11:28:07.232977500 [17244] error: bayes: locker: safe_lock: cannot create lockfile /var/spool/spamd/.spamassassin/bayes.mutex: Permission denied
2007-03-24 11:28:07.234100500 [17244] info: spamd: identified spam (20.2/4.0) for qpsmtpd:1005 in 6.3 seconds, 2803 bytes.
2007-03-24 11:28:07.234541500 [17244] info: spamd: result: Y 20 - HTML_FONT_BIG,HTML_MESSAGE,RAZOR2_CF_RANGE_51_100,RAZOR2_CF_RANGE_E8_51_100,RAZOR2_CHECK,RCVD_IN_NJABL_DUL,RCVD_IN_PBL,RCVD_IN_WHOIS_INVALID,URIBL_AB_SURBL,URIBL_BLACK,URIBL_OB_SURBL,URIBL_SBL,URIBL_SC_SURBL scantime=6.3,size=2803,user=qpsmtpd,uid=1005,required_score=4.0,rhost=localhost,raddr=127.0.0.1,rport=34289,mid=<001501c76b7c$75bc7430$078f6e34@billgates>,autolearn=failed
2007-03-24 11:28:07.296676500 [3136] info: prefork: child states: II
2007-03-24 11:28:08.031758500 [17244] info: spamd: connection from localhost [127.0.0.1] at port 34292
2007-03-24 11:28:08.045079500 [17244] info: spamd: checking message <72ec01c76dda$b0673380$c1ab5b20@engrenexu> for qpsmtpd:1005
2007-03-24 11:28:09.216065500 [17244] error: mkdir /var/service/qpsmtpd/.spamassassin: Permission denied at /usr/lib/perl5/vendor_perl/5.8.5/Mail/SpamAssassin.pm line 1536
2007-03-24 11:28:09.552331500 [17244] info: spamd: identified spam (11.5/4.0) for qpsmtpd:1005 in 1.5 seconds, 17497 bytes.
2007-03-24 11:28:09.552643500 [17244] info: spamd: result: Y 11 - EXTRA_MPART_TYPE,FUZZY_OCR,HTML_MESSAGE,RCVD_IN_NJABL_DUL,RCVD_IN_PBL scantime=1.5,size=17497,user=qpsmtpd,uid=1005,required_score=4.0,rhost=localhost,raddr=127.0.0.1,rport=34292,mid=<72ec01c76dda$b0673380$c1ab5b20@engrenexu>,autolearn=no
2007-03-24 11:28:09.610611500 [3136] info: prefork: child states: II
2007-03-24 11:28:46.514599500 [17244] info: spamd: connection from localhost [127.0.0.1] at port 34295
2007-03-24 11:28:46.526226500 [17244] info: spamd: checking message <001601c76e31$8d0534d0$06da0fec@patryk1cf0bd85> for qpsmtpd:1005
2007-03-24 11:28:48.005091500 [17244] error: mkdir /var/service/qpsmtpd/.spamassassin: Permission denied at /usr/lib/perl5/vendor_perl/5.8.5/Mail/SpamAssassin.pm line 1536
2007-03-24 11:28:48.556723500 [17244] error: bayes: locker: safe_lock: cannot create lockfile /var/spool/spamd/.spamassassin/bayes.mutex: Permission denied
2007-03-24 11:28:48.557900500 [17244] info: spamd: identified spam (23.8/4.0) for qpsmtpd:1005 in 2.0 seconds, 13172 bytes.
2007-03-24 11:28:48.558313500 [17244] info: spamd: result: Y 23 - EXTRA_MPART_TYPE,FUZZY_OCR,HTML_MESSAGE,PART_CID_STOCK,RCVD_IN_NJABL_DUL,RCVD_IN_PBL,RCVD_IN_SORBS_DUL,TVD_FW_GRAPHIC_ID1,TVD_FW_GRAPHIC_NAME_MID scantime=2.0,size=13172,user=qpsmtpd,uid=1005,required_score=4.0,rhost=localhost,raddr=127.0.0.1,rport=34295,mid=<001601c76e31$8d0534d0$06da0fec@patryk1cf0bd85>,autolearn=failed
2007-03-24 11:28:48.619349500 [3136] info: prefork: child states: II
2007-03-24 11:33:40.130040500 [17244] info: spamd: connection from localhost [127.0.0.1] at port 34298
2007-03-24 11:33:40.138425500 [17244] info: spamd: checking message <C159F956865D00A.B02C8951DF@interspes.pl> for qpsmtpd:1005
2007-03-24 11:33:42.461627500 [17244] error: bayes: locker: safe_lock: cannot create lockfile /var/spool/spamd/.spamassassin/bayes.mutex: Permission denied
2007-03-24 11:33:42.462703500 [17244] info: spamd: identified spam (18.1/4.0) for qpsmtpd:1005 in 2.3 seconds, 1840 bytes.
2007-03-24 11:33:42.463167500 [17244] info: spamd: result: Y 18 - DIGEST_MULTIPLE,HTML_MESSAGE,MIME_HTML_ONLY,PYZOR_CHECK,RAZOR2_CF_RANGE_51_100,RAZOR2_CF_RANGE_E4_51_100,RAZOR2_CF_RANGE_E8_51_100,RAZOR2_CHECK,URIBL_BLACK,URIBL_JP_SURBL,URIBL_SBL,URIBL_SC_SURBL scantime=2.3,size=1840,user=qpsmtpd,uid=1005,required_score=4.0,rhost=localhost,raddr=127.0.0.1,rport=34298,mid=<C159F956865D00A.B02C8951DF@interspes.pl>,autolearn=failed
...

Offline okepc

  • ***
  • 118
  • +0/-0
    • http://www.okepc.nl
Spamassassin - Log Clarification
« Reply #1 on: March 28, 2007, 10:30:18 AM »
You probably enabled bayes and the permissions for that file/dir are incorrect.
Correct me if im wrong i have no access to the server atm
/var/spool/spamd/.spamassassin should be spamd:spamd 750
The files in there should be spamd:spamd 644

Dirk

Offline idyll

  • ***
  • 113
  • +0/-0
agree
« Reply #2 on: March 28, 2007, 03:41:34 PM »
The above is exactly the same issue we all face when enabling Bayes, as it is not enabled by default. Simple fix.

Search for the threads discussing that issue if you find it odd to run Spam Assassin without self learning enabled.

regards,

patrick
...

Offline mmccarn

  • *
  • 2,626
  • +10/-0
Spamassassin - Log Clarification
« Reply #3 on: March 28, 2007, 04:00:37 PM »
I had a permissions problem after originally configuring auto-learn, and found entries like these in /var/log/spamd/current:
Code: [Select]
error: bayes: locker: safe_lock: cannot create lockfile /var/spool/spamd/.spamassassin/bayes.mutex: Permission deniedRunning chown spamd.spamd /var/spool/spamd/.spamassassin/bayes.mutex solved the problem.

Offline compdoc

  • ****
  • 211
  • +0/-0
Spamassassin - Log Clarification
« Reply #4 on: March 30, 2007, 08:58:20 PM »
bayes.mutex and bayes_seen need to be set to 750. bayes_journal and bayes_toks are ok at 640.

Unfortunately, it seems whenever there is a major update, the permissions are changed to all 640, which breaks bayes autolearn...

Offline pmstewart

  • *
  • 73
  • +0/-0
Spamassassin - Log Clarification
« Reply #5 on: April 12, 2007, 03:44:07 PM »
Quote
compdoc:  Unfortunately, it seems whenever there is a major update, the permissions are changed to all 640, which breaks bayes autolearn


Just a thought ..... perms are frequently set by the metadata templates - so would it be safe to assume one could create a custom-metadata template for perms on the file?

Offline jfarschman

  • *
  • 406
  • +0/-0
Spamassassin - Log Clarification
« Reply #6 on: April 12, 2007, 05:16:18 PM »
That is an elegant and logical way to make that happen.

Care to post it to bugzilla?  It's painless and rewarding.  8)
Jay Farschman
ICQ - 60448985
jay@hitechsavvy.com

Offline compdoc

  • ****
  • 211
  • +0/-0
Spamassassin - Log Clarification
« Reply #7 on: April 12, 2007, 05:40:22 PM »
I was waiting to see what the next major SME or spamassassin update brings. If it sets those permssions wrong again, I'm going to report it.

Just want to make sure whats causing it...