How to install and integrate SpamAssassin with Postfix on a CentOS 6 VPS

Leave reply

spamassassinThe following article is part 4 of our mailserver set-up with virtual users and domains using Postfix and Dovecot on a CentOS 6 VPS, followed by part 2 which explains how to install and set-up the Roundcube webmail interface on a linux vps server and then part 3 which is all about how to set-up an SSL encrypted connection in Postfix, Dovecot and Apache using SSL certificates.

In this tutorial we are going to set-up SpamAssassin on one of our CentOS 6 linux virtual servers and integrate it into our Postfix mailserver set-up so it can scan and mark the emails detected as SPAM.

What is SpamAssassin?

It is a program released under the Apache License 2.0 used for e-mail spam filtering based on content-matching rules.

UPDATE THE SYSTEM

As usual, make sure your CentOS 6 linux vps is fully up to date by executing:

## screen -U -S spamc-screen
## yum update

INSTALL SPAMASSASSIN

Install the SpamAssassin package using yum by running:

## yum install spamassassin

SET-UP USER

create spamfilter group used for the user that will run the spamassassin service

## groupadd spamfilter

create new user spamfilter with a home directory of /usr/local/spamassassin and add it to the spamfilter group you just created

## useradd -g spamfilter -s /bin/false -d /usr/local/spamassassin spamfilter
## chown spamfilter: /usr/local/spamassassin

CONFIGURE SPAMASSASSIN

next, configure spamassassin by editing /etc/mail/spamassassin/local.cf and adding/setting the following

## vim /etc/mail/spamassassin/local.cf

## Required_hits: This determines the filter balance; the lower the score the more aggressive the filter.
# A setting of 5.0 is generally effective for a small organisation or a single user.
# Adjust the strictness score to your organization's needs - a large medical organisation might want  to let email items
# through that are trying to sell pharmaceuticals, so we might increase the level to a more modest 8.0.
required_hits 5
## Report_safe:  This line determines whether to delete the item or to move the item to the inbox whilst appending
# a spam notice to the subject line. The levels for this line are set to either a 1 or 0. A score of 1 will delete the spam item,
# whereas a score of 0 will send the item to the inbox and rewrite the subject line.
report_safe 0
rewrite_header Subject [**SPAM**]
## Required_score: This line sets the spam score for all email alllowed through to your domain, with levels of certainty set from 0 to 5.
# Zero would be classified as a legitimate email item, whereas 5 would be an definite 'SPAM' item.  If we set the score to 3 we would catch a
# lot of unsolicited emails but quite a few false positives would still get through. For our example email server we will use the score of 5,
# but you can of course set this value according to your preference.
required_score 5.0

before we proceed with starting-up the spamassassin service, we need to make sure it runs with our newly created spamfilter user by editing /etc/sysconfig/spamassassin and setting-up the following:

## vim /etc/sysconfig/spamassassin

# Options to spamd
SAHOME="/usr/local/spamassassin"
SPID_DIR="/var/run/spamassassin"
SUSER="spamfilter"
SPAMDOPTIONS="-d -c -m5 --username ${SUSER} -H ${SAHOME} -s ${SAHOME}/spamfilter.log"

with all that in place, we are ready to start and enable the spamassassin service on system startup using:

## service spamassassin start
## chkconfig spamassassin on

CONFIGURE POSTFIX

next thing you need to do is to actually integrate spamassassin into postfix so it can scan and mark the emails that were detected as SPAM. To achieve this we need to edit postfix configuration file. Edit master.cf:

## vim /etc/postfix/master.cf

and add/edit the following lines:

smtp      inet  n       -       n       -       -       smtpd -o content_filter=spamassassin
spamassassin unix -     n       n       -       -       pipe user=spamfilter argv=/usr/bin/spamc -f -e  /usr/sbin/sendmail -oi -f ${sender} ${recipient}

then, restart postfix for the changes to take effect

## service postfix restart

TEST THE SET-UP

To test if SpamAssassin actually works, you can simply send an email with subject XJS*C4JDBQADN1.NSBN3*2IDNEN*GTUBE-STANDARD-ANTI-UBE-TEST-EMAIL*C.34X to some of your email accounts and once the email is received, check it’s headers and you should notice something like this:

X-Spam-Flag: YES
X-Spam-Level: **************************************************
X-Spam-Status: Yes, score=1000.0 required=5.0 tests=GTUBE,RCVD_IN_DNSWL_NONE,
    TVD_SPACE_RATIO autolearn=no version=3.3.1
....

This means that SpamAssassin is doing it’s job.


Implementing SpamAssassin to the mailserver set-up with virtual users and domains using Postfix and Dovecot adds another nice feature to the mail server set-up.

However, there are still other parts missing like digital signatures using opendkim, dovecot sieve filter rules, virus scanning etc for a full-featured mail server. In the next few related articles, we will be adding additional features to the set-up so stay tuned.

Update: Part 5 – How to install and integrate OpenDKIM with Postfix on a CentOS 6 VPS

Update: Part 6 – How to set-up server-side email filtering with Dovecot Sieve and Roundcube on a CentOS 6 VPS


Of course, if you are one of our Linux VPS Hosting customers, you don’t have to do any of this, simply ask our admins, sit back and relax. Our admins will set this up for you immediately.

PS. If you liked this post please share it with your friends on the social networks using the buttons on the left or simply leave a reply below. Thanks.

12 Responses to “How to install and integrate SpamAssassin with Postfix on a CentOS 6 VPS”

  1. Set-up SSL encrypted connection in Postfix, Dovecot and Apache | RoseHosting.com Linux VPS Hosting Blog

    […] Update: Part 4 – How to install and integrate SpamAssassin with Postfix on a CentOS 6 VPS […]

    Reply
  2. el_condor

    and spamassassin with procmail ????

    Reply
    • admin

      hi el_condor,

      this set-up uses dovecot and sieve rules, not procmail. anyway, we will consider writing an article using spamassassin in combination with procmail in the near future. you can subscribe to our newsletter at http://www.rosehosting.com/blog/ so you don’t miss any future posts.

      thanks

      Reply
  3. Max

    Hey,

    I tried following your instructions, but something is going wrong.
    When i send the test mail, It seems to be going lost somewhere and there is nothing in the /usr/local/spamassassin direcotry (no log).

    Any idea?

    Reply
  4. Max

    I’ve checked, it’s empty.

    But shouldn’t it be sent to spamassassin first? Or am I missing something here?

    Reply
    • admin

      In order to investigate and fix your problem, you could increase the level of verbose logging in Postfix. For example, you may append the ‘-v’ option that is passed to the smtpd when it is started:

      vi /etc/postfix/master.cf

      (search for smtpd and append ‘-v’)

      smtp inet n – n – – smtpd -v

      Do not forget to execute ‘/etc/init.d/postfix reload’ for the changes to take effect.

      Make sure your syslogd service is setup to log stuff to /var/log/maillog, like following:

      grep ^mail /etc/rsyslog.conf
      mail.* -/var/log/maillog

      Also, make sure it is up and running:

      service rsyslog status
      rsyslogd (pid 19563) is running…

      Reply
      • Max

        Below is the verbose logging when I send the test mail as above from my_account@hotmail.com to my.account@my.domain.

        I’ve checked and rsyslogd is running, I’ve reloaded postfix service after every change.

        Jun 2 12:37:08 353918 postfix/smtpd[32683]: name_mask: all
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: inet_addr_local: configured 2 IPv4 addresses
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: inet_addr_local: configured 2 IPv6 addresses
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: process generation: 4360 (4360)
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: mynetworks ~? debug_peer_list
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: mynetworks ~? fast_flush_domains
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: mynetworks ~? mynetworks
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: relay_domains ~? debug_peer_list
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: relay_domains ~? fast_flush_domains
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: relay_domains ~? mynetworks
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: relay_domains ~? permit_mx_backup_networks
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: relay_domains ~? qmqpd_authorized_clients
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: relay_domains ~? relay_domains
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: permit_mx_backup_networks ~? debug_peer_list
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: permit_mx_backup_networks ~? fast_flush_domains
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: permit_mx_backup_networks ~? mynetworks
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: permit_mx_backup_networks ~? permit_mx_backup_networks
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: connect to subsystem private/proxymap
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: send attr request = open
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: send attr table = unix:passwd.byname
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: send attr flags = 16448
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/proxymap socket: wanted attribute: status
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: status
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute value: 0
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/proxymap socket: wanted attribute: flags
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: flags
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute value: 16464
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/proxymap socket: wanted attribute: (list terminator)
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: (end)
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: dict_proxy_open: connect to map=unix:passwd.byname status=0 server_flags=fixed|lock|fold_fix
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: dict_open: proxy:unix:passwd.byname
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: Compiled against Berkeley DB: 4.7.25?
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: Run-time linked against Berkeley DB: 4.7.25?
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: dict_open: hash:/etc/aliases
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: Compiled against Berkeley DB: 4.7.25?
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: Run-time linked against Berkeley DB: 4.7.25?
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: dict_open: hash:/var/spool/postfix/plesk/aliases
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: Compiled against Berkeley DB: 4.7.25?
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: Run-time linked against Berkeley DB: 4.7.25?
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: dict_open: hash:/var/spool/postfix/plesk/virtual
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: Compiled against Berkeley DB: 4.7.25?
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: Run-time linked against Berkeley DB: 4.7.25?
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: dict_open: hash:/var/spool/postfix/plesk/vmailbox
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: smtpd_access_maps ~? debug_peer_list
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: smtpd_access_maps ~? fast_flush_domains
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: smtpd_access_maps ~? mynetworks
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: smtpd_access_maps ~? permit_mx_backup_networks
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: smtpd_access_maps ~? qmqpd_authorized_clients
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: smtpd_access_maps ~? relay_domains
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: smtpd_access_maps ~? smtpd_access_maps
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: Compiled against Berkeley DB: 4.7.25?
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: Run-time linked against Berkeley DB: 4.7.25?
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: dict_open: hash:/var/spool/postfix/plesk/blacklists
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: dict_open: pcre:/var/spool/postfix/plesk/non_auth.re
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: dict_open: pcre:/var/spool/postfix/plesk/no_relay.re
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: unknown_helo_hostname_tempfail_action = defer_if_permit
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: unknown_address_tempfail_action = defer_if_permit
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: unverified_recipient_tempfail_action = defer_if_permit
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: unverified_sender_tempfail_action = defer_if_permit
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: xsasl_cyrus_server_init: SASL config file is smtpd.conf
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: auto_clnt_create: transport=local endpoint=private/tlsmgr
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: auto_clnt_open: connected to private/tlsmgr
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: send attr request = seed
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: send attr size = 32
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/tlsmgr: wanted attribute: status
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: status
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute value: 0
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/tlsmgr: wanted attribute: seed
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: seed
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute value: ofqzimL3tQvD5JG05xsApvk9mamQuoFxlYYfb88f6DU=
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/tlsmgr: wanted attribute: (list terminator)
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: (end)
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: name_mask: CVE-2005-2969
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: name_mask: CVE-2010-4180
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: send attr request = policy
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: send attr cache_type = smtpd
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/tlsmgr: wanted attribute: status
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: status
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute value: 0
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/tlsmgr: wanted attribute: cachable
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: cachable
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute value: 0
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/tlsmgr: wanted attribute: (list terminator)
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: (end)
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: fast_flush_domains ~? debug_peer_list
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_string: fast_flush_domains ~? fast_flush_domains
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: auto_clnt_create: transport=local endpoint=private/anvil
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: connection established
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: master_notify: status 0
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: name_mask: resource
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: name_mask: software
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: connect from col004-omc4s9.hotmail.com[65.55.34.211]
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_list_match: col004-omc4s9.hotmail.com: no match
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_list_match: 65.55.34.211: no match
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_hostname: col004-omc4s9.hotmail.com ~? 127.0.0.0/8
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_hostaddr: 65.55.34.211 ~? 127.0.0.0/8
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_hostname: col004-omc4s9.hotmail.com ~? [::1]/128
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_hostaddr: 65.55.34.211 ~? [::1]/128
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_list_match: col004-omc4s9.hotmail.com: no match
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_list_match: 65.55.34.211: no match
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_hostname: col004-omc4s9.hotmail.com ~? 127.0.0.0/8
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_hostaddr: 65.55.34.211 ~? 127.0.0.0/8
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_hostname: col004-omc4s9.hotmail.com ~? [::1]/128
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_hostaddr: 65.55.34.211 ~? [::1]/128
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_hostname: col004-omc4s9.hotmail.com ~? my.ip/32
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_hostaddr: 65.55.34.211 ~? my.ip/32
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_list_match: col004-omc4s9.hotmail.com: no match
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_list_match: 65.55.34.211: no match
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: auto_clnt_open: connected to private/anvil
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: send attr request = connect
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: send attr ident = smtp:65.55.34.211
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/anvil: wanted attribute: status
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: status
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute value: 0
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/anvil: wanted attribute: count
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: count
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute value: 1
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/anvil: wanted attribute: rate
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: rate
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute value: 1
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/anvil: wanted attribute: (list terminator)
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: (end)
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: report connect to all milters
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter_macro_lookup: “j”
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter_macro_lookup: result “my.vps.name”
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter_macro_lookup: “{daemon_name}”
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter_macro_lookup: result “my.vps.name”
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter_macro_lookup: “v”
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter_macro_lookup: result “Postfix 2.8.14″
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter8_connect: non-protocol events for protocol version 6:
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter8_connect: transport=inet endpoint=127.0.0.1:12768
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: trying… [127.0.0.1]
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: vstream_tweak_tcp: TCP_MAXSEG 16384
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter8_connect: my_version=0×6
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter8_connect: my_actions=0x1ff SMFIF_ADDHDRS SMFIF_CHGBODY SMFIF_ADDRCPT SMFIF_DELRCPT SMFIF_CHGHDRS SMFIF_QUARANTINE SMFIF_CHGFROM SMFIF_ADDRCPT_PAR SMFIF_SETSYMLIST
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter8_connect: my_events=0x1fffff SMFIP_NOCONNECT SMFIP_NOHELO SMFIP_NOMAIL SMFIP_NORCPT SMFIP_NOBODY SMFIP_NOHDRS SMFIP_NOEOH SMFIP_NR_HDR SMFIP_NOUNKNOWN SMFIP_NODATA SMFIP_SKIP SMFIP_RCPT_REJ SMFIP_NR_CONN SMFIP_NR_HELO SMFIP_NR_MAIL SMFIP_NR_RCPT SMFIP_NR_DATA SMFIP_NR_UNKN SMFIP_NR_EOH SMFIP_NR_BODY SMFIP_HDR_LEADSPC
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter8_connect: milter inet:127.0.0.1:12768 version 6
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter8_connect: events SMFIP_NOUNKNOWN
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter8_connect: requests SMFIF_ADDHDRS SMFIF_CHGBODY SMFIF_CHGHDRS
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter8_conn_event: milter inet:127.0.0.1:12768: connect col004-omc4s9.hotmail.com/65.55.34.211
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: event: SMFIC_CONNECT; macros: j=my.vps.name {daemon_name}=my.vps.name v=Postfix 2.8.14
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: reply: SMFIR_CONTINUE data 0 bytes
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: > col004-omc4s9.hotmail.com[65.55.34.211]: 220 my.vps.name ESMTP Postfix
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: xsasl_cyrus_server_create: SASL service=smtp, realm=(null)
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: name_mask: noanonymous
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: col004-omc4s9.hotmail.com[65.55.34.211]: 250-my.vps.name
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: > col004-omc4s9.hotmail.com[65.55.34.211]: 250-PIPELINING
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: > col004-omc4s9.hotmail.com[65.55.34.211]: 250-SIZE 1024000000
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: > col004-omc4s9.hotmail.com[65.55.34.211]: 250-ETRN
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: > col004-omc4s9.hotmail.com[65.55.34.211]: 250-STARTTLS
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_list_match: col004-omc4s9.hotmail.com: no match
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: match_list_match: 65.55.34.211: no match
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: > col004-omc4s9.hotmail.com[65.55.34.211]: 250-AUTH PLAIN CRAM-MD5 DIGEST-MD5 LOGIN
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: > col004-omc4s9.hotmail.com[65.55.34.211]: 250-ENHANCEDSTATUSCODES
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: > col004-omc4s9.hotmail.com[65.55.34.211]: 250-8BITMIME
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: > col004-omc4s9.hotmail.com[65.55.34.211]: 250 DSN
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: col004-omc4s9.hotmail.com[65.55.34.211]: 220 2.0.0 Ready to start TLS
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: abort all milters
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: milter8_abort: abort milter inet:127.0.0.1:12768
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: send attr request = seed
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: send attr size = 32
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/tlsmgr: wanted attribute: status
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: status
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute value: 0
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/tlsmgr: wanted attribute: seed
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: seed
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute value: uwJpYA+Xj2HMg/nlSNH4Tb8LA2xdqO35B4zkzFh+nYA=
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: private/tlsmgr: wanted attribute: (list terminator)
        Jun 2 12:37:08 353918 postfix/smtpd[32683]: input attribute name: (end)
        Jun 2 12:37:09 353918 postfix/smtpd[32683]: xsasl_cyrus_server_create: SASL service=smtp, realm=(null)
        Jun 2 12:37:09 353918 postfix/smtpd[32683]: name_mask: noanonymous
        Jun 2 12:37:09 353918 postfix/smtpd[32683]: col004-omc4s9.hotmail.com[65.55.34.211]: 250-my.vps.name
        Jun 2 12:37:09 353918 postfix/smtpd[32683]: > col004-omc4s9.hotmail.com[65.55.34.211]: 250-PIPELINING
        Jun 2 12:37:10 353918 postfix/cleanup[32689]: A1532120CE2: message-id=
        Jun 2 12:37:10 353918 /usr/lib64/plesk-9.0/psa-pc-remote[7568]: handlers_stderr: SKIP
        Jun 2 12:37:10 353918 /usr/lib64/plesk-9.0/psa-pc-remote[7568]: SKIP during call ‘check-quota’ handler
        Jun 2 12:37:10 353918 qmail-queue[32691]: dwlib: fd: connect() failed – Connection refused
        Jun 2 12:37:10 353918 qmail-queue[32691]: dwlib: tcp: connecting to 127.0.0.1:3000 – failed
        Jun 2 12:37:10 353918 qmail-queue[32691]: dwlib: cannot create connection with a DrWeb daemon
        Jun 2 12:37:10 353918 /usr/lib64/plesk-9.0/psa-pc-remote[7568]: handlers_stderr: SKIP
        Jun 2 12:37:10 353918 /usr/lib64/plesk-9.0/psa-pc-remote[7568]: SKIP during call ‘drweb’ handler
        Jun 2 12:37:10 353918 postfix/qmgr[32616]: A1532120CE2: from=, size=1657, nrcpt=1 (queue active)
        Jun 2 12:37:10 353918 spamd[16194]: spamd: connection from my.vps.name [127.0.0.1] at port 57223
        Jun 2 12:37:11 353918 spamd[16194]: spamd: processing message for spamfilter:30
        Jun 2 12:37:14 353918 spamd[16194]: spamd: identified spam (1000.0/5.0) for spamfilter:30 in 3.5 seconds, 1590 bytes.
        Jun 2 12:37:14 353918 spamd[16194]: spamd: result: Y 1000 – FREEMAIL_FROM,GTUBE,HTML_MESSAGE,RCVD_IN_DNSWL_NONE scantime=3.5,size=1590,user=spamfilter,uid=30,required_score=5.0,rhost=my.vps.name,raddr=127.0.0.1,rport=57223,mid=,autolearn=no
        Jun 2 12:37:14 353918 postfix/pickup[32615]: 5B4EE1210CC: uid=10005 from=
        Jun 2 12:37:14 353918 postfix/pipe[32692]: A1532120CE2: to=, relay=spamassassin, delay=4.9, delays=0.8/0.04/0/4.1, dsn=2.0.0, status=sent (delivered via spamassassin service)
        Jun 2 12:37:14 353918 postfix/qmgr[32616]: A1532120CE2: removed
        Jun 2 12:37:14 353918 postfix/cleanup[32689]: 5B4EE1210CC: message-id=
        Jun 2 12:37:14 353918 postfix/qmgr[32616]: 5B4EE1210CC: from=, size=2582, nrcpt=1 (queue active)
        Jun 2 12:37:14 353918 postfix-local[32703]: postfix-local: from=my_account@hotmail.com, to=my.account@my.domain, dirname=/var/qmail/mailnames
        Jun 2 12:37:14 353918 postfix/smtpd[32683]: rewrite stream disconnect
        Jun 2 12:37:14 353918 spamd[29043]: spamd: connection from my.vps.name [127.0.0.1] at port 57254
        Jun 2 12:37:15 353918 spamd[29043]: spamd: processing message for my.account@my.domain:30
        Jun 2 12:37:15 353918 spamd[18097]: prefork: child states: IB
        Jun 2 12:37:16 353918 spamd[29043]: spamd: identified spam (1001.0/5.0) for my.account@my.domain:30 in 1.9 seconds, 2610 bytes.
        Jun 2 12:37:16 353918 spamd[29043]: spamd: result: Y 1000 – FREEMAIL_FROM,GTUBE,HTML_MESSAGE,RCVD_IN_DNSWL_NONE,RP_MATCHES_RCVD,SUBJ_ALL_CAPS scantime=1.9,size=2610,user=my.account@my.domain,uid=30,required_score=5.0,rhost=my.vps.name,raddr=127.0.0.1,rport=57254,mid=,autolearn=no
        Jun 2 12:37:16 353918 spamd[18097]: prefork: child states: II
        Jun 2 12:37:16 353918 postfix-local[32703]: handlers_stderr: STOP
        Jun 2 12:37:16 353918 postfix-local[32703]: STOP during call ‘spam’ handler
        Jun 2 12:37:16 353918 postfix-local[32703]: message discarded by a mail handler
        Jun 2 12:37:16 353918 postfix/pipe[32702]: 5B4EE1210CC: to=, relay=plesk_virtual, delay=2.3, delays=0.03/0.03/0/2.2, dsn=2.0.0, status=sent (delivered via plesk_virtual service)
        Jun 2 12:37:16 353918 postfix/qmgr[32616]: 5B4EE1210CC: removed

        Reply
        • admin

          We cannot reproduce this issue. Are you sure you are running the latest CentOS 6 and postfix ?

          Reply
          • Max

            I’ve just checked, this is the output:

            cat /etc/*release*
            CentOS release 6.5 (Final)
            CentOS release 6.5 (Final)
            CentOS release 6.5 (Final)
            cpe:/o:centos:linux:6:GA

            postconf -d |grep mail_version
            mail_version = 2.8.14
            milter_macro_v = $mail_name $mail_version

          • Max

            Hey,

            I’ve made some progress. When I send a mail, I do get the following into my spamfilter.log:
            Mon Jun 9 11:21:02 2014 [27243] info: spamd: connection from myVPS.com [127.0.0.1] at port 60255
            Mon Jun 9 11:21:02 2014 [27243] info: spamd: processing message for spamfilter:10005
            Mon Jun 9 11:21:02 2014 [27243] info: spamd: identified spam (1000.0/5.0) for spamfilter:10005 in 0.3 seconds, 1561 bytes.
            Mon Jun 9 11:21:02 2014 [27243] info: spamd: result: Y 1000 – FREEMAIL_FROM,GTUBE,HTML_MESSAGE,RCVD_IN_DNSWL_NONE,TVD_SPACE_RATIO scantime=0.3,size=1561,user=spamfilter,uid=10005,required_score=5.0,rhost=myVPS.com,raddr=127.0.0.1,rport=60255,mid=,autolearn=no
            Mon Jun 9 11:21:02 2014 [27242] info: prefork: child states: II
            Mon Jun 9 11:21:02 2014 [27243] info: spamd: connection from myVPS.com [127.0.0.1] at port 60257
            Mon Jun 9 11:21:02 2014 [27243] info: spamd: handle_user unable to find user: ‘myaccount@mydomain’
            Mon Jun 9 11:21:02 2014 [27243] info: spamd: processing message for myaccount@mydomain:10005
            Mon Jun 9 11:21:02 2014 [27243] info: spamd: identified spam (1001.0/5.0) for myaccount@mydomain:10005 in 0.1 seconds, 2638 bytes.
            Mon Jun 9 11:21:02 2014 [27243] info: spamd: result: Y 1000 – FREEMAIL_FROM,GTUBE,HTML_MESSAGE,RCVD_IN_DNSWL_NONE,RP_MATCHES_RCVD,SUBJ_ALL_CAPS,TVD_SPACE_RATIO scantime=0.1,size=2638,user=myaccount@mydomain,uid=10005,required_score=5.0,rhost=myVPS.com,raddr=127.0.0.1,rport=60257,mid=,autolearn=no
            Mon Jun 9 11:21:02 2014 [27242] info: prefork: child states: II

            Any idea?

          • admin

            Most likely there is no such ‘myaccount@mydomain’ email account on your server.

Leave a Reply