Dovecot not accepting passwords

$ telnet 127.0.0.1 25
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
220 moonpoint.com ESMTP Sendmail 8.14.7/8.14.7; Sat, 6 Aug 2016 09:26:06 -0400
quit
221 2.0.0 moonpoint.com closing connection
Connection closed by foreign host.
$

Since the Sendmail SMTP service seemed to be functioning properly, I next checked the Dovecot POP3/POP3S software on the system. I entered the commands an email client would submit to authenticate with the server on the POP3 port, port 110, i.e., pass followed by the user's login id then pass and the password for the user's account. I received an immediate response to the user command, but when I entered the pass command followed by the password and hit Enter I didn't see any response even after waiting much longer than I would expect to have to wait for a response. So I hit Ctrl-], i.e., the Ctrl and ] keys to return to the Telnet prompt and then exited from the telnet program.

$ telnet 127.0.0.1 110
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
+OK Dovecot ready.
user nell
+OK
pass ASecretPassword
^]

telnet> quit
Connection closed.
$

I asked another user to attempt to download her email using the Outlook 2016 email client she uses to check her email. Outlook was not able to successfully download her email and reported the following error:

Task 'anne2@moonpoint.com - Receiving' reported error (0x8004210A): 'The operation timed out waiting for a response from the receiving (POP) server. If you continue to receive this message, contact your server administrator or Internet service provider (ISP).'

I then logged into the root account on the system, checked the time and restarted the Dovecot POP3/POP3/IMAP/IMAPS service. After I restarted the service, I was able to successfully log into the user's account using Telnet. Once I had logged in, I issued the stat command which shows the number of messages in the user's inbox, in this case 357, and the number of bytes of storage used by all of the messages. I then issued the command retr 357 to retrieve the last message sent to the user, which was a test message I had sent from an external email account. I then issued the quit command to terminate the POP3 connection.

# date
Sat Aug  6 09:41:02 EDT 2016
# service dovecot restart
Redirecting to /bin/systemctl restart  dovecot.service
[root@moonpoint ~]# telnet 127.0.0.1 110
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
+OK Dovecot ready.
user nell
+OK
pass ASecretPassword
+OK Logged in.
stat
+OK 357 25659570
retr 357
+OK 5519 octets
Return-Path: <moonpoint@example.com>
Received: from ABC004-OMNI.example.com (ABC004-omni.example.com [10.10.90.45])
	by moonpoint.com (8.14.7/8.14.7) with ESMTP id u76DUvO3022890;
	Sat, 6 Aug 2016 09:31:03 -0400
<text snipped>
quit
+OK Logging out.
Connection closed by foreign host.
#

Initially, I thought I would see entries in the /var/log/maillog file that I had seen on July 4, 2016 when the same user had reported that she was not receiving any email - see Dovecot - client connections are being dropped. But on that occasion, when I connected to port 110 then entered the user command followed by her user name and hit Enter the connection was immediately terminated before I could enter the pass command. I looked for the "client connections are being dropped" messages from Dovecot in the log file that I had seen on that date, but saw none.

# grep "client connections" /var/log/maillog 
#

I then searched for any warning messages, but saw only one entry in the log file containing the word "warning" and that was for the time when I restarted Dovecot.

# grep "Warning" /var/log/maillog
Aug  6 09:41:08 moonpoint dovecot: master: Warning: Killed with signal 15 (by pid=1 uid=0 code=kill)
#

However, looking through the log file, I saw entries like the following one for IP address 71.6.158.166:

# grep '71.6.158.166' /var/log/maillog | tail 
Aug  6 10:07:41 moonpoint dovecot: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=71.6.158.166, lip=192.168.0.5, TLS, session=<05TStGc5wwBHBp6m>
Aug  6 10:07:41 moonpoint dovecot: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=71.6.158.166, lip=192.168.0.5, TLS handshaking: SSL_accept() failed: error:140760FC:SSL routines:SSL23_GET_CLIENT_HELLO:unknown protocol, session=<GCHUtGc51QBHBp6m>
Aug  6 10:07:42 moonpoint dovecot: pop3-login: Disconnected (no auth attempts in 1 secs): user=<>, rip=71.6.158.166, lip=192.168.0.5, TLS, session=<jXnZtGc54wBHBp6m>
Aug  6 10:07:42 moonpoint dovecot: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=71.6.158.166, lip=192.168.0.5, TLS, session=<2kzetGc5/ABHBp6m>
Aug  6 10:07:42 moonpoint dovecot: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=71.6.158.166, lip=192.168.0.5, TLS, session=<6y7jtGc56gBHBp6m>
Aug  6 10:07:43 moonpoint dovecot: pop3-login: Disconnected (no auth attempts in 1 secs): user=<>, rip=71.6.158.166, lip=192.168.0.5, TLS, session=<amfntGc5OgBHBp6m>
Aug  6 10:07:43 moonpoint dovecot: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=71.6.158.166, lip=192.168.0.5, TLS, session=<N2XrtGc5agBHBp6m>
Aug  6 10:07:43 moonpoint dovecot: pop3-login: Disconnected (no auth attempts in 6 secs): user=<>, rip=71.6.158.166, lip=192.168.0.5, TLS: Disconnected, session=<TJfrtGc5lwBHBp6m>
Aug  6 10:07:43 moonpoint dovecot: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=71.6.158.166, lip=192.168.0.5, TLS, session=<LqfxtGc5oABHBp6m>
Aug  6 10:07:43 moonpoint dovecot: pop3-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=71.6.158.166, lip=192.168.0.5, TLS handshaking: SSL_accept() failed: error:1408A0C1:SSL routines:SSL3_GET_CLIENT_HELLO:no shared cipher, session=<0jvztGc5uwBHBp6m> 

I found there were 24 entries related to that IP address in the mail log file all of which were "pop3-login" entries.

# grep --count '71.6.158.166' /var/log/maillog
24
#

The 71.6.158.166 IP address wasn't one I would expect from any legitimate user of the system. When I performed an nslookup on the address to determine the fully qualified domain name (FQDN) associated with it, I found it was ninja.census.shodan.io.

# nslookup 71.6.158.166 8.8.8.8
Server:		8.8.8.8
Address:	8.8.8.8#53

Non-authoritative answer:
166.158.6.71.in-addr.arpa	name = ninja.census.shodan.io.

Authoritative answers can be found from:

#

When I checked the allocation of the IP address at the American Registry for Internet Numbers (ARIN), I found the 71.6.158.166 address is in a block of IP addresses assigned to CariNet, Inc. in San Diego California in the United States.

When I checked the DShield site, which is a firewall log correlation site which receives logs from volunteers worldwide which are used to analyze attack trends, I found the 71.6.158.166 I address listed there with submitter diversity rated very high. DShield showed it was first linked to a port 110 (POP3) scan on November 5, 2015 and last seen conducting such a scan by someone submitting logs to DShield on July 11, 2016. It was also found to be conducting a port 143 (IMAP) scan over that same date range.

External Threat Feeds

This data was retrieved from various external threat feeds

I also saw the IP address associated with port 22 (SSH) scanning, so I checked the Fail2ban log on the system, but saw no evidence that the system had been associated with failed attempts to break into the system via SSH. Nor did I see any entries in /var/log/secure indicating any failed SSH logins for that IP address.

# grep '71.6.158.166' /var/log/fail2ban.log
# grep '71.6.158.166' /var/log/secure
#

I didn't see any entries in the system's web server logs for the last month related to the IP address, either.

After looking through the system's logs, I recalled that I had read something about "shodan", the domain name for the system with that IP address, before and a relationship between the name and network security, but couldn't remember the details. Sentient Hyper-Optimized Data Access Network (SHODAN) is the name of an artificial intelligence (AI) character in the video games System Shock and System Shock 2. The name was adopted by John Matherly, a computer programmer who created a search engine with that name and registered the domain name shodan.io. The search engine scours the web for systems listening on certain ports and grabs the banners provided by the software listening on those ports. Such banner grabbing can often be used to identify the particular software program listening on the port and, perhaps, even the version number for the application. E.g., if you perform a search on "pop3" on the Shodan website, you will see a list of IP adresses and physical locations associated with those IP addresses for systems listening on the POP3 port, port 110. You will see the banners returned by those systems as well. You can also search by IP address and see a list of services found to be offered at that IP address with the banners seen by the Shodan search engine, such as FTP, HTTP, IMAP, POP3, and SMTP banners, when it connected to the IP address on those ports.

 

Justdeals Daily Electronics Deals