====== 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.de'' was 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 [[https://www.uceprotect.net/en/rblcheck.php|UCEProtect]] * **-** Fix certificate problems during fetching of mails (e.g. in Thunderbird) * **-** Prevent login attempts from unknown ''@wialon-consulting.de'' accounts (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: * https://www.tecmint.com/prevent-ssh-brute-force-login-attacks/ * **-** 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 deferred'' for deferred queue * **-** check log file ''/var/log/docker.log'' * **-** check whether the IP 94.199.215.198 is not blacklisted at [[https://www.uceprotect.net/en/rblcheck.php|UCEProtect]] ===== Some documentation about how to deal with compromised server ===== * [[https://jvulinux.wordpress.com/2014/12/26/commands-to-check-spamming-in-postfix-mail-server/|Commands to check spamming in POSTFIX mail 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 * [[https://www.interserver.net/tips/kb/tips-to-block-email-spam-with-postfix-smtp-server/|Tips to Block Email Spam with Postfix SMTP Server]] * [[https://www.linuxbabe.com/mail-server/block-email-spam-postfix|7 Effective Tips for Blocking Email Spam with Postfix SMTP Server]] * [[https://serverfault.com/questions/218005/how-do-i-deal-with-a-compromised-server|How do I deal with a compromised server?]] * [[https://www.liquidweb.com/kb/how-to-stop-a-spamming-server/|How To Stop a Spamming Server]] * [[http://www.postfix.org/BASIC_CONFIGURATION_README.html|Postfix Basic Configuration]] * [[https://unix.stackexchange.com/questions/121517/my-postfix-installation-is-sending-out-spam-how-to-stop-it|My Postfix installation is sending out spam; how to stop it?]] * [[https://serverfault.com/questions/1050276/how-to-analyze-cause-of-postfix-server-sending-spam|How to analyze cause of postfix server sending spam]] Not very good (for me at the moment): * [[https://abusix.com/resources/network-security/how-to-check-if-your-server-is-sending-spam/|How to Check if Your Server is Sending Spam]] - not really much information * [[https://documentation.clearos.com/content:en_us:kb_o_i_m_sending_spam_how_do_i_stop_it|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=, 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=, 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] -> ,,,,,,,,,,,,,,,, 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=, 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=, 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=, 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=, 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=, 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=, 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=, 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=, 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= 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= 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= 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= 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= 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= 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= 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= 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= 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= 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= 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= 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= 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= ===== 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: 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 docker restart jrserver MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit X-Cron-Env: X-Cron-Env: X-Cron-Env: X-Cron-Env: 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" ==== 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'' * [[https://de.godaddy.com/help/spam-absender-finden-sie-mit-postfix-mit-ssh-40422?lc=en-US|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'' * [[https://serverfault.com/questions/58196/how-do-i-check-the-postfix-queue-size|How do I check the postfix queue size?]]: * 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 docker restart jrserver MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit X-Cron-Env: X-Cron-Env: X-Cron-Env: X-Cron-Env: 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 deferred'' delivered : ... ''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 docker restart jrserver MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit X-Cron-Env: X-Cron-Env: X-Cron-Env: X-Cron-Env: 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: * [[https://www.thegeekstuff.com/2012/07/crontab-log/|Crontab Log: How to Log the Output of My Cron Script]] * [[https://stackoverflow.com/questions/4811738/how-to-log-cron-jobs|How to log cron jobs?]] * [[https://www.cyberciti.biz/faq/disable-the-mail-alert-by-crontab-command/|Disable the eMail Alert By Crontab Command On a Linux or Unix-like Systems]]