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)

• + 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 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”?

These tasks should be done regularly to check whether the server sends SPAM.

• - 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 UCEProtect

• 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

• Tips to Block Email Spam with Postfix SMTP Server
• 7 Effective Tips for Blocking Email Spam with Postfix SMTP Server

• How do I deal with a compromised server?
• How To Stop a Spamming Server
• Postfix Basic Configuration
• My Postfix installation is sending out spam; how to stop it?
• How to analyze cause of postfix server sending spam

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

/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

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>

• 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>

• 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

• 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 <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 deferred delivered : … TOTAL 0 0 0 0 0 0 0 0 0 0 0 …

Maybe it can be useful.

IMAP and POP3 - protocols to receive emails.

SMTP - protocol normally used to send emails.

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.

Mail server to sent emails with SMTP.

• 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 ***

• 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:
        • Crontab Log: How to Log the Output of My Cron Script
        • How to log cron jobs?
        • Disable the eMail Alert By Crontab Command On a Linux or Unix-like Systems