Table of Contents
SPAM Problems from 27.12.2022
My server relay.avril.work was used to sent SPAM mails.
See the e-mail “FWD: [Ticket#20221226250029] UCEPROTECT Monitoring Report” from Daniel Bruhn - IP-Projects GmbH & Co. KG (aka support@ip-projects.de)
Tasks to fix the problem
- + Find out why my server sending SPAM
- it seems that the user
test@glomus-gps.dewas compromised (someone knows the password)
- + Prevent sending SPAM from the account
test@glomus-gps.de- changed the password
- + Check whether the IP 94.199.215.198 is not more blacklisted at UCEProtect
- - Fix certificate problems during fetching of mails (e.g. in Thunderbird)
- - Prevent login attempts from unknown
@wialon-consulting.deaccounts (e.g.gloria@wialon-consulting.de)
- - Prevent wrong SSH login attempts from different users (see
/var/log/auth.log)- useful tactics: disable SSH password based authentication and use the SSH-key based:
- - Prevent suspicious log entries
- - like:
Jan 22 15:30:04 relay postfix/smtps/smtpd[8530]: connect from ec2-35-178-213-55.eu-west-2.compute.amazonaws.com[35.178.213.55] Jan 22 15:30:04 relay postfix/smtps/smtpd[8530]: lost connection after CONNECT from ec2-35-178-213-55.eu-west-2.compute.amazonaws.com[35.178.213.55] Jan 22 15:30:04 relay postfix/smtps/smtpd[8530]: disconnect from ec2-35-178-213-55.eu-west-2.compute.amazonaws.com[35.178.213.55] commands=0/0
- - like:
Jan 22 15:36:15 relay dovecot: imap-login: Disconnected: Too many invalid commands (no auth attempts in 0 secs): user=<>, rip=35.178.213.55, lip=94.199.215.198, session$ Jan 22 15:36:18 relay dovecot: imap-login: Disconnected: Too many invalid commands (no auth attempts in 0 secs): user=<>, rip=35.178.213.55, lip=94.199.215.198, session$ Jan 22 15:36:20 relay dovecot: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=35.178.213.55, lip=94.199.215.198, session=<1X++NNvyeLcjstU3>
- - like …
- - check documentation about “postfix block spam” (→ Google-search)
- - check documentation about Postfix configuration
- - check the documentation about how to deal with compromised server
- - find the process/script sending spam mails ( e.g. see the directory /var/spool/postfix/maildrop on the server?)
- - are spam mails sent with a (PHP?)script or my postfix is an “open relay”?
Regularly tasks
These tasks should be done regularly to check whether the server sends SPAM.
Weekly
- - check whether some SPAM warnings are in the log files
- -
/var/log/mail.log - -
/var/log/mail.err(should be empty)
- - check sent mails
- - with
sudo grep 'status=sent' /var/log/mail.log- or to redirect the output to a file
sudo grep 'status=sent' /var/log/mail.log > ~/mail.sent.log- and after that:
nano ~/mail.sent.log
- - check mail queue (see “Useful commands”?)
- -
postqueue -p→ display all mails in queue - also useful is e.g.
qshape deferredfor deferred queue
- - check log file
/var/log/docker.log - - check whether the IP 94.199.215.198 is not blacklisted at UCEProtect
Some documentation about how to deal with compromised server
-
- 6. To delete all queued messages that contain the word “abc” in the e-mail address:
- # ./postfix-delete.pl abc
- 7. To know the number of messages sitting in the deferred queue:
- # find /var/spool/postfix/deferred -type f | wc -l
- 8. To get a sorted list of the accounts that have the most mail in the queue. This usually means a maximum of 2 or 3 spammers at the end of the list:
- # mailq|grep ^[A-F0-9]|cut -c 42-80|sort |uniq -c|sort -n|tail
Not very good (for me at the moment):
- How to Check if Your Server is Sending Spam - not really much information
- I'm Sending Spam. How do I Stop it? - maybe good, but seems to be for ClearOS users
Logs from my server relay.avril.work
/var/log/mail.log.1 (first page only):
Dec 26 06:25:22 relay postfix/qmgr[932]: 5937236F4B4: from=<test@glomus-gps.de>, size=5126, nrcpt=16 (queue active)
Dec 26 06:25:22 relay postfix/smtpd[4381]: connect from localhost.localdomain[127.0.0.1]
Dec 26 06:25:22 relay postfix/smtpd[4381]: 48C3E36F4D8: client=localhost.localdomain[127.0.0.1], orig_queue_id=5937236F4B4, orig_client=unknown[49.48.218.242]
Dec 26 06:25:22 relay postfix/cleanup[10614]: 48C3E36F4D8: message-id=<874EF9E4.7171186@glomus-gps.de>
Dec 26 06:25:22 relay postfix/smtpd[4381]: disconnect from localhost.localdomain[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=16 data=1 quit=1 commands=21
Dec 26 06:25:22 relay postfix/qmgr[932]: 48C3E36F4D8: from=<test@glomus-gps.de>, size=5531, nrcpt=16 (queue active)
Dec 26 06:25:22 relay amavis[11081]: (11081-15) Passed CLEAN {RelayedOutbound}, ORIGINATING LOCAL [49.48.218.242]:25053 [49.48.218.242] <test@glomus-gps.de> -> <wulf777d@aol.com>,<bcosgrove734@gmail.com>,<brockjacobbrock19@gmail.com>,<catjscatering@gmail.com>,<dkbproperties@gmail.com>,<hartsfieldbe@gmail.com>,<ilgermogliostefano@gmail.com>,<jimbeau.bui@gmail.com>,<krish.edwards@gmail.com>,<rweitzel56@gmail.com>,<sfoceanvu@gmail.com>,<chef_alanj@hotmail.com>,<damurray98@hotmail.com>,<esfinter56@hotmail.com>,<estepkenneth@hotmail.com>,<wjferg88@yahoo.com>, Queue-ID: 5937236F4B4, Message-ID: <874EF9E4.7171186@glomus-gps.de>, mail_id: UnSBON_0bH8o, Hits: 1.213, size: 5126, queued_as: 48C3E36F4D8, 533 ms
Dec 26 06:25:22 relay postfix/smtp[11102]: 5937236F4B4: to=<wulf777d@aol.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=7.6, delays=7.1/0/0.01/0.53, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 48C3E36F4D8)
Dec 26 06:25:22 relay postfix/smtp[11102]: 5937236F4B4: to=<bcosgrove734@gmail.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=7.6, delays=7.1/0/0.01/0.53, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 48C3E36F4D8)
Dec 26 06:25:22 relay postfix/smtp[11102]: 5937236F4B4: to=<brockjacobbrock19@gmail.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=7.6, delays=7.1/0/0.01/0.53, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 48C3E36F4D8)
Dec 26 06:25:22 relay postfix/smtp[11102]: 5937236F4B4: to=<catjscatering@gmail.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=7.6, delays=7.1/0/0.01/0.53, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 48C3E36F4D8)
Dec 26 06:25:22 relay postfix/smtp[11102]: 5937236F4B4: to=<dkbproperties@gmail.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=7.6, delays=7.1/0/0.01/0.53, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 48C3E36F4D8)
Dec 26 06:25:22 relay postfix/smtp[11102]: 5937236F4B4: to=<hartsfieldbe@gmail.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=7.6, delays=7.1/0/0.01/0.53, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 48C3E36F4D8)
Dec 26 06:25:22 relay postfix/smtp[11102]: 5937236F4B4: to=<ilgermogliostefano@gmail.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=7.6, delays=7.1/0/0.01/0.53, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 48C3E36F4D8)
Dec 26 06:25:22 relay postfix/smtp[11102]: 5937236F4B4: to=<jimbeau.bui@gmail.com>, relay=127.0.0.1[127.0.0.1]:10026, delay=7.6, delays=7.1/0/0.01/0.53, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 48C3E36
mail.log contains strange auth attempts
Jan 13 08:50:13 relay dovecot: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=104.156.155.21, lip=94.199.215.198, TLS handshaking: SSL_accept() syscall failed: Success, session=<No/TeyDyeNFonJsV> Jan 13 08:50:13 ...: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() syscall failed: Success, session=<K5HTeyDyQIFonJsV> Jan 13 08:50:14 ...: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() syscall failed: Success, session=<bPLbeyDyooZonJsV> Jan 13 08:50:14 ...: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() syscall failed: Success, session=<PfXbeyDy2NZonJsV> Jan 13 08:50:14 ...: imap-login: Disconnected (no auth attempts in 1 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() syscall failed: Success, session=<E7TceyDyINdonJsV> Jan 13 08:50:14 ...: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() failed: error:1417A0C1:SSL routines:tls_post_process_client_hello:no shared cipher, session=<qTXfeyDy4ttonJsV> Jan 13 08:50:14 ...: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() failed: error:1417A0C1:SSL routines:tls_post_process_client_hello:no shared cipher, session=<zzrfeyDyqotonJsV> Jan 13 08:50:14 ...: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() syscall failed: Success, session=<eoPgeyDyKsVonJsV> Jan 13 08:50:15 ...: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() failed: error:1417A0C1:SSL routines:tls_post_process_client_hello:no shared cipher, session=<GBjleyDymt9onJsV> Jan 13 08:50:15 ...: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() failed: error:1417A0C1:SSL routines:tls_post_process_client_hello:no shared cipher, session=<bCfleyDyZI9onJsV> Jan 13 08:50:15 ...: imap-login: Disconnected (no auth attempts in 1 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() failed: error:1417A0C1:SSL routines:tls_post_process_client_hello:no shared cipher, session=<bQbpeyDyrOFonJsV> Jan 13 08:50:15 ...: pop3-login: Disconnected (no auth attempts in 1 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() syscall failed: Success, session=<nhfveyDylM1onJsV> Jan 13 08:50:15 ...: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() syscall failed: Success, session=<a4jweyDy6uJonJsV> Jan 13 08:50:15 ...: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=..., lip=..., TLS handshaking: SSL_accept() syscall failed: Success, session=<qaDweyDytJJonJsV>
Useful stuff
- My postfixadmin website: https://postfixadmin.avril.work/public/viewlog.php
- Content of /var/spool/mail/root
From root@relay.avril.work Wed May 19 21:15:01 2021
Return-Path: <root@relay.avril.work>
X-Original-To: root
Delivered-To: root@relay.avril.work
Received: by relay.avril.work (Postfix, from userid 0)
id 5E79624E7B8; Wed, 19 May 2021 21:15:01 +0200 (CEST)
From: root@relay.avril.work (Cron Daemon)
To: root@relay.avril.work
Subject: Cron <root@relay> docker restart jrserver
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit
X-Cron-Env: <SHELL=/bin/sh>
X-Cron-Env: <HOME=/root>
X-Cron-Env: <PATH=/usr/bin:/bin>
X-Cron-Env: <LOGNAME=root>
Message-Id: <20210519191501.5E79624E7B8@relay.avril.work>
Date: Wed, 19 May 2021 21:15:01 +0200 (CEST)
Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running?
- Example of a spam mail in /var/spool/postfix/active directory:
root@relay:/var/spool/postfix/active# postcat -q BF15B373EF8 postcat: warning: /etc/postfix/main.cf, line 91: overriding earlier entry: smtpd_relay_restrictions=permit_mynetworks permit_sasl_authenticated defer_unauth_destination *** ENVELOPE RECORDS active/BF15B373EF8 *** message_size: 5654 2578 22 0 5654 0 message_arrival_time: Mon Dec 26 16:56:30 2022 create_time: Mon Dec 26 16:56:30 2022 named_attribute: log_ident=AA0A1373EEC named_attribute: rewrite_context=remote sender: test@glomus-gps.de named_attribute: encoding=7bit named_attribute: log_client_name=unknown named_attribute: log_client_address=171.7.235.230 named_attribute: log_client_port=59178 named_attribute: log_message_origin=unknown[171.7.235.230] named_attribute: log_helo_name=[127.0.0.1] named_attribute: log_protocol_name=ESMTP named_attribute: client_name=localhost.localdomain named_attribute: reverse_client_name=localhost.localdomain named_attribute: client_address=127.0.0.1 named_attribute: client_port=48314 named_attribute: server_address=127.0.0.1 named_attribute: server_port=10025 named_attribute: helo_name=localhost named_attribute: protocol_name=ESMTP named_attribute: client_address_type=2 named_attribute: dsn_orig_rcpt=rfc822;elenazangari@aol.com original_recipient: elenazangari@aol.com recipient: elenazangari@aol.com named_attribute: dsn_orig_rcpt=rfc822;law ... *** MESSAGE CONTENTS active/BF15B373EF8 *** Received: from localhost (localhost.localdomain [127.0.0.1]) by relay.avril.work (Postfix) with ESMTP id BF15B373EF8; Mon, 26 Dec 2022 16:56:30 +0100 (CET) X-Virus-Scanned: Debian amavisd-new at relay.avril.work Received: from relay.avril.work ([127.0.0.1]) by localhost (relay.avril.work [127.0.0.1]) (amavisd-new, port 10026) with ESMTP id 1QIafpiF3I2g; Mon, 26 Dec 2022 16:56:30 +0100 (CET) Received: from [127.0.0.1] (unknown [171.7.235.230]) by relay.avril.work (Postfix) with ESMTPSA id AA0A1373EEC; Mon, 26 Dec 2022 16:56:19 +0100 (CET) From: "CANADlAN PHARNACY" <test@glomus-gps.de>
Useful commands
- Check postfix service status:
sudo service postfix status
- Display of all queued mails:
postqueue -p
- Display the mail header and contents:
postcat -q “QUEUE_ID”- e.g.:
postcat -q E2A85373E7C
- Find SPAM senders using Postfix with SSH (do it as root):
zgrep -h 'sasl_method' /var/log/mail.log* | cut -d' ' -f9 | cut -d= -f2 | sort | uniq -c | sort -nr
-
- I chose this command:
postqueue -p | tail -n 1- Output on 10.01.2023:
– 287533 Kbytes in 53646 Requests.
- Output on 12.01.2023:
– 38504 Kbytes in 8458 Requests.(it is less then on 10.01.2023, maybe because I've deleted all deferred mails)
- Output on 13.01.2023:
– 38540 Kbytes in 8552 Requests.(it is more then on 12.01.2023, because the root still tries to send mails. Like:
root@relay:/var/log# postcat -q C9CCA24EA03 *** ENVELOPE RECORDS maildrop/C9CCA24EA03 *** message_arrival_time: Fri Jan 13 04:15:02 2023 named_attribute: rewrite_context=local sender_fullname: CronDaemon sender: root named_attribute: encoding=8bit recipient: root *** MESSAGE CONTENTS maildrop/C9CCA24EA03 *** From: root (Cron Daemon) To: root Subject: Cron <root@relay> docker restart jrserver MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit X-Cron-Env: <SHELL=/bin/sh> X-Cron-Env: <HOME=/root> X-Cron-Env: <PATH=/usr/bin:/bin> X-Cron-Env: <LOGNAME=root> jrserver *** HEADER EXTRACTED maildrop/C9CCA24EA03 *** *** MESSAGE FILE END maildrop/C9CCA24EA03 ***
qshape active- This command delivered
- (at 10.01.2023): …
TOTAL 78494 0 0 0 0 0 0 0 0 0 78494 - (at 12.01.2023): …
TOTAL 78494 0 0 0 0 0 0 0 0 0 78494→ the same as on 10.01.2023 - (at 13.01.2023): …
TOTAL 78494 0 0 0 0 0 0 0 0 0 78494→ the same as on 12.01.2023
qshape deferred- This command delivered (at 10.01.2023): …
TOTAL 481187 0 0 0 0 0 0 0 0 0 481187… - After that I've removed all mails from deferred queue with
postsuper -d ALL deferred- Output was:
postsuper: Deleted: 45378 messages
- Then the command
qshape deferreddelivered : …TOTAL 0 0 0 0 0 0 0 0 0 0 0…
Misc
Maybe it can be useful.
IMAP and POP3 - protocols to receive emails.
SMTP - protocol normally used to send emails.
Dovecot
https://wiki.ubuntuusers.de/Dovecot/:
Dovecot ist ein Open-Source-E-Mailserver für Linux, der die Protokolle IMAP und POP3 unterstützt. Seine Spezialität sind kleine Netzwerke (ca. 200 Mailboxen) bis hin zu großen Firmennetzwerken (über 1000 Mailboxen). Die Daten werden im mbox- bzw. Maildir-Format abgelegt und können so leicht migriert oder in E-Mail-Clients genutzt werden, die lokal auf die Daten zugreifen. Des Weiteren müssen keine Benutzer angelegt werden. Jeder lokale Benutzer kann sich direkt auf dem Mailserver mit seinem Benutzerdaten anmelden.
Postfix
Mail server to sent emails with SMTP.
Found facts
- It seems that SPAM mails were sent from account
test@glomus-gps.de - It seems that my server still tries to send emails (SPAM?) with/from root account.
- Content of
postqueue -p| grep “Jan 13”:
0169624EA15 395 Fri Jan 13 08:15:03 root E3A0224E9F6 397 Fri Jan 13 01:00:02 root ... D954C24EA07 397 Fri Jan 13 05:15:02 root C9CCA24EA03 397 Fri Jan 13 04:15:02 root
- Then the result of command:
postcat -q C9CCA24EA03:
*** ENVELOPE RECORDS maildrop/C9CCA24EA03 *** message_arrival_time: Fri Jan 13 04:15:02 2023 named_attribute: rewrite_context=local sender_fullname: CronDaemon sender: root named_attribute: encoding=8bit recipient: root *** MESSAGE CONTENTS maildrop/C9CCA24EA03 *** From: root (Cron Daemon) To: root Subject: Cron <root@relay> docker restart jrserver MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit X-Cron-Env: <SHELL=/bin/sh> X-Cron-Env: <HOME=/root> X-Cron-Env: <PATH=/usr/bin:/bin> X-Cron-Env: <LOGNAME=root> jrserver *** HEADER EXTRACTED maildrop/C9CCA24EA03 *** *** MESSAGE FILE END maildrop/C9CCA24EA03 ***
Made changes
- Changed password from account
test@glomus-gps.de - Deleted all deferred mails in queue with
postsuper -d ALL deferred- Output was:
postsuper: Deleted: 45378 messages
- 12.01.2023
- Commented out lines 91 - 94 from
/etc/postfix/main.cf
# smtpd_relay_restrictions = # permit_mynetworks # permit_sasl_authenticated # defer_unauth_destination
- 13.01.2023
- Emptied maildrop
postsuper -d ALL maildrop- Output:
postsuper: Deleted: 1648 messages
postqueue -p | tail -n 1- Output:
– 37902 Kbytes in 6907 Requests.
- Deleted all mails in active queue:
postsuper -d ALL active- Output:
postsuper: Deleted: 6907 messages
- At ca. 11:14 I've started the postfix service:
sudo service postfix start
- 20.01.2023
- Changed the log location of cron job which has restarted my docker container jrserver
sudo crontab -e- Then changed the cron job (line with docker restart):
*/15 * * * * docker restart jrserver- to
*/15 * * * * docker restart jrserver » /var/log/docker.log 2>&1
- Explanation: by default the cron job sends mails about unsuccessful restarts, and now (after adding
»…) it should use the log file- see also:
