spamassassin - не работает тестовое правило

[WWT]

Со spamassassin'ом общался только встроенным в почтовик Kerio, linux с postfix'ом знаю очень-очеь поверхностно, а тут именно они.

Суть: не работают мои правила.

Сделал 90_test.cf с тестовым правилом

header WWT_TEST01 Subject =~ /qwertys/
score WWT_TEST01 5.9

Положил в /usr/share/spamassassin/ к правилам (под Kerio так работает), рестартовал spamd - не работает

Положил в /etc/spamassassin/, прописал в local.cf
include 90_test.cf
рестартовал spamd - не работает

Прогнал spamassasin --lint - не ругается (если сделать ошибку в правиле - ругается)

kill -s SIGHUP spamd - нет эффекта.

Подскажите pls где бы ещё порыться.

[Хостинг HostFood.ru]

Тарифы на хостинг в России, от 12 рублей: https://www.host-food.ru/tariffs/hosting/
Тарифы на виртуальные сервера (VPS/VDS/KVM) в РФ, от 189 руб.: https://www.host-food.ru/tariffs/virtualny-server-vps/
Выделенные сервера, Россия, Москва, от 2000 рублей (HP Proliant G5, Intel Xeon E5430 (2.66GHz, Quad-Core, 12Mb), 8Gb RAM, 2x300Gb SAS HDD, P400i, 512Mb, BBU):
https://www.host-food.ru/tariffs/vydelennyi-server-ds/
Недорогие домены в популярных зонах: https://www.host-food.ru/domains/

[WWT]

всё ещё нужна помощь

[dm07]

Что в логах?

[WWT]

/var/log/mail.log
Вот, шлю себе снаружи письмо с текстом qweeertSS в теме, доставляется, баллы не начисляются:

Код: Выделить всё

Jul 18 02:32:19 smicro postfix/cleanup[19423]: 8178CF41D65: message-id=<CAPcZZRCMdpg7U2xAJVkPPjwBJuzXHYSFq6f8_CZjR-ezWAPPvA@mail.gmail.com>
Jul 18 02:32:19 smicro postfix/smtpd[19502]: disconnect from smicro[127.0.0.1]
Jul 18 02:32:19 smicro postfix/qmgr[14374]: 8178CF41D65: from=<yyy@gmail.com>, size=2583, nrcpt=2 (queue active)
Jul 18 02:32:19 smicro amavis[18082]: (18082-12) FWD via SMTP: <yyy@gmail.com> -> <wwt@xxx.ru>,BODY=7BIT 250 2.0.0 Ok, id=18082-12, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 8178CF41D65
Jul 18 02:32:19 smicro amavis[18082]: (18082-12) Passed CLEAN, [209.85.216.172] [209.85.216.172] <yyy@gmail.com> -> <wwt@xxx.ru>, Message-ID: <CAPcZZRCMdpg7U2xAJVkPPjwBJuzXHYSFq6f8_CZjR-ezWAPPvA@mail.gmail.com>, mail_id: bN3Mz21r22x6, Hits: -1.311, size: 2162, queued_as: 8178CF41D65, dkim_id=@gmail.com, 15514 ms
Jul 18 02:32:19 smicro amavis[18082]: (18082-12) TIMING-SA total 14991 ms - parse: 1.20 (0.0%), extract_message_metadata: 3 (0.0%), get_uri_detail_list: 0.28 (0.0%), tests_pri_-1000: 146 (1.0%), tests_pri_-950: 0.91 (0.0%), tests_pri_-900: 0.93 (0.0%), tests_pri_-400: 1866 (12.4%), check_bayes: 1864 (12.4%), tests_pri_0: 3870 (25.8%), check_spf: 845 (5.6%), poll_dns_idle: 9896 (66.0%), check_dcc: 0.71 (0.0%), check_razor2: 2653 (17.7%), check_pyzor: 0.13 (0.0%), tests_pri_500: 9066 (60.5%), tests_pri_1000: 24 (0.2%), total_awl: 23 (0.2%), check_awl: 0.12 (0.0%), update_awl: 0.06 (0.0%), get_report: 0.90 (0.0%)
Jul 18 02:32:19 smicro postfix/smtp[19443]: 01726F41DF5: to=<wwt@xxx.ru>, relay=127.0.0.1[127.0.0.1]:10024, delay=16, delays=0.15/0/0/16, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=18082-12, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 8178CF41D65)
Jul 18 02:32:19 smicro postfix/qmgr[14374]: 01726F41DF5: removed
Jul 18 02:32:19 smicro amavis[18082]: (18082-12) TIMING [total 15611 ms] - SMTP greeting: 1 (0%)0, SMTP EHLO: 0 (0%)0, SMTP pre-MAIL: 0 (0%)0, SMTP pre-DATA-flush: 1 (0%)0, SMTP DATA: 45 (0%)0, check_init: 0(0%)0, digest_hdr: 2 (0%)0, digest_body_dkim: 144 (1%)1, gen_mail_id: 2 (0%)1, mime_decode: 7 (0%)1, get-file-type2: 155 (1%)2, parts_decode: 0 (0%)2, check_header: 1 (0%)2, AV-scan-1: 108 (1%)3, spam-wb-list: 1 (0%)3, SA parse: 2 (0%)3, SA check: 14987 (96%)99, update_cache: 4 (0%)99, decide_mail_destiny: 0 (0%)99, fwd-connect: 2 (0%)99, fwd-mail-pip: 4 (0%)99, fwd-rcpt-pip: 0 (0%)99, fwd-data-chkpnt: 0 (0%)99,write-header: 1 (0%)99, fwd-data-contents: 0 (0%)99, fwd-end-chkpnt: 40 (0%)99, prepare-dsn: 0 (0%)99, main_log_entry: 99 (1%)100, update_snmp: 1 (0%)100, SMTP pre-response: 0 (0%)100, SMTP response: 0 (0%)100, unlink-2-files: 0 (0%)100, rundown: 1 (0%)100
Jul 18 02:32:19 smicro postfix/pipe[19460]: 8178CF41D65: to=<kr@xxx.ru>, orig_to=<wwt@xxx.ru>, relay=dovecot, delay=0.27, delays=0.04/0/0/0.23, dsn=2.0.0, status=sent (delivered via dovecot service)
Jul 18 02:32:19 smicro postfix/pipe[19571]: 8178CF41D65: to=<ms@xxx.ru>, orig_to=<wwt@xxx.ru>, relay=dovecot, delay=0.37, delays=0.04/0.1/0/0.23, dsn=2.0.0, status=sent (delivered via dovecot service)
Jul 18 02:32:19 smicro postfix/qmgr[14374]: 8178CF41D65: removed

[dm07]

Можете показать, что происходит в логах Spamassassin'а (/var/log/spamassassin/spamd.log или где вы храните свой лог), когда вы шлете себе письмо?

[WWT]

Не вижу spamd.log, увы. Пытаюсь понять, пишется ли лог и где это настраивается.

[dm07]

Если SpamAsassin запускать с ключом -s /путь/к/логфайлу/spamd.log будет создан указанный лог-файл (либо создайте его вручную и пропишите на него права). Если у вас линукс (Убунту, к примеру), то все опции запуска можно прописать в /etc/default/spamassassin в директиве OPTIONS, либо смотрите скрипт запуска и там задайте ключ -s. Кроме того, вы можете включить дебаггинг, добавив ключ -D.

[WWT]

Спасибо, сейчас включу логирование.

[WWT]

Итак, добавил в /etc/default/spamassassin в OPTIONS -s /var/log/spamd.log -D

Перезапустил SA:

Код: Выделить всё

root@smicro:/etc/spamassassin# sudo /etc/init.d/spamassassin restart
Restarting SpamAssassin Mail Filter Daemon: июля 18 18:48:59.357 [3271] dbg: logger: adding facilities: all
июля 18 18:48:59.357 [3271] dbg: logger: logging level is DBG
июля 18 18:48:59.359 [3271] dbg: logger: successfully opened file /var/log/spamd.log
июля 18 18:48:59.359 [3271] dbg: logger: successfully added file method
июля 18 18:48:59.359 [3271] dbg: spamd: will perform setuids? 1
июля 18 18:48:59.359 [3271] dbg: spamd: creating INET socket:
июля 18 18:48:59.359 [3271] dbg: spamd: [...] Listen: 128
июля 18 18:48:59.359 [3271] dbg: spamd: [...] LocalAddr: 127.0.0.1
июля 18 18:48:59.359 [3271] dbg: spamd: [...] LocalPort: 783
июля 18 18:48:59.359 [3271] dbg: spamd: [...] Proto: 6
июля 18 18:48:59.359 [3271] dbg: spamd: [...] ReuseAddr: 1
июля 18 18:48:59.359 [3271] dbg: spamd: [...] Type: 1
июля 18 18:48:59.360 [3271] dbg: logger: adding facilities: all
июля 18 18:48:59.360 [3271] dbg: logger: logging level is DBG
июля 18 18:48:59.360 [3271] dbg: generic: SpamAssassin version 3.3.1
июля 18 18:48:59.360 [3271] dbg: generic: Perl 5.010001, PREFIX=/usr, DEF_RULES_DIR=/usr/share/spamassassin, LOCAL_RULES_DIR=/etc/spamassassin, LOCAL_STATE_DIR=/var/lib/spamassassin
июля 18 18:48:59.360 [3271] dbg: config: timing enabled
июля 18 18:48:59.361 [3271] dbg: config: score set 0 chosen.
июля 18 18:48:59.485 [3271] dbg: dns: is Net::DNS::Resolver available? yes
июля 18 18:48:59.485 [3271] dbg: dns: Net::DNS version: 0.66

Перепроверил правило /etc/spamassassin/90_wwtmasterhost.cf:

header WWT_TEST01 Subject =~ /qweeertSS/
score WWT_TEST01 5.9

Посмотрел в spamd.log, увидел что:

Wed Jul 18 18:48:59 2012 [3274] dbg: config: read file /etc/spamassassin/90_wwtmasterhost.cf

Ругани про этот файл нет, сделал spamassassin --lint, всё ок

Послал письмо с темой "qweeertSS"

В mail.log:

Код: Выделить всё

Jul 18 19:00:56 smicro postfix/smtpd[2470]: connect from smicro[127.0.0.1]
Jul 18 19:00:56 smicro postfix/smtpd[2470]: 27E1DF41E23: client=smicro[127.0.0.1]
Jul 18 19:00:56 smicro postfix/cleanup[3432]: 27E1DF41E23: message-id=<5006CF8C.1080408@aaa.ru>
Jul 18 19:00:56 smicro postfix/qmgr[14374]: 27E1DF41E23: from=<wwt@aaa.ru>, size=1699, nrcpt=2 (queue active)
Jul 18 19:00:56 smicro postfix/smtpd[2470]: disconnect from smicro[127.0.0.1]
Jul 18 19:00:56 smicro amavis[2825]: (02825-08) FWD via SMTP: <wwt@aaa.ru> -> <wwt@xxx.ru>,BODY=8BITMIME 250 2.0.0 Ok, id=02825-08, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 27E1DF41E23
Jul 18 19:00:56 smicro amavis[2825]: (02825-08) Passed CLEAN, [195.90.163.198] [109.252.202.142] <wwt@aaa.ru> -> <wwt@xxx.ru>, Message-ID: <5006CF8C.1080408@aaa.ru>, mail_id: HRKPW+bRswoS, Hits: 1.58, size: 1278, queued_as: 27E1DF41E23, 15556 ms
Jul 18 19:00:56 smicro amavis[2825]: (02825-08) TIMING-SA total 15293 ms - parse: 1.17 (0.0%), extract_message_metadata: 2 (0.0%), get_uri_detail_list: 0.34 (0.0%), tests_pri_-1000: 173 (1.1%), tests_pri_-950: 0.87 (0.0%), tests_pri_-900: 0.92 (0.0%), tests_pri_-400: 152 (1.0%), check_bayes: 151 (1.0%), tests_pri_0: 11087 (72.5%), check_dkim_adsp: 438 (2.9%), check_spf: 5332 (34.9%), poll_dns_idle: 8880 (58.1%),check_dcc: 111 (0.7%), check_razor2: 5001 (32.7%), check_pyzor: 0.13 (0.0%), tests_pri_500: 3555 (23.2%), tests_pri_1000: 26 (0.2%), total_awl: 25 (0.2%), check_awl: 0.12 (0.0%), update_awl: 0.06 (0.0%), learn: 279 (1.8%), get_report: 0.87 (0.0%)
Jul 18 19:00:56 smicro postfix/smtp[3618]: 984DCF41E43: to=<wwt@xxx.ru>, relay=127.0.0.1[127.0.0.1]:10024, delay=16, delays=0.12/0/0/16, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=02825-08, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 27E1DF41E23)
Jul 18 19:00:56 smicro postfix/qmgr[14374]: 984DCF41E43: removed
Jul 18 19:00:56 smicro amavis[2825]: (02825-08) TIMING [total 15559 ms] - SMTP greeting: 1 (0%)0, SMTP EHLO: 0 (0%)0, SMTP pre-MAIL: 0 (0%)0, SMTP pre-DATA-flush: 1 (0%)0, SMTP DATA: 35 (0%)0, check_init: 0 (0%)0, digest_hdr: 1 (0%)0, digest_body_dkim: 0 (0%)0, gen_mail_id: 1 (0%)0, mime_decode: 4 (0%)0, get-file-type1: 142 (1%)1, parts_decode: 0 (0%)1, check_header: 1 (0%)1, AV-scan-1: 1 (0%)1, spam-wb-list: 1 (0%)1, SA parse: 2 (0%)1, SA check: 15289 (98%)99, update_cache: 4 (0%)100, decide_mail_destiny: 0 (0%)100, fwd-connect: 2 (0%)100, fwd-mail-pip: 1 (0%)100, fwd-rcpt-pip: 0 (0%)100, fwd-data-chkpnt: 0 (0%)100, write-header: 1 (0%)100, fwd-data-contents: 0 (0%)100, fwd-end-chkpnt: 64 (0%)100, prepare-dsn: 0 (0%)100, main_log_entry: 4 (0%)100, update_snmp: 1 (0%)100, SMTP pre-response: 0 (0%)100, SMTP response: 0 (0%)100, unlink-1-files: 0 (0%)100, rundown: 0 (0%)100
Jul 18 19:00:56 smicro postfix/pipe[3776]: 27E1DF41E23: to=<kr@xxx.ru>, orig_to=<wwt@xxx.ru>, relay=dovecot, delay=0.36, delays=0.06/0.1/0/0.2, dsn=2.0.0, status=sent (delivered via dovecot service)
Jul 18 19:00:56 smicro postfix/pipe[3777]: 27E1DF41E23: to=<ms@xxx.ru>, orig_to=<wwt@xxx.ru>, relay=dovecot, delay=0.45, delays=0.06/0.2/0/0.18, dsn=2.0.0, status=sent (delivered via dovecot service)
Jul 18 19:00:56 smicro postfix/qmgr[14374]: 27E1DF41E23: removed

В spamd.log нет ничего в это время:

Код: Выделить всё

Wed Jul 18 18:59:07 2012 [3296] dbg: prefork: periodic ping from spamd parent
Wed Jul 18 18:59:07 2012 [3295] dbg: prefork: periodic ping from spamd parent
Wed Jul 18 18:59:07 2012 [3296] dbg: prefork: sysread(9) not ready, wait max 300 secs
Wed Jul 18 18:59:07 2012 [3295] dbg: prefork: sysread(7) not ready, wait max 300 secs
Wed Jul 18 19:01:39 2012 [3295] dbg: prefork: periodic ping from spamd parent
Wed Jul 18 19:01:39 2012 [3295] dbg: prefork: sysread(7) not ready, wait max 300 secs
Wed Jul 18 19:01:39 2012 [3296] dbg: prefork: periodic ping from spamd parent
Wed Jul 18 19:01:39 2012 [3296] dbg: prefork: sysread(9) not ready, wait max 300 secs
Wed Jul 18 19:04:10 2012 [3295] dbg: prefork: periodic ping from spamd parent
Wed Jul 18 19:04:10 2012 [3295] dbg: prefork: sysread(7) not ready, wait max 300 secs
Wed Jul 18 19:04:10 2012 [3296] dbg: prefork: periodic ping from spamd parent
Wed Jul 18 19:04:10 2012 [3296] dbg: prefork: sysread(9) not ready, wait max 300 secs

Чтож ему надо то?

[dm07]

Т.е. ваш postfix не вызывает SpamAssassin в момент обработки письма, верно (поскольку в spamd.log вы не видите никаких изменений)? Значит, нужно проштрудировать конфиг постфикса на тему связки с SpamAssassin. Еще: в логе spamd не должно быть вот этого:

Код: Выделить всё

Wed Jul 18 19:04:10 2012 [3296] dbg: prefork: periodic ping from spamd parent
Wed Jul 18 19:04:10 2012 [3296] dbg: prefork: sysread(9) not ready, wait max 300 secs

[WWT]

Дык вызывает, только не postfix, а amavis, насколько я вижу.
Письма в спам валятся:

Код: Выделить всё

X-Spam-Status: Yes, score=10.642-5 tag=-1 tag2=5.5 kill=5.5
	tests=[AM:BOOST=-5, BAYES_50=0.8, DATE_IN_PAST_06_12=1.543,
	HK_RANDOM_REPLYTO=0.999, HTML_MESSAGE=0.001,
	RCVD_IN_BL_SPAMCOP_NET=1.347, RCVD_IN_BRBL_LASTEXT=1.449,
	RCVD_IN_PBL=3.335, RCVD_IN_XBL=0.375, RDNS_NONE=0.793,
	SPF_PASS=-0.001, UNPARSEABLE_RELAY=0.001] autolearn=spam