Suggested change to Exim SMTP AUTH regex

[terryr]

Hi,

I had a problem with 535 incorrect authentication in exim mainlog not being picked up. I did some research using a regex tester and the Exim SMTP AUTH line from regex.pm (5.54 version) which is:

Code: Select all

^\S+\s+\S+\s+(\S+) authenticator failed for \S+ (\S+ )?\[(\S+)\]:(\S*:)? 535 Incorrect authentication data( \(set_id=(\S+)\))?

The choice of log selectors enabled in Exim will definitely impact whether the current regex in regex.pm will match. Log selectors which cause the regex to fail appear to be:
-pid (process id - in example below it's [12898]
-incoming_interface - in example below it's I=[1.2.3.4]
-outgoing_port - in example below it's 25

I use the +all log selector. Example output of log selector "all" is:

Code: Select all

2012-05-23 14:07:24 [12898] dovecot_login authenticator failed for (ylmf-pc) [183.7.98.74]:3654 I=[1.2.3.4]:25: 535 Incorrect authentication data (set_id=hlvest2@mail.domain[dot]com)

Note: [dot] added because I can't post urls.

The third field in the log line is the process id. This is where the regex.pm line fails initially. The first part of the regex

Code: Select all

^\S+\s+\S+\s+(\S+)

matches 2012-05-23 14:07:24 [12898] instead of 2012-05-23 14:07:24 [12898] dovecot_login. Changing that part of the regex to

Code: Select all

^\S+\s+\S+\s+(\[\S+\]\s)?(\S+)

solves the problem and matches 2012-05-23 14:07:24 [12898] dovecot_login.

The second problem comes in with the placement of the ending semicolon and the insertion of the tenth field - I=[1.2.3.4]:25. I changed the part of the regex that matches the ip and port to match both the external ip and optional port as well as an optional ip and port for the server.

Complete new regex is

Code: Select all

^\S+\s+\S+\s+(?:\[\S+\]\s)?(\S+) authenticator failed for \S+ (\S+ )?\[(\S+)\](:)?(?:\S*)?(?:\s)?(?:\S*)?(?::) 535 Incorrect authentication data( \(set_id=(\S+)\))?

Note: I added ?: in a few places so that the $ip=$3 and $acc=$6 remained the same as in regex.pm.

I am no regex expert. I'm sure it could be improved upon. I've tested it with lines from my log file using +all and with lines from log files found when googling. Seems to work. I am going to put it into regex.custom.pm to see if it will work. My server's pretty small potatoes though and I don't experience attacks often so it may take a while for me to test it out in real life.

For your consideration.

Thanks,
Terry

[terryr]

Hi,

Thanks for the new regex. It works great for some instances but not others. The problem is the colon. The final colon is always after the last ip or port selected through log selectors, i.e. there will always be a colon before the 535 error message - : 535. The colon separates the "data" part of the log from the "message" part of the log line. It has nothing to do with the ip or port. Exim uses colons like this in some of its other messages. So the possible scenarios are:

1.2.3.4:
1.2.3.4:3654:
1.2.3.4:3654 I=1.2.3.4:
1.2.3.4:3654 I=1.2.3.4:25:
1.2.3.4:3654 25:
1.2.3.4 I=1.2.3.4:
1.2.3.4 I=1.2.3.4:25:
1.2.3.4 25:

Testing the regex with these log lines which contain the possibilities:

Code: Select all

Works on:
2012-01-21 08:58:38 login authenticator failed for adsl-x-x-x-x.dsl.okcyok.swbell[dot]net (zion) [1.2.3.4]: 535 Incorrect authentication data (set_id=admin)
2012-05-23 14:07:24 [12345] dovecot_login authenticator failed for (ylmf-pc) [1.2.3.4]:3654: 535 Incorrect authentication data (set_id=admin)
2012-05-23 14:07:24 [12345] dovecot_login authenticator failed for (ylmf-pc) [1.2.3.4]:3654 I=1.2.3.4: 535 Incorrect authentication data (set_id=admin)
2012-05-23 14:07:24 [12345] dovecot_login authenticator failed for (ylmf-pc) [1.2.3.4]:3654 I=1.2.3.4:25: 535 Incorrect authentication data (set_id=admin)

Fails on:
2012-05-23 14:07:24 [12345] dovecot_login authenticator failed for (ylmf-pc) [1.2.3.4]:3654 25: 535 Incorrect authentication data (set_id=admin)
2012-05-23 14:07:24 [12345] dovecot_login authenticator failed for (ylmf-pc) [1.2.3.4] I=1.2.3.4: 535 Incorrect authentication data (set_id=admin)
2012-05-23 14:07:24 [12345] dovecot_login authenticator failed for (ylmf-pc) [1.2.3.4] I=1.2.3.4:25: 535 Incorrect authentication data (set_id=admin)
2012-05-23 14:07:24 [12345] dovecot_login authenticator failed for (ylmf-pc) [1.2.3.4] 25: 535 Incorrect authentication data (set_id=admin)

Terry

[ForumAdmin]

Thank you for the detailed response. I'll look at further changes to the regex.

[ForumAdmin]

Hopefully v5.56 will now detect the various combinations correctly.

[terryr]

Thanks for the changes. Seems to be working fine now.

Terry

[WBA]

Hello, I seem to be having this same problem and it is not being picked up by CSF
Currently using version 5.59
"csf is already at the latest version: v5.59"

Here is what I see in /var/log/exim/mainlog

2012-07-26 10:51:04 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=finlay)
2012-07-26 10:54:59 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=alexander)
2012-07-26 10:55:21 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=alexander)
2012-07-26 10:59:18 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=oliver)
2012-07-26 10:59:39 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=oliver)
2012-07-26 11:03:38 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=luke)
2012-07-26 11:03:59 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=luke)
2012-07-26 11:07:58 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=logan)
2012-07-26 11:08:19 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=logan)
2012-07-26 11:12:18 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=matthew)
2012-07-26 11:12:39 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=matthew)
2012-07-26 11:16:38 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=alex)
2012-07-26 11:16:59 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=alex)
2012-07-26 11:20:58 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=connor)
2012-07-26 11:21:20 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=connor)
2012-07-26 11:25:18 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=brandon)
2012-07-26 11:25:40 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=brandon)
2012-07-26 11:29:38 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=ryan)
2012-07-26 11:30:00 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=ryan)
2012-07-26 11:33:55 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=sam)
2012-07-26 11:34:17 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=sam)
2012-07-26 11:38:15 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=freddie)
2012-07-26 11:38:37 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=freddie)
2012-07-26 11:42:34 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=dylan)
2012-07-26 11:42:56 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=dylan)
2012-07-26 11:46:55 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=cody)
2012-07-26 11:47:16 plain authenticator failed for portal_peceofmind_com ([10.10.11.6]) [71.43.34.58]: 535 Incorrect authentication data (set_id=cody)
ANy help would be appreciated.
Thanks,
WBA

[terryr]

Have you resolved this? I tested your log lines against the regex in regex.pm and they matched.

Terry

[WBA]

I think I have figured it out, you are correct, the reason for not blocking the IP was the time interval, after reviewing the log very closely there were less than 10 attempts in 5 minutes from each IP.
I am going to increase the time spam to 30 minutes if I can figure out how.
Thanks for the follow up.
WBA