[Solved] User logins/hour excessive causing Fail2Ban blocks

1

I posted yesterday about the external IP address of my internal network being blocked by Fail2Ban. I have temporarily overcome by unbanning the IP address in the Dovecot and Recidive jails for Fail2Ban but this will be overwritten by the next update so I want to get to the route cause…

This is the weekly usage report:

User logins per hour
════════════════════ 
                                   imap smtp │ timespan
─────────────────────────────────────────────┼─────────
Email_Account_1_at_Domain1          3.2  0.0 │ 7.0 days
Email_Account_2_at_Domain1          0.6  0.0 │ 6.2 days
Email_Account_1_at_Domain2          3.3  0.0 │ 6.8 days
Email_Account_2_at_Domain2          8.5  0.1 │ 6.9 days
Email_Account_3_at_Domain2        902.1  0.0 │ 7.0 days
Email_Account_4_at_Domain2          3.4  0.0 │ 6.7 days
Email_Account_5_at_Domain2          4.7  0.1 │ 6.7 days
Email_Account_6_at_Domain2          3.5  0.0 │ 6.7 days
Email_Account_7_at_Domain2          4.6  0.0 │ 7.0 days
Email_Account_8_at_Domain2          3.8  0.0 │ 6.7 days
Email_Account_1_at_Domain3        909.0  0.0 │ 7.0 days

There are two accounts here that are constantly logging into imap every few seconds from what appears to be local machine (rip=127.0.0.1, lip=127.0.0.1)

Below a sample from /var/log/mail.log

Mar 31 10:59:34 imap(Email_Account_3_at_Domain2): Info: Logged out in=12 out=412
Mar 31 10:59:34 imap-login: Info: Login: user=<Email_Account_3_at_Domain2>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=28024, secured, session=<+jD0nyOiKrF/AAAB>
Mar 31 10:59:34 imap(Email_Account_3_at_Domain2): Info: Logged out in=12 out=412
Mar 31 10:59:38 imap-login: Info: Login: user=< Email_Account_1_at_Domain3>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=28026, TLS, session=<kVIzoCOiaLp/AAAB>
Mar 31 10:59:38 imap(Email_Account_1_at_Domain3): Info: Logged out in=445 out=2973
Mar 31 10:59:42 imap-login: Info: Login: user=<Email_Account_3_at_Domain2>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=28028, secured, session=<cjFvoCOiLrF/AAAB>
Mar 31 10:59:42 imap(Email_Account_3_at_Domain2): Info: Logged out in=12 out=412
Mar 31 10:59:47 imap-login: Info: Login: user=< Email_Account_1_at_Domain3>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=28030, secured, session=<7la9oCOiNLF/AAAB>
Mar 31 10:59:47 imap(Email_Account_1_at_Domain3): Info: Logged out in=12 out=412
Mar 31 10:59:47 imap-login: Info: Login: user=< Email_Account_1_at_Domain3>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=28033, secured, session=<SGK+oCOiOLF/AAAB>
Mar 31 10:59:47 imap(Email_Account_1_at_Domain3): Info: Logged out in=12 out=412

I have logged into/out of the accounts on WebMail on the same server to ensure they weren’t constantly polling.

Can anyone advise on likely root cause/resolution?

Thank you

2

I’m not sure. Are you using Nextcloud? Does it use IMAP to log in?

3

Not using Nextcloud but have logged in/out of that as well and it hasn’t changed the incidence of local logins from these two accounts.

What is the maid - mpid=28030?

This is incrementing by two for every login - is this a type of process ID?

4

Have resolved (by running setup again)

sudo mailinabox

So I haven’t found the root cause of the issue but at least I can move forward.

I’ll monitor and update again if it re-occurs.

5

Spoke too soon :confused: symptoms have returned.

Have noticed the difference in Method between a ‘valid’ imap call and ‘invalid’ map call (from my perspective)

Excessive:

method=PLAIN

Aligns with timings of real account logins:

method=LOGIN

Does anyone know what originates the two different types

6

Every end-user application should be using the PLAIN method.

I would look at other log files to see what other activity is ocurring. Connections from 127.0.0.1 are authentication checks from other services running on the box (Roundcube, Nextcloud, Contacts, Calendar, Exchange ActiveSync, the Mail-in-a-Box control panel).

7

Thanks @JoshData

I have found this from 2015

which is exactly the same issue (at least the entries in mail.log are the same) and had similar implications with fail2ban blocking. The user indicated it might be related to ActiveSynce / z-push so will look at that.

8

Have found this in z-push-error.log:

31/03/2020 14:46:18 [ 3859] [WARN] [Email_Account_3_at_Domain2] BackendIMAP->getImapIdFromFolderId(‘9b5513f7’) = not initialized!

31/03/2020 14:46:19 [ 3869] [WARN] [Email_Account_1_at_Domain3] BackendIMAP->getImapIdFromFolderId(‘c1449dea’) = not initialized!

Which corresponds to the two accounts with issues and no other accounts reported in this log file. Any ideas where these folders are created/exist?

9

Believing that the errors may be related to authentication issues for the accounts using local services I have changed the password for one of the two accounts experiencing the issues.

This (at the moment) appears to have resolved it for that account. I’ll monitor and review tomorrow and if it remains resolved I’ll amend the password for the other account and confirm one way or another.

10

Update as of this morning, no further occurrences since 22:57 when the password was changed for the one account and repeated instances continue for the account that has not had password changed.

I’ll arrange for the password of the other account to be changed, monitor and feedback.

11

Further update. Changed password for the second account as I had done for the first. This appeared to have no apparent difference. Changed password a second time (removing special characters) and incidence has dropped from 86 times (over three minutes) to once a minute (at exactly the same time each minute xx:xx:17).

Will continue to monitor.

12

Looks like this is now pretty much solved by changing the passwords. About half an hour after the second account had the password changed the reduced incidence of the issue stopped completely. So an invalid imap login which was spamming the log file:

imap-login: Info: Login: user=user1@domain1.co.uk, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=27717, TLS, session=<WIyI4Tqi9MN/AAAB>

Has now been replaced by ‘valid’ imap logins with valid Remote IP’s and Local IP’s:

imap-login: Info: Login: user=user1@domain1.co.uk, method=PLAIN, rip=214.31.121.97, lip=68.183.36.125, mpid=4234, TLS, session=

I have noted a very low volume remaining but this is now every few hours rather than multiple times in the same second.

@JoshData, can you mark the subject as [Solved] as I get ‘You are not permitted to view the requested resource’

13

Yep. Got it. Glad you got to the bottom of it.