lfd not blocking multiple smtp auth failed login attempts

[mikan]

Hi everyone,

I just noticed that some failed smtp login attempts logged into exim_mainlog were not blocked by lfd after the limit I configured (LF_SMTPAUTH is set to 10). It works most of the time, but I don't know if there is something different with these attempts, they don't get blocked and in two days, from the same IP, more than 850 failed logins were logged.

Here is a part of my exim_mainlog:

Code: Select all

2015-06-14 14:15:37 SMTP connection from [62.210.XXX.XXX]:50446 (TCP/IP connection count = 1)
2015-06-14 14:15:40 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:50446: 535 Incorrect authentication data (set_id=administrator)
2015-06-14 14:15:40 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:50446 lost (error: Connection reset by peer)
2015-06-14 14:15:51 SMTP connection from [62.210.XXX.XXX]:57033 (TCP/IP connection count = 1)
2015-06-14 14:15:57 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:57033: 535 Incorrect authentication data (set_id=administrator)
2015-06-14 14:15:57 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:57033 lost (error: Connection reset by peer)
2015-06-14 14:16:02 SMTP connection from [62.210.XXX.XXX]:62264 (TCP/IP connection count = 1)
2015-06-14 14:16:02 SMTP connection from [62.210.XXX.XXX]:62266 (TCP/IP connection count = 2)
2015-06-14 14:16:02 SMTP connection from [62.210.XXX.XXX]:62577 (TCP/IP connection count = 3)
2015-06-14 14:16:02 SMTP connection from [62.210.XXX.XXX]:62578 (TCP/IP connection count = 4)
2015-06-14 14:16:04 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:62266: 535 Incorrect authentication data (set_id=administrator)
2015-06-14 14:16:04 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:62264: 535 Incorrect authentication data (set_id=administrator)
2015-06-14 14:16:04 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:62577: 535 Incorrect authentication data (set_id=administrator)
2015-06-14 14:16:04 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:62578: 535 Incorrect authentication data (set_id=administrator)
2015-06-14 14:16:04 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:62577 lost (error: Connection reset by peer)
2015-06-14 14:16:04 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:62264 lost (error: Connection reset by peer)
2015-06-14 14:16:04 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:62578 lost (error: Connection reset by peer)
2015-06-14 14:16:04 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:62266 lost (error: Connection reset by peer)
2015-06-14 16:30:13 SMTP connection from [62.210.XXX.XXX]:50769 (TCP/IP connection count = 1)
2015-06-14 16:30:16 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:50769: 535 Incorrect authentication data (set_id=accounts)
2015-06-14 16:30:16 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:50769 lost (error: Connection reset by peer)
2015-06-14 16:30:28 SMTP connection from [62.210.XXX.XXX]:58384 (TCP/IP connection count = 1)
2015-06-14 16:30:34 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:58384: 535 Incorrect authentication data (set_id=accounts)
2015-06-14 16:30:34 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:58384 lost (error: Connection reset by peer)
2015-06-14 16:30:34 SMTP connection from [62.210.XXX.XXX]:61872 (TCP/IP connection count = 1)
2015-06-14 16:30:34 SMTP connection from [62.210.XXX.XXX]:61878 (TCP/IP connection count = 2)
2015-06-14 16:30:34 SMTP connection from [62.210.XXX.XXX]:61879 (TCP/IP connection count = 3)
2015-06-14 16:30:34 SMTP connection from [62.210.XXX.XXX]:61880 (TCP/IP connection count = 4)
2015-06-14 16:30:37 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:61879: 535 Incorrect authentication data (set_id=accounts)
2015-06-14 16:30:37 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:61878: 535 Incorrect authentication data (set_id=accounts)
2015-06-14 16:30:37 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:61880: 535 Incorrect authentication data (set_id=accounts)
2015-06-14 16:30:37 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:61872: 535 Incorrect authentication data (set_id=accounts)
2015-06-14 16:30:37 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:61878 lost (error: Connection reset by peer)
2015-06-14 16:30:37 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:61880 lost (error: Connection reset by peer)
2015-06-14 16:30:37 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:61879 lost (error: Connection reset by peer)
2015-06-14 16:30:37 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:61872 lost (error: Connection reset by peer)
2015-06-14 16:43:36 SMTP connection from [62.210.XXX.XXX]:52856 (TCP/IP connection count = 1)
2015-06-14 16:43:38 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:52856: 535 Incorrect authentication data (set_id=abc123)
2015-06-14 16:43:38 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:52856 lost (error: Connection reset by peer)
2015-06-14 16:43:51 SMTP connection from [62.210.XXX.XXX]:60470 (TCP/IP connection count = 1)
2015-06-14 16:43:54 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:60470: 535 Incorrect authentication data (set_id=abc123)
2015-06-14 16:43:54 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:60470 lost (error: Connection reset by peer)
2015-06-14 16:43:58 SMTP connection from [62.210.XXX.XXX]:63956 (TCP/IP connection count = 1)
2015-06-14 16:43:58 SMTP connection from [62.210.XXX.XXX]:63962 (TCP/IP connection count = 2)
2015-06-14 16:43:58 SMTP connection from [62.210.XXX.XXX]:63963 (TCP/IP connection count = 3)
2015-06-14 16:43:59 SMTP connection from [62.210.XXX.XXX]:63964 (TCP/IP connection count = 4)
2015-06-14 16:44:01 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:63956: 535 Incorrect authentication data (set_id=abc123)
2015-06-14 16:44:01 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:63964: 535 Incorrect authentication data (set_id=abc123)
2015-06-14 16:44:01 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:63963: 535 Incorrect authentication data (set_id=abc123)
2015-06-14 16:44:01 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:63962: 535 Incorrect authentication data (set_id=abc123)
2015-06-14 16:44:01 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:63956 lost (error: Connection reset by peer)
2015-06-14 16:44:01 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:63962 lost (error: Connection reset by peer)
2015-06-14 16:44:01 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:63963 lost (error: Connection reset by peer)
2015-06-14 16:44:01 SMTP connection from 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:63964 lost (error: Connection reset by peer)

I dug into csf source code (although I don't know Perl) and if I am not wrong, it should be blocked by the regular expressions in regex.pm, line 255 (Exim SMTP AUTH block).

Is this a bug or a misconfiguration (although, as I said, other "kind" of attempts get blocked)?

Thanks!

Marc-André

[ForumAdmin]

csf does detect the log line format of:

Code: Select all

2015-06-14 14:15:40 dovecot_login authenticator failed for 62-210-XXX-XXX.rev.poneytelecom.eu (User) [62.210.XXX.XXX]:50446: 535 Incorrect authentication data (set_id=administrator)

But only that one. So, my guess would be that either:

1. It did not block because insufficient triggers were not met within LF_INTERVAL seconds

2. lfd was restarted at any point which would reset the interval tracking

3. If the server was being flooded with connections, syslog will buffer log lines interfering with LF_INTERVAL

4. SMTPAUTH_LOG is not point to the correct exim log

Other than those, no idea since the feature works in practice and is part of the whole LF_* option log tracking and blocking.

[mikan]

Thanks, it must be the LF_INTERVAL setting which was too low. I changed the value and will check if this fixes the problem.

Kind regards,

Marc-André