I'm getting a huge amount of spamming attempts to random usernames. I know that it happens to all mail servers to some degree, but during the last two weeks there was so much that my VPS's disk allotment filled up just because of the size of the maillog files! One week's log was almost 7GB, and others were smaller but not normal. I'm a novice at reading logs, but here is a small randomly selected snippet:
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 05DEA31470BF: from=<glenda_fitzgerald@l4jp.com>, size=1165, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 05DEA31470BF: to=<smith88@yahoo.com>, relay=none, delay=358802, delays=358802/0.07/0/0, dsn=4.4.2, status=deferred (delivery temporarily suspended: lost connection with mta5.am0.yahoodns.net[66.196.118.34] while sending RCPT TO)
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 00B053186BAE: from=<minnie_duncan@l4jp.com>, size=1123, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/local[27246]: 00DAD31454C1: to=<ginger_walton@l4jp.com>, relay=local, delay=391867, delays=391867/0.13/0/0.02, dsn=4.1.1, status=SOFTBOUNCE (unknown user: "ginger_walton")
Sep 11 03:53:16 vps-1011517-5697 postfix/smtp[26812]: 0099B3136B26: to=<aziz.toska@gmail.com>, relay=gmail-smtp-in.l.google.com[74.125.204.27]:25, delay=107076, delays=107075/0/0.39/0.68, dsn=4.7.1, status=SOFTBOUNCE (host gmail-smtp-in.l.google.com[74.125.204.27] said: 550-5.7.1 [27.112.107.68 1] Our system has detected an unusual rate of 550-5.7.1 unsolicited mail originating from your IP address. To protect our 550-5.7.1 users from spam, mail sent from your IP address has been blocked. 550-5.7.1 Please visit 550-5.7.1 https://support.google.com/mail/?p=UnsolicitedIPError to review our 550 5.7.1 Bulk Email Senders Guidelines. q189si11097060pfq.189 - gsmtp (in reply to end of DATA command))
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 00ECD3169334: from=<lauren_christensen@l4jp.com>, size=1106, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 00ECD3169334: to=<judelaws67@yahoo.com>, relay=none, delay=246340, delays=246340/0.02/0/0, dsn=4.4.2, status=deferred (delivery temporarily suspended: lost connection with mta5.am0.yahoodns.net[66.196.118.34] while sending RCPT TO)
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 0231E3138414: from=<david_moon@l4jp.com>, size=1560, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 0231E3138414: to=<colbypeoples44@yahoo.com>, relay=none, delay=14482, delays=14482/0/0/0, dsn=4.4.2, status=deferred (delivery temporarily suspended: lost connection with mta5.am0.yahoodns.net[66.196.118.34] while sending RCPT TO)
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 062593144D72: from=<>, size=3463, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 08A1D31498F3: from=<>, size=3045, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/local[27247]: 062593144D72: to=<isabel_miles@l4jp.com>, relay=local, delay=396966, delays=396966/0.01/0/0, dsn=4.1.1, status=SOFTBOUNCE (unknown user: "isabel_miles")
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 0D692313F1DA: from=<>, size=3078, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 00EA0313F88E: from=<>, size=3464, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/local[27248]: 08A1D31498F3: to=<bridget_harrison@l4jp.com>, relay=local, delay=321787, delays=321787/0.02/0/0, dsn=4.1.1, status=SOFTBOUNCE (unknown user: "bridget_harrison")
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 0F2A33147B48: from=<>, size=3657, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/local[27246]: 0D692313F1DA: to=<freda_gordon@l4jp.com>, relay=local, delay=430240, delays=430240/0.02/0/0, dsn=4.1.1, status=SOFTBOUNCE (unknown user: "freda_gordon")
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 046C83133878: from=<shelley_garcia@l4jp.com>, size=1180, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/local[27247]: 00EA0313F88E: to=<amelia_hanson@l4jp.com>, relay=local, delay=425180, delays=425180/0.02/0/0, dsn=4.1.1, status=SOFTBOUNCE (unknown user: "amelia_hanson")
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 035633144D87: from=<>, size=3087, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 019673137E30: from=<marguerite_lee@l4jp.com>, size=1161, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/local[27248]: 0F2A33147B48: to=<della_wright@l4jp.com>, relay=local, delay=347073, delays=347073/0.02/0/0, dsn=4.1.1, status=SOFTBOUNCE (unknown user: "della_wright")
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 01F593146A8D: from=<>, size=3579, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/local[27246]: 035633144D87: to=<kelley_strickland@l4jp.com>, relay=local, delay=396952, delays=396952/0.02/0/0, dsn=4.1.1, status=SOFTBOUNCE (unknown user: "kelley_strickland")
Sep 11 03:53:16 vps-1011517-5697 postfix/smtp[27074]: 0423D31361AE: to=<ka-abdel@hotmail.fr>, relay=mx3.hotmail.com[65.55.37.72]:25, delay=33557, delays=33557/0.01/0.38/0.12, dsn=4.0.0, status=SOFTBOUNCE (host mx3.hotmail.com[65.55.37.72] said: 550 SC-002 (COL004-MC1F20) Unfortunately, messages from 27.112.107.68 weren't sent. Please contact your Internet service provider since part of their network is on our block list. You can also refer your provider to http://mail.live.com/mail/troubleshooting.aspx#errors. (in reply to MAIL FROM command))
Sep 11 03:53:16 vps-1011517-5697 postfix/smtp[27074]: 0423D31361AE: lost connection with mx3.hotmail.com[65.55.37.72] while sending RCPT TO
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 078CF312D56D: from=<>, size=3751, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/local[27247]: 01F593146A8D: to=<eva_morrison@l4jp.com>, relay=local, delay=371261, delays=371261/0.02/0/0, dsn=4.1.1, status=SOFTBOUNCE (unknown user: "eva_morrison")
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 0CB143130F4A: from=<>, size=3022, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/local[27248]: 078CF312D56D: to=<gwen_mendoza@l4jp.com>, relay=local, delay=321700, delays=321700/0.01/0/0, dsn=4.1.1, status=SOFTBOUNCE (unknown user: "gwen_mendoza")
Sep 11 03:53:16 vps-1011517-5697 postfix/qmgr[31514]: 02A0C31284D7: from=<>, size=3032, nrcpt=1 (queue active)
Sep 11 03:53:16 vps-1011517-5697 postfix/local[27246]: 0CB143130F4A: to=<marcia_harvey@l4jp.com>, relay=local, delay=242903, delays=242903/0.01/0/0, dsn=4.1.1, status=SOFTBOUNCE (unknown user: "marcia_harvey")
Three musings:
- My understanding of "SOFTBOUNCE" doesn't fit the situation - an invalid username should be a hard bounce, right? Anyway, I would rather not have any bounce at all, as it's a waste of resources as well as giving the spammer too much info.
- I don't understand the text of the complaint from Google's server - the number "500-5.7.1" seems to be randomly inserted in the sentence. But I assume that all those outgoing bounces could be construed as spam in of themselves if there are enough of them, right?
- The complaint from French Hotmail about a blocklist could be caused by my server or someone else's; a check of 107 blacklists reported my IP on just two of them, so I don't think I have real spam generators on my website or anything like that.
Anyway, I only have one valid username on the domain, so is it possible to configure postfix to simply drop any attempts at mail to any other username? I would be happy if no bounces were sent and nothing was even entered in the log file, because as I said, the log files themselves are filling up. Or if there is a better way of handling this sort of attack, I'm all ears.
EDIT #1: In response to the comment asking about connect/disconnect entries, I searched for the first occurrence of " connect " (with spaces around it - otherwise I get all the "lost connection" entries), and then grepped subsequent references to the same mailserver. Here is the first sequence of those, which occur within a two-second span so are probably related to the same email attempt:
Sep 11 03:53:25 vps-1011517-5697 postfix/smtpd[20505]: connect from simcoe209srvr.owm.bell.net[184.150.200.209]
Sep 11 03:53:25 vps-1011517-5697 postfix/smtpd[20505]: setting up TLS connection from simcoe209srvr.owm.bell.net[184.150.200.209]
Sep 11 03:53:26 vps-1011517-5697 postfix/smtpd[20505]: TLS connection established from simcoe209srvr.owm.bell.net[184.150.200.209]: TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bi
ts)
Sep 11 03:53:26 vps-1011517-5697 postfix/smtpd[20505]: NOQUEUE: reject: RCPT from simcoe209srvr.owm.bell.net[184.150.200.209]: 450 4.1.1 <louise_bryant@l4jp.com>: Recipient address
rejected: User unknown in local recipient table; from=<> to=<louise_bryant@l4jp.com> proto=ESMTP helo=<torfep04.bell.net>
Sep 11 03:53:27 vps-1011517-5697 postfix/smtpd[20505]: disconnect from simcoe209srvr.owm.bell.net[184.150.200.209]
These were not sequential entries in the log; there were volumes of unrelated entries during the same two seconds. But if you want me to search for something related in the midst, just tell me what to look for.
EDIT #2: In response to JennyD, here is my /etc/postfix/main.cf (with comments removed, of course):
soft_bounce = yes
queue_directory = /var/spool/postfix
command_directory = /usr/sbin
daemon_directory = /usr/libexec/postfix
mail_owner = postfix
myhostname = l4jp.com
mydomain = l4jp.com
mydestination = $myhostname, localhost.$mydomain, localhost, $mydomain
unknown_local_recipient_reject_code = 550
alias_maps = hash:/etc/aliases
alias_database = hash:/etc/aliases
debug_peer_level = 2
debugger_command =
PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin
xxgdb $daemon_directory/$process_name $process_id & sleep 5
sendmail_path = /usr/sbin/sendmail.postfix
newaliases_path = /usr/bin/newaliases.postfix
mailq_path = /usr/bin/mailq.postfix
setgid_group = postdrop
html_directory = no
manpage_directory = /usr/share/man
sample_directory = /usr/share/doc/postfix-2.3.3/samples
readme_directory = /usr/share/doc/postfix-2.3.3/README_FILES
# THE FOLLOWING IS FROM: http://www.anchor.com.au/hosting/dedicated/Postfix-SASL-setup
smtpd_sasl_type = dovecot
smtpd_sasl_path = private/auth
smtpd_sasl_auth_enable = yes
smtpd_sasl_authenticated_header = yes
broken_sasl_auth_clients = yes
smtpd_recipient_restrictions =
permit_mynetworks
permit_sasl_authenticated
reject_unauth_destination
smtpd_tls_security_level = may
smtpd_tls_key_file = /etc/ssl/smtpd.key
smtpd_tls_cert_file = /etc/ssl/smtpd.crt
smtpd_tls_auth_only = yes
smtpd_tls_loglevel = 1
smtpd_tls_received_header = yes
#My settings for virtual mailbox domains (which I don't think I actually use for anything)
virtual_mailbox_domains = /etc/postfix/vhosts.txt
virtual_mailbox_base = /var/spool/vmail
virtual_mailbox_maps = hash:/etc/postfix/vmaps.txt
virtual_minimum_uid = 100
virtual_uid_maps = static:101
virtual_gid_maps = static:101
message_size_limit = 30720000
EDIT #3: Dom recommended softbounce=no. I sent a test email before and after making that change - here are the relevant log entries (from-address sanitized):
Sep 12 20:38:39 vps-1011517-5697 postfix/smtpd[5343]: connect from gateway21.websitewelcome.com[192.185.45.43]
Sep 12 20:38:39 vps-1011517-5697 postfix/smtpd[5343]: setting up TLS connection from gateway21.websitewelcome.com[192.185.45.43]
Sep 12 20:38:39 vps-1011517-5697 postfix/smtpd[5343]: TLS connection established from gateway21.websitewelcome.com[192.185.45.43]: TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)
Sep 12 20:38:40 vps-1011517-5697 postfix/smtpd[5343]: NOQUEUE: reject: RCPT from gateway21.websitewelcome.com[192.185.45.43]: 450 4.1.1 <testing@l4jp.com>: Recipient address rejected: User unknown in local recipient table; from=<myotheremail@otherdomain.com> to=<testing@l4jp.com> proto=ESMTP helo=<gateway21.websitewelcome.com>
Sep 12 20:38:40 vps-1011517-5697 postfix/smtpd[5343]: disconnect from gateway21.websitewelcome.com[192.185.45.43]
Sep 12 20:43:06 vps-1011517-5697 postfix/smtpd[6400]: connect from gateway23.websitewelcome.com[192.185.50.119]
Sep 12 20:43:06 vps-1011517-5697 postfix/smtpd[6400]: setting up TLS connection from gateway23.websitewelcome.com[192.185.50.119]
Sep 12 20:43:07 vps-1011517-5697 postfix/smtpd[6400]: TLS connection established from gateway23.websitewelcome.com[192.185.50.119]: TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)
Sep 12 20:43:07 vps-1011517-5697 postfix/smtpd[6400]: NOQUEUE: reject: RCPT from gateway23.websitewelcome.com[192.185.50.119]: 550 5.1.1 <testing@l4jp.com>: Recipient address rejected: User unknown in local recipient table; from=<myotheremail@otherdomain.com> to=<testing@l4jp.com> proto=ESMTP helo=<gateway23.websitewelcome.com>
Sep 12 20:43:07 vps-1011517-5697 postfix/smtpd[6400]: disconnect from gateway23.websitewelcome.com[192.185.50.119]
There were five entries in both cases - the only difference in the log was the error code (as expected). But after the change I got an actual bounce message to the address from which I sent the test. Isn't that a bad thing to send to spammers?
EDIT #4: In response to masegaloeh's comment asking for all entries related to the same message queue ID. The ID he gave as an example was from the original files before I turned off soft_bounce, but I suspect one without soft_bounce is more useful, so here is a very recent random example:
[root](10:27:06)[~]$ grep E6CBF312663B /var/log/maillog
Sep 15 10:26:11 vps-1011517-5697 postfix/cleanup[10347]: E6CBF312663B: message-id=<20160915012611.E6CBF312663B@l4jp.com>
Sep 15 10:26:11 vps-1011517-5697 postfix/bounce[10292]: 47A8E3126F85: sender non-delivery notification: E6CBF312663B
Sep 15 10:26:11 vps-1011517-5697 postfix/qmgr[8701]: E6CBF312663B: from=<>, size=3801, nrcpt=1 (queue active)
Sep 15 10:26:11 vps-1011517-5697 postfix/local[10477]: E6CBF312663B: to=<eula_mcdonald@l4jp.com>, relay=local, delay=0, delays=0/0/0/0, dsn=5.1.1, status=bounced (unknown user: "eula_mcdonald")
Sep 15 10:26:11 vps-1011517-5697 postfix/qmgr[8701]: E6CBF312663B: removed
The current log file has grown to 1.2GB in only about 2.5 days. I cannot sustain this pace...
EDIT #5: Next, masegaloeh asked for this:
[root](09:03:50)[/var/log]$ grep 47A8E3126F85 maillog
Sep 15 10:26:10 vps-1011517-5697 postfix/pickup[10444]: 47A8E3126F85: uid=500 from=<eula_mcdonald@l4jp.com>
Sep 15 10:26:10 vps-1011517-5697 postfix/cleanup[10347]: 47A8E3126F85: message-id=<7adc4f0bc266b560e0ec0521654f81b8@l4jp.com>
Sep 15 10:26:10 vps-1011517-5697 postfix/qmgr[8701]: 47A8E3126F85: from=<eula_mcdonald@l4jp.com>, size=1153, nrcpt=1 (queue active)
Sep 15 10:26:11 vps-1011517-5697 postfix/smtp[9981]: 47A8E3126F85: to=<nashvilleguy717@gmail.com>, relay=gmail-smtp-in.l.google.com[64.233.189.27]:25, delay=1.7, delays=0.02/0.39/0.51/0.75, dsn=5.7.1, status=bounced (host gmail-smtp-in.l.google.com[64.233.189.27] said: 550-5.7.1 [27.112.107.68 1] Our system has detected an unusual rate of 550-5.7.1 unsolicited mail originating from your IP address. To protect our 550-5.7.1 users from spam, mail sent from your IP address has been blocked. 550-5.7.1 Please visit 550-5.7.1 https://support.google.com/mail/?p=UnsolicitedIPError to review our 550 5.7.1 Bulk Email Senders Guidelines. n130si231260oig.169 - gsmtp (in reply to end of DATA command))
Sep 15 10:26:11 vps-1011517-5697 postfix/bounce[10292]: 47A8E3126F85: sender non-delivery notification: E6CBF312663B
Sep 15 10:26:11 vps-1011517-5697 postfix/qmgr[8701]: 47A8E3126F85: removed
EDIT #6: After taking Michael Hampton's suggested actions, I looked at a tail of the log again. The words "accepted for delivery" caught my eye, because I'm not sending or receiving any real mail - here is the series related to the one I noticed:
[root](15:01:16)[/var/log]$ grep 638BD3122039 maillog
Sep 17 14:59:34 vps-1011517-5697 postfix/pickup[8959]: 638BD3122039: uid=500 from=<juanita_ellis@l4jp.com>
Sep 17 14:59:34 vps-1011517-5697 postfix/cleanup[9099]: 638BD3122039: message-id=<106604bcf476c97586ba8590c7db683e@l4jp.com>
Sep 17 14:59:34 vps-1011517-5697 postfix/qmgr[7492]: 638BD3122039: from=<juanita_ellis@l4jp.com>, size=1185, nrcpt=1 (queue active)
Sep 17 14:59:38 vps-1011517-5697 postfix/smtp[9109]: 638BD3122039: to=<john.timmermans@philips.com>, relay=gw-eur1.smtp.philips.com[212.159.218.9]:25, delay=3.6, delays=0.07/0.01/1.6/2, dsn=2.0.0, status=sent (250 2.0.0 kVzb1t0041UaJoz01VzcmY mail accepted for delivery)
Sep 17 14:59:38 vps-1011517-5697 postfix/qmgr[7492]: 638BD3122039: removed
Of course there is no juanita_ellis here. What could cause that message to get sent? Am I really sending spam???
