I am using Postfix and have noticed vast numbers of messages like this one lately: Code: postfix/smtpd[20961]: NOQUEUE: reject: RCPT from some-host.example.com[1.2.3.4]: 554 5.7.1 <[email protected]>: Relay access denied; from=<[email protected]> to=<user@domain2> proto=ESMTP helo=<[169.254.97.163]> This results from automated "bots" attempting to hammer mail through this server (even though relaying is not allowed). I find this annoying. Is there some way to drop the connection immediately if the user-agent has not authenticated? I don't want anybody sending mail through this server who isn't authenticated, unless the connection is coming from 127.0.0.1. Everyone else can simply be disconnected immediately. This must be possible in Postfix. Any help is greatly appreciated. P.S. Yes, I have searched on this subject, but, unfortunately, almost all of the resources returned relate to people who are receiving "relay access denied" erroneously when trying to send legitimate mail themselves.
Just looking for some help here, folks. Apparently, someone has managed to exploit Postfix on this server and the mail queue keeps filling-up with entries like this: Code: 856BD22A97B9* 1202 Fri May 24 10:19:53 [email protected] [email protected] [email protected] where [email protected] is a "fake" email address (the lgvuwak appears to be randomly-generated with each mail sent, and example.com is an actual, legitimate domain whose mail services are hosted on this server). How is Postfix being exploited and how is this happening? All the reading I've done indicates that this mail is coming from 127.0.0.1, which is why Postfix allows the mail to be sent (instead of refusing with "relay access denied"). This fact seems consistent with the headers in the queued messages. Here are the contents of one such message: http://pastebin.com/7aTrsdxL While this is occurring, I see a lot of activity from external IP addresses when this queue flooding is happening. These IP addresses appear to be Hotmail's. Here's an excerpt: Code: May 24 10:35:18 serverds postfix/qmgr[885]: 9E7A822A68B5: from=<[email protected]>, size=1586, nrcpt=2 (queue active) May 24 10:35:18 serverds postfix/error[23964]: 9ED8322A52CB: to=<[email protected]>, relay=none, delay=4652, delays=4652/0.02/0/0.01, dsn=4.4.2, status=deferred (delivery temporarily suspended: lost connection with mx1.hotmail.com[65.55.92.168] while sending RCPT TO) The only way I've been able to stop this is to add drop rules for Hotmail's IP addresses to iptables. I need to uncover the root source of this exploitation. The most likely source of mail being sent from 127.0.0.1 seems to be a compromised Web application or site. We host a couple of WordPress sites on this server, and they seem to be the most likely culprit. Where should I start looking? top/htop doesn't give any clues. All I see his heavy amavis activity. All of the sites on this server run PHP in Fast-CGI mode, with SuExec enabled, so, CPU activity attributable to PHP appears as a unique process in top. But, I don't see particularly heavy CPU activity for any particular website. Thanks in advance for any help! P.S. I realize that implementing what I describe in my initial post won't stop this exploitation, if it is in fact coming from a compromised website, but I would still like to know how it's done.
check the mail contents of one or more of these mails in the deferred queue with the postcat command. Most likely you will see in themail headers which website has inserted them in the mailqueue.
Thanks for the quick reply, Till. I really appreciate your help. I did think to inspect the message headers for some evidence of "X-Mailer: PHP" or similar, and I see no evidence whatsoever of PHP in the message headers. (I do realize that this observation does not necessarily mean that the messages were not sent with PHP.) When I first noticed this, I saw one website (PHP process) in particular with higher-than-normal CPU usage. I placed "sendmail_path = /dev/null" in that site's "Custom php.ini settings" field and the problem seemed to stop. I didn't see any further activity for a couple of days. But I wasn't satisfied with "hoping" that the problem was resolved. Also, I can't have PHP mail capability disabled for the vhost in question in the long-term. In effort to confirm that the problem was in fact coming from this one vhost, I removed the sendmail_path override to see if the problem recurred. The problem did not recur immediately. But after a few days, I returned to find 8000 emails in the deferred queue. The problem is that once those emails are in the deferred queue, a lot of the activity that I see in mail.log seems related to Postfix trying to re-send those messages, which creates a cascading effect and way too much log traffic to sift through without a meaningful strategy. I have been clearing the queue of all messages with recipients @hotmail.com each time this happens. I am doing this because Hotmail is blacklisting my server due to the abuse, and I have legitimate clients who need to be able to send mail to @hotmail.com recipients. I want to drop-off Hotmail's blacklist as soon as possible. I have again removed "sendmail_path = /dev/null" from the suspect vhost. I guess I'll wait to see if the problem occurs a third time. And this time, I'll try to capture a large sample of messages from the deferred queue before I clear it. Thanks again. I'm all ears if you have any other ideas.
Well, these guys are at it again, filling my mail queue with outgoing spam to Hotmail addresses. I still see no real evidence of a compromised Web application here. It's possible that someone has found a way to exploit a "Contact Us" email form, but I would expect some evidence of PHP in the mail headers if that were the case. Also, I'm no longer convinced that this mail is coming from localhost; it seems to be originating elsewhere. I thought it was coming from localhost, but upon closer inspection, the localhost connections in the logs seem to be to amavis-new, not from the sending agent. I've done my best to capture the mail.log entries for one single sending attempt. In this snippet, example2.com is the server's FQDN, and example.com is one of my legitimate domains on the same server. Notice that the spammer's external IP address (or a proxy, etc.) appears in the log entries: 189.84.21.206. I have added this entire block to iptables for now. Code: May 28 06:30:01 example2 amavis[21173]: (21173-12-9) ESMTP::10024 /var/lib/amavis/tmp/amavis-20130528T062825-21173: <[email protected]> -> <[email protected]>,<[email protected]> SIZE=1348 Received: from example2.com ([127.0.0.1]) by localhost (example2.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP; Tue, 28 May 2013 06:30:01 -0700 (PDT) May 28 06:30:01 example2 amavis[21173]: (21173-12-9) Checking: AodNAbQyfJVE [189.84.21.206] <[email protected]> -> <[email protected]>,<[email protected]> May 28 06:30:01 example2 amavis[21173]: (21173-12-9) Open relay? Nonlocal recips but not originating: [email protected], [email protected] May 28 06:30:01 example2 amavis[21173]: (21173-12-9) cached bb4750473febfc3a2c5e49a67135b953 from <[email protected]> (0,1) May 28 06:30:01 example2 amavis[21173]: (21173-12-9) p001 1 Content-Type: text/plain, size: 912 B, name: May 28 06:30:01 example2 postfix/smtpd[12536]: A163122A43E6: client=localhost.localdomain[127.0.0.1] May 28 06:30:01 example2 postfix/cleanup[21166]: A163122A43E6: message-id=<[email protected]> May 28 06:30:01 example2 postfix/qmgr[32248]: A163122A43E6: from=<[email protected]>, size=1741, nrcpt=2 (queue active) May 28 06:30:01 example2 amavis[21173]: (21173-12-9) FWD via SMTP: <[email protected]> -> <[email protected]>,<[email protected]>, 250 2.0.0 Ok, id=21173-12-9, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as A163122A43E6 May 28 06:30:01 example2 amavis[21173]: (21173-12-9) Passed CLEAN, [189.84.21.206] [189.84.21.206] <[email protected]> -> <[email protected]>,<[email protected]>, mail_id: AodNAbQyfJVE, Hits: 21.996, size: 1348, queued_as: A163122A43E6, 124 ms May 28 06:30:01 example2 postfix/smtp[21338]: 84D7022A43E9: to=<[email protected]>, relay=127.0.0.1[127.0.0.1]:10024, conn_use=9, delay=9.7, delays=1.9/7.7/0/0.13, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=21173-12-9, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as A163122A43E6) May 28 06:30:01 example2 postfix/smtp[21338]: 84D7022A43E9: to=<[email protected]>, relay=127.0.0.1[127.0.0.1]:10024, conn_use=9, delay=9.7, delays=1.9/7.7/0/0.13, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=21173-12-9, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as A163122A43E6) May 28 06:30:01 example2 postfix/qmgr[32248]: 84D7022A43E9: removed May 28 06:30:01 example2 postfix/error[21283]: A163122A43E6: to=<[email protected]>, relay=none, delay=0.04, delays=0.03/0.01/0/0, dsn=4.4.2, status=deferred (delivery temporarily suspended: lost connection with mx3.hotmail.com[65.54.188.94] while sending RCPT TO) May 28 06:30:01 example2 amavis[21173]: (21173-12-9) TIMING [total 130 ms] - lookup_sql: 4 (3%)3, lookup_sql: 3 (2%)5, SMTP pre-DATA-flush: 1 (1%)6, SMTP DATA: 32 (25%)30, check_init: 1 (1%)31, digest_hdr: 1 (1%)32, digest_body_dkim: 1 (0%)33, gen_mail_id: 1 (1%)34, mime_decode: 11 (8%)42, get-file-type1: 20 (15%)57, parts_decode: 0 (0%)57, check_header: 2 (1%)59, spam-wb-list: 3 (3%)61, update_cache: 1 (1%)62, decide_mail_destiny: 2 (1%)63, fwd-connect: 4 (3%)66, fwd-mail-pip: 14 (10%)77, fwd-rcpt-pip: 1 (1%)78, fwd-data-chkpnt: 3 (3%)80, write-header: 1 (1%)81, fwd-data-contents: 0 (0%)81, fwd-end-chkpnt: 10 (7%)89, prepare-dsn: 1 (1%)89, main_log_entry: 9 (7%)97, update_snmp: 2 (2%)99, SMTP pre-response: 0 (0%)99, SMTP response: 1 (0%)99, unlink-1-files: 0 (0%)99, rundown: 1 (1%)100 May 28 06:30:01 example2 postfix/error[21283]: A163122A43E6: to=<[email protected]>, relay=none, delay=0.04, delays=0.03/0.01/0/0, dsn=4.4.2, status=deferred (delivery temporarily suspended: lost connection with mx3.hotmail.com[65.54.188.94] while sending RCPT TO) Not sure where else to look Relevant section of Postfix's main.cf (relatively untouched from ISPC's default template): Code: myhostname = example.com alias_maps = hash:/etc/aliases, hash:/var/lib/mailman/data/aliases alias_database = hash:/etc/aliases, hash:/var/lib/mailman/data/aliases myorigin = /etc/mailname mydestination = localhost, localhost.localdomain relayhost = mynetworks = 127.0.0.0/8 [::1]/128 mailbox_size_limit = 0 recipient_delimiter = + inet_interfaces = all html_directory = /usr/share/doc/postfix/html virtual_alias_domains = virtual_alias_maps = proxy:mysql:/etc/postfix/mysql-virtual_forwardings.cf, proxy:mysql:/etc/postfix/mysql-virtual_email2email.cf, hash:/var/lib/mailman/data/virtual-mailman virtual_mailbox_domains = proxy:mysql:/etc/postfix/mysql-virtual_domains.cf virtual_mailbox_maps = proxy:mysql:/etc/postfix/mysql-virtual_mailboxes.cf virtual_mailbox_base = /var/vmail virtual_uid_maps = static:5000 virtual_gid_maps = static:5000 smtpd_sasl_auth_enable = yes broken_sasl_auth_clients = yes smtpd_sasl_authenticated_header = yes smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated, check_recipient_access, mysql:/etc/postfix/mysql-virtual_recipient.cf, reject_unauth_destination, reject_invalid_hostname, reject_non_fqdn_hostname, reject_non_fqdn_sender, reject_non_fqdn_recipient, reject_unknown_sender_domain, reject_unknown_recipient_domain, reject_unauth_destination, permit_mynetworks, reject_rbl_client bl.spamcop.net, reject_rbl_client zen.spamhaus.org, #reject_rbl_client dnsbl.sorbs.net, permit smtpd_tls_security_level = may transport_maps = proxy:mysql:/etc/postfix/mysql-virtual_transports.cf relay_domains = mysql:/etc/postfix/mysql-virtual_relaydomains.cf relay_recipient_maps = mysql:/etc/postfix/mysql-virtual_relayrecipientmaps.cf virtual_create_maildirsize = yes virtual_maildir_extended = yes virtual_mailbox_limit_maps = proxy:mysql:/etc/postfix/mysql-virtual_mailbox_limit_maps.cf virtual_mailbox_limit_override = yes virtual_maildir_limit_message = "The user you are trying to reach is over quota." virtual_overquota_bounce = yes proxy_read_maps = $local_recipient_maps $mydestination $virtual_alias_maps $virtual_alias_domains $virtual_mailbox_maps $virtual_mailbox_domains $relay_recipient_maps $relay_domains $canonical_maps $sender_canonical_maps $recipient_canonical_maps $relocated_maps $transport_maps $mynetworks $virtual_mailbox_limit_maps smtpd_sender_restrictions = check_sender_access mysql:/etc/postfix/mysql-virtual_sender.cf smtpd_client_restrictions = check_client_access mysql:/etc/postfix/mysql-virtual_client.cf maildrop_destination_concurrency_limit = 1 maildrop_destination_recipient_limit = 1 virtual_transport = dovecot header_checks = regexp:/etc/postfix/header_checks mime_header_checks = regexp:/etc/postfix/mime_header_checks nested_header_checks = regexp:/etc/postfix/nested_header_checks body_checks = regexp:/etc/postfix/body_checks dovecot_destination_recipient_limit = 1 smtpd_sasl_type = dovecot smtpd_sasl_path = private/auth #These two lines commented temporarily, due to memory constraints. #See http://www.clearlysecure.com.au/node/48 content_filter = amavis:[127.0.0.1]:10024 receive_override_options = no_address_mappings message_size_limit = 0 smtpd_use_tls = yes smtpd_client_message_rate_limit = 100 owner_request_special = no And the relevant bit from master.cf: Code: amavis unix - - - - 1 smtp -o smtp_data_done_timeout=1200 -o smtp_send_xforward_command=yes 127.0.0.1:10025 inet n - - - - smtpd -o content_filter= -o local_recipient_maps= -o relay_recipient_maps= -o smtpd_restriction_classes= -o smtpd_client_restrictions= -o smtpd_helo_restrictions= -o smtpd_sender_restrictions= -o smtpd_recipient_restrictions=permit_mynetworks,reject -o mynetworks=127.0.0.0/8 -o strict_rfc821_envelopes=yes -o receive_override_options=no_unknown_recipient_checks,no_header_body_checks -o smtpd_bind_address=127.0.0.1 The reading I've done on amavis-new states that at long as the line "-o smtp_send_xforward_command=yes" is present, an open relay should not occur. Is anyone able to spot a misconfiguration here? Thanks in advance. ETA: Here's some additional information. The following information was sent in an email (to "root") via Postfix while all of this was occurring, with the subject "Postfix SMTP server: errors from localhost.localdomain[127.0.0.1]: Code: Transcript of session follows. Out: 220 example2.com ESMTP Postfix (Ubuntu) In: EHLO localhost Out: 250-example2.com Out: 250-PIPELINING Out: 250-SIZE Out: 250-VRFY Out: 250-ETRN Out: 250-STARTTLS Out: 250-AUTH PLAIN LOGIN Out: 250-AUTH=PLAIN LOGIN Out: 250-ENHANCEDSTATUSCODES Out: 250-8BITMIME Out: 250 DSN In: MAIL FROM:<[email protected]> Out: 250 2.1.0 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: DATA Out: 354 End data with <CR><LF>.<CR><LF> Out: 451 4.3.0 Error: queue file write error In: MAIL FROM:<[email protected]> Out: 250 2.1.0 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: DATA Out: 354 End data with <CR><LF>.<CR><LF> Out: 451 4.3.0 Error: queue file write error In: MAIL FROM:<[email protected]> Out: 250 2.1.0 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: DATA Out: 354 End data with <CR><LF>.<CR><LF> Out: 451 4.3.0 Error: queue file write error In: MAIL FROM:<[email protected]> Out: 250 2.1.0 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: RCPT TO:<[email protected]> ORCPT=rfc822;[email protected] Out: 250 2.1.5 Ok In: DATA Out: 354 End data with <CR><LF>.<CR><LF> Out: 451 4.3.0 Error: queue file write error For other details, see the local mail logfile I find this bit curious, in particular: Code: Out: 250-STARTTLS Out: 250-AUTH PLAIN LOGIN Out: 250-AUTH=PLAIN LOGIN Does this indicate that the spammer is actually authenticating to the server (compromised credentials)? (UPDATE: Never mind; it seems as though the mail server is simply advertising its capabilities here.) This line, too: Code: Out: 250-PIPELINING I found the following directive in the Postfix documentation: Code: smtpd_data_restrictions = reject_unauth_pipelining Should this be switched-on in my configuration? The documentation is somewhat unclear and has the following to say: Additionally, the following information was sent in an email (to "root") via Postfix while all of this was occurring, with the subject "Postfix SMTP server: errors from unknown[189.84.21.206]: Code: Transcript of session follows. Out: 220 example2.com ESMTP Postfix (Ubuntu) In: HELO 189.84.21.205 Out: 250 example2.com In: RSET Out: 250 2.0.0 Ok In: MAIL FROM:<[email protected]> Out: 250 2.1.0 Ok In: RCPT TO:<[email protected]> Out: 451 4.3.0 <[email protected]>: Temporary lookup failure In: RCPT TO:<[email protected]> Out: 451 4.3.0 <[email protected]>: Temporary lookup failure In: RCPT TO:<[email protected]> Out: 451 4.3.0 <[email protected]>: Temporary lookup failure In: RCPT TO:<[email protected]> Out: 451 4.3.0 <[email protected]>: Temporary lookup failure In: RCPT TO:<[email protected]> Out: 451 4.3.0 <[email protected]>: Temporary lookup failure In: RCPT TO:<[email protected]> Out: 451 4.3.0 <[email protected]>: Temporary lookup failure In: RCPT TO:<[email protected]> Out: 451 4.3.0 <[email protected]>: Temporary lookup failure In: RCPT TO:<[email protected]> Out: 451 4.3.0 <[email protected]>: Temporary lookup failure In: RCPT TO:<[email protected]> Out: 451 4.3.0 <[email protected]>: Temporary lookup failure In: RCPT TO:<[email protected]> Out: 451 4.3.0 <[email protected]>: Temporary lookup failure In: QUIT Out: 221 2.0.0 Bye For other details, see the local mail logfile I don't know if this snippet tells us anything useful or not. ETA: This looks very similar or the same as what I'm experiencing: http://www.tolaris.com/2009/07/15/stopping-spam-botnets-with-fail2ban/ The article advises using fail2ban to ban IP addresses that trigger "RCPT from (.*)\[<HOST>\]: 554", which seems like it would put this specific type of attack on ice. I'm still curious, though, how this bot is jamming these messages through to the end result that Hotmail blocks connections from my server? This shouldn't be possible in a sound configuration!
I reached-out to the Postfix mailing list and one of the list's more accomplished contributors recommended strongly that I swap the order of two configuration directives, which are set "incorrectly" by default (I don't know whether by Ubuntu or by ISPConfig): http://archives.neohapsis.com/archives/postfix/2013-05/0520.html If this Postfix misconfiguration issue is, in fact, at the root of this problem, I'm surprised that others have not had similar experiences with flooded Postfix queues. I'm still not convinced that these two configuration values are the problem. Only time will tell. I also modified my fail2ban configuration so that "relay access denied" offenders are banned (the appropriate regular expression already exists in filter.d/postfix.conf). In jail.local, the Postfix section now reads: Code: [postfix] enabled = true ignoreip = 127.0.0.1/8 port = smtp,ssmtp filter = postfix logpath = /var/log/mail.log bantime = 3600 Code: # service fail2ban reload I'll see how these changes affect the observed behavior and update this thread when I know more.
The problem has not recurred since I reordered the values within the smtpd_recipient_restrictions directive. I strongly recommend enabling fail2ban's Postfix filter, as I did, too. This filter is banning over 600 IP addresses every 24 hours. I wish I had enabled this filter sooner!