fail2ban érdekesség vagy bug?

Van rá állítva szűrő.

A szabvány 535-ös hibás jelszóval való próbálkozás.
A minta jó, a többit meg is fogja. Ugyanilyen típusú log bejegyzéseket tiltólistára tett már vagy tízet.
A mintára illeszkednek is a bejegyzések. Ezt egy külön kis perl scripttel ellenőriztem.
A felismerendő logsorok:

2018-02-14 05:15:59 [25405] login_server authenticator failed for (ylmf-pc) [87.98.226.111]:50824 I=[*******]:25: 535 Incorrect authentication data (set_id=****)

Egyébként a fail2ban alapbeállítással fut. Csak néhány fix IP van fehérlistán, de nem a támadóé. A findtime és a bantime van még egyedire állítva.

# fail2ban-client status exim
Status for the jail: exim
|- Filter
|  |- Currently failed: 9
|  |- Total failed:     18
|  `- File list:        ... /var/log/exim4/main.20180124
`- Actions
   |- Currently banned: 13
   |- Total banned:     13
   `- Banned IP list:   123.206.198.138 177.221.108.196 183.144.202.166 185.156.173.137 191.96.249.183 218.90.34.190 46.37.105.170 49.83.24.93 80.82.70.210 91.200.12.214 93.174.93.46 94.177.244.119 185.81.157.119

Látszik, hogy bár a bejegyzés hajnali 5-kor történt, még most sincs a tiltólistán. Egyre inkább az a gyanúm, hogy holnap kerül fel rá.

# fail2ban-client get exim failregex
The following regular expression are defined:
|- [0]: ^(?: \[\d+\])? (?:H=([\w.-]+ )?(?:\(\S+\) )?)?\[(?:::f{4,6}:)?(?P<host>[\w\-.^_]*\w)\](?::\d+)? (?:I=\[\S+\](:\d+)? )?(?:U=\S+ )?(?:P=e?smtp )?sender verify fail for <\S+>: (?:Unknown user|Unrouteable address|all relevant MX records point to non-existent hosts)\s*$
|- [1]: ^(?: \[\d+\])? \w+ authenticator failed for (\S+ )?\(\S+\) \[(?:::f{4,6}:)?(?P<host>[\w\-.^_]*\w)\](?::\d+)?(?: I=\[\S+\](:\d+)?)?: 535 Incorrect authentication data( \(set_id=.*\)|: \d+ Time\(s\))?\s*$
|- [2]: ^(?: \[\d+\])? (?:H=([\w.-]+ )?(?:\(\S+\) )?)?\[(?:::f{4,6}:)?(?P<host>[\w\-.^_]*\w)\](?::\d+)? (?:I=\[\S+\](:\d+)? )?(?:U=\S+ )?(?:P=e?smtp )?F=(?:<>|[^@]+@\S+) rejected RCPT [^@]+@\S+: (?:relay not permitted|Sender verify failed|Unknown user)\s*$
|- [3]: ^(?: \[\d+\])? SMTP protocol synchronization error \([^)]*\): rejected (?:connection from|"\S+") (?:H=([\w.-]+ )?(?:\(\S+\) )?)?\[(?:::f{4,6}:)?(?P<host>[\w\-.^_]*\w)\](?::\d+)? (?:I=\[\S+\](:\d+)? )?(?:U=\S+ )?(?:P=e?smtp )?(?:next )?input=".*"\s*$
|- [4]: ^(?: \[\d+\])? SMTP call from \S+ (?:H=([\w.-]+ )?(?:\(\S+\) )?)?\[(?:::f{4,6}:)?(?P<host>[\w\-.^_]*\w)\](?::\d+)? (?:I=\[\S+\](:\d+)? )?(?:U=\S+ )?(?:P=e?smtp )?dropped: too many nonmail commands \(last was "\S+"\)\s*$                                                                                                                                                                                                   
|- [5]: ^(?: \[\d+\])? SMTP protocol error in "AUTH \S*(?: \S*)?" (?:H=([\w.-]+ )?(?:\(\S+\) )?)?\[(?:::f{4,6}:)?(?P<host>[\w\-.^_]*\w)\](?::\d+)? (?:I=\[\S+\](:\d+)? )?(?:U=\S+ )?(?:P=e?smtp )?AUTH command used when not advertised\s*$                                                                                                                                                                                           
|- [6]: ^(?: \[\d+\])? no MAIL in SMTP connection from (?:\S* )?(?:\(\S*\) )?(?:H=([\w.-]+ )?(?:\(\S+\) )?)?\[(?:::f{4,6}:)?(?P<host>[\w\-.^_]*\w)\](?::\d+)? (?:I=\[\S+\](:\d+)? )?(?:U=\S+ )?(?:P=e?smtp )?D=\d+s(?: C=\S*)?\s*$                                                                                                                                                                                                    
`- [7]: ^(?: \[\d+\])? \S+ SMTP connection from (?:\S* )?(?:\(\S*\) )?(?:H=([\w.-]+ )?(?:\(\S+\) )?)?\[(?:::f{4,6}:)?(?P<host>[\w\-.^_]*\w)\](?::\d+)? (?:I=\[\S+\](:\d+)? )?(?:U=\S+ )?(?:P=e?smtp )?closed by DROP in ACL\s*$         

# fail2ban-client get exim ignoreregex                                                                                                                                                            
No regular expression is defined 

Mindig ugyanazzal a felhasználónévvel próbálkozott.

Alapvetően most az a gond, hogy a fail2ban nem azt csinálja, amit kellene, és nem az.
Azóta megnéztem, és még sok másik IP címet is kihagy így a blokkolásból, pedig a minták alapján kellene.

Pl.:

2018-02-15 10:30:48 [19323] login_server authenticator failed for (vtVI8Gf362) [37.49.226.106]:59777 I=[***]:25: 535 Incorrect authentication data (set_id=***)

A verzió kimarad:
Fail2Ban v0.9.6
A legfrissebb 9.3-as debianban található változat.

A fail2ban wikije alapján a findtime:
The counter is set to zero if no match is found within "findtime" seconds.
Vagyis nem a próbálkozások számolásához, hanem a nullázáshoz használja.
Ma például 10:14-től 10:20-ig 234 próbálkozás volt, 2-3 másodpercenként, azonos usernévvel a 180.118.242.127 IP címről.
Egy logsor ebből:

2018-02-16 10:20:29 [5077] login_server authenticator failed for (ylmf-pc) [180.118.242.127]:51152 I=[***]:25: 535 Incorrect authentication data (set_id=***)

A fail2ban logjában 0 bejegyzés tartozik ehhez az IP címhez. Nem is blokkolta.
A bantime 604800 ( 1 hét ).
A findtime értékét lecsökkentettem 21600-ra ( 6 óra ).
Eközben pedig sorban fogja meg az új próbálkozásokat is, mint amilyen a következő logsor:

2018-02-15 10:30:48 [19323] login_server authenticator failed for (vtVI8Gf362) [37.49.226.106]:59777 I=[***]:25: 535 Incorrect authentication data (set_id=***)

Az eredeti 87.98.226.111 IP címet pedig 14-e óta nem tiltotta le, és nem is került be a fail2ban logjába, pedig arról összesen 378 próbálkozás történt azonos felhasználónévvel.

Na, ez egyre izgalmasabb!
A következő parancs kimente ugyanis gyakorlatilag üres volt:

fail2ban-regex --print-all-missed /var/log/exim4/main.20180216 /etc/fail2ban/filter.d/exim.conf | grep "Incorrect"

A kimenetben pedig: "Ignoreregex: 0 total" szerepel.
Vagyis a saját mintája alapján minden "Incorrect authentication data" logbejegyzést megtalált.

Egyébként sem fehérlistán nincsenek a keresett IP-k, sem a fail2ban saját logjában nem tesz róluk említést, azaz fel sem ismeri.

Ez jó ötlet!
Kipróbáltam, és meglepve látom, hogy az újraindítás után nem olvassa újra az össze meglévő logot. Legalábbis előtte már 19 IP-t blokkolt az exim logjai alapján, utána meg csak 3-at.
Az azért a javára írható, hogy ez az új 3 IP cím nem szerepelt az előzőleg blokkolt 19 régiben.

Lehet, az egész problémának köze van a dbpurgeage paraméterhez, ami nálam szintén 1 nap volt?
Felemeltem két hétre, töröltem az adatbázist, de így sem talál meg több IP címet. Marad az új 3, a régi 19 meg feledve.
Így legalább egyre valószínűbb, hogy ez egy bug.