From 16b3993be679aab0472835493120b95e3f186f00 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 22 Aug 2019 21:05:38 +0200 Subject: [PATCH 1/3] actions: improve conditional execution of some operations, also allow to start action on demand (by first ban if `actionstart_on_demand` enabled) for non-conditional actions (backwards compatible, so actionstart_on_demand is on per default only for the actions having family-conditional sections); small bug fixing (stop/flush/restore env etc) and code simplification. --- fail2ban/server/action.py | 62 +++++++++++++++++---------------------- 1 file changed, 27 insertions(+), 35 deletions(-) diff --git a/fail2ban/server/action.py b/fail2ban/server/action.py index ef953eff..e4c83409 100644 --- a/fail2ban/server/action.py +++ b/fail2ban/server/action.py @@ -385,20 +385,20 @@ class CommandAction(ActionBase): res = True try: # common (resp. ipv4): - startCmd = None + cmd = self._getOperation(tag, 'inet4') if not family or 'inet4' in family: - startCmd = self._getOperation(tag, 'inet4') - if startCmd: - res &= self.executeCmd(startCmd, self.timeout) - # start ipv6 actions if available: + if cmd: + res &= self.executeCmd(cmd, self.timeout) + # execute ipv6 operation if available (and not the same as ipv4): if allowed_ipv6 and (not family or 'inet6' in family): - startCmd6 = self._getOperation(tag, 'inet6') - if startCmd6 and startCmd6 != startCmd: - res &= self.executeCmd(startCmd6, self.timeout) + cmd6 = self._getOperation(tag, 'inet6') + if cmd6 and cmd6 != cmd: # - avoid double execution of same command + res &= self.executeCmd(cmd6, self.timeout) if not res: raise RuntimeError("Error %s action %s/%s" % (operation, self._jail, self._name,)) except ValueError as e: raise RuntimeError("Error %s action %s/%s: %r" % (operation, self._jail, self._name, e)) + return res COND_FAMILIES = ('inet4', 'inet6') @@ -406,28 +406,32 @@ class CommandAction(ActionBase): def _startOnDemand(self): """Checks the action depends on family (conditional)""" v = self._properties.get('actionstart_on_demand') - if v is None: - v = False - for n in self._properties: - if CONDITIONAL_FAM_RE.match(n): - v = True - break + if v is not None: + return v + # not set - auto-recognize (depending on conditional): + v = False + for n in self._properties: + if CONDITIONAL_FAM_RE.match(n): + v = True + break self._properties['actionstart_on_demand'] = v return v - def start(self, family=[]): + def start(self, family=None, forceStart=False): """Executes the "actionstart" command. Replace the tags in the action command with actions properties and executes the resulting command. """ - if not family: - # check the action depends on family (conditional): - if self._startOnDemand: + # check the action depends on family (conditional): + if self._startOnDemand: + if not forceStart: return True elif self.__started.get(family): # pragma: no cover - normally unreachable return True - return self._executeOperation('', 'starting', family=family) + ret = self._executeOperation('', 'starting', family=family) + self.__started[family] = ret + return ret def ban(self, aInfo): """Executes the "actionban" command. @@ -445,15 +449,7 @@ class CommandAction(ActionBase): if self._startOnDemand: family = aInfo.get('family') if not self.__started.get(family): - self.start(family) - self.__started[family] = 1 - # mark also another families as "started" (-1), if they are equal - # (on demand, but the same for ipv4 and ipv6): - cmd = self._getOperation('', family) - for f in CommandAction.COND_FAMILIES: - if f != family and not self.__started.get(f): - if cmd == self._getOperation('', f): - self.__started[f] = -1 + self.start(family, forceStart=True) # ban: if not self._processCmd('', aInfo): raise RuntimeError("Error banning %(ip)s" % aInfo) @@ -485,9 +481,7 @@ class CommandAction(ActionBase): family = [] # collect started families, if started on demand (conditional): if self._startOnDemand: - for f in CommandAction.COND_FAMILIES: - if self.__started.get(f) == 1: # only real started: - family.append(f) + family = [f for (f,v) in self.__started.iteritems() if v] # if no started (on demand) actions: if not family: return True return self._executeOperation('', 'flushing', family=family) @@ -501,12 +495,10 @@ class CommandAction(ActionBase): family = [] # collect started families, if started on demand (conditional): if self._startOnDemand: - for f in CommandAction.COND_FAMILIES: - if self.__started.get(f) == 1: # only real started: - family.append(f) - self.__started[f] = 0 + family = [f for (f,v) in self.__started.iteritems() if v] # if no started (on demand) actions: if not family: return True + self.__started = {} return self._executeOperation('', 'stopping', family=family) def reload(self, **kwargs): From 65da15327eb31f766f1b24be4d0190d67c572942 Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 22 Aug 2019 21:17:45 +0200 Subject: [PATCH 2/3] curtail some bothering continuously repeatable debug messages of filters (backend-related) to level 4 (below extra heavy-debug, so simplifying debugging and testing with level 5) --- fail2ban/server/filtergamin.py | 2 +- fail2ban/server/filterpoll.py | 8 ++++---- fail2ban/server/filterpyinotify.py | 2 +- 3 files changed, 6 insertions(+), 6 deletions(-) diff --git a/fail2ban/server/filtergamin.py b/fail2ban/server/filtergamin.py index 963c6850..77c81757 100644 --- a/fail2ban/server/filtergamin.py +++ b/fail2ban/server/filtergamin.py @@ -64,7 +64,7 @@ class FilterGamin(FileFilter): logSys.debug("Created FilterGamin") def callback(self, path, event): - logSys.debug("Got event: " + repr(event) + " for " + path) + logSys.log(4, "Got event: " + repr(event) + " for " + path) if event in (gamin.GAMCreated, gamin.GAMChanged, gamin.GAMExists): logSys.debug("File changed: " + path) self.__modified = True diff --git a/fail2ban/server/filterpoll.py b/fail2ban/server/filterpoll.py index 30241d50..228a2c8b 100644 --- a/fail2ban/server/filterpoll.py +++ b/fail2ban/server/filterpoll.py @@ -98,8 +98,8 @@ class FilterPoll(FileFilter): def run(self): while self.active: try: - if logSys.getEffectiveLevel() <= 6: - logSys.log(6, "Woke up idle=%s with %d files monitored", + if logSys.getEffectiveLevel() <= 4: + logSys.log(4, "Woke up idle=%s with %d files monitored", self.idle, self.getLogCount()) if self.idle: if not Utils.wait_for(lambda: not self.active or not self.idle, @@ -140,10 +140,10 @@ class FilterPoll(FileFilter): logStats = os.stat(filename) stats = logStats.st_mtime, logStats.st_ino, logStats.st_size pstats = self.__prevStats.get(filename, (0)) - if logSys.getEffectiveLevel() <= 5: + if logSys.getEffectiveLevel() <= 4: # we do not want to waste time on strftime etc if not necessary dt = logStats.st_mtime - pstats[0] - logSys.log(5, "Checking %s for being modified. Previous/current stats: %s / %s. dt: %s", + logSys.log(4, "Checking %s for being modified. Previous/current stats: %s / %s. dt: %s", filename, pstats, stats, dt) # os.system("stat %s | grep Modify" % filename) self.__file404Cnt[filename] = 0 diff --git a/fail2ban/server/filterpyinotify.py b/fail2ban/server/filterpyinotify.py index 383e67a4..ca6b253f 100644 --- a/fail2ban/server/filterpyinotify.py +++ b/fail2ban/server/filterpyinotify.py @@ -87,7 +87,7 @@ class FilterPyinotify(FileFilter): logSys.debug("Created FilterPyinotify") def callback(self, event, origin=''): - logSys.log(7, "[%s] %sCallback for Event: %s", self.jailName, origin, event) + logSys.log(4, "[%s] %sCallback for Event: %s", self.jailName, origin, event) path = event.pathname # check watching of this path: isWF = False From e547927075eee62ab087899ebcc6790bd08f685e Mon Sep 17 00:00:00 2001 From: sebres Date: Thu, 22 Aug 2019 21:29:46 +0200 Subject: [PATCH 3/3] tests: extend server test cases for some stock jails (e. g. check issue with sendmail filters gh-2493 + covering `maxmatches` / `dbmaxmatches` in server tests) --- fail2ban/tests/fail2banclienttestcase.py | 132 ++++++++++++++++++++++- 1 file changed, 128 insertions(+), 4 deletions(-) diff --git a/fail2ban/tests/fail2banclienttestcase.py b/fail2ban/tests/fail2banclienttestcase.py index 2542f314..ad3c7355 100644 --- a/fail2ban/tests/fail2banclienttestcase.py +++ b/fail2ban/tests/fail2banclienttestcase.py @@ -146,6 +146,7 @@ def _start_params(tmp, use_stock=False, use_stock_cfg=None, cfg = pjoin(tmp, "config") if db == 'auto': db = pjoin(tmp, "f2b-db.sqlite3") + j_conf = 'jail.conf' if use_stock and STOCK: # copy config (sub-directories as alias): def ig_dirs(dir, files): @@ -167,6 +168,8 @@ def _start_params(tmp, use_stock=False, use_stock_cfg=None, if r.match(line): line = "backend = polling" print(line) + # jails to local: + j_conf = 'jail.local' if jails else '' else: # just empty config directory without anything (only fail2ban.conf/jail.conf): os.mkdir(cfg) @@ -183,17 +186,23 @@ def _start_params(tmp, use_stock=False, use_stock_cfg=None, "dbpurgeage = 1d", "", ) - _write_file(pjoin(cfg, "jail.conf"), "w", + # write jails (local or conf): + if j_conf: + _write_file(pjoin(cfg, j_conf), "w", *(( "[INCLUDES]", "", "[DEFAULT]", "tmp = " + tmp, "", )+jails) ) - if unittest.F2B.log_level < logging.DEBUG: # pragma: no cover - _out_file(pjoin(cfg, "fail2ban.conf")) - _out_file(pjoin(cfg, "jail.conf")) if f2b_local: _write_file(pjoin(cfg, "fail2ban.local"), "w", *f2b_local) + if unittest.F2B.log_level < logging.DEBUG: # pragma: no cover + _out_file(pjoin(cfg, "fail2ban.conf")) + _out_file(pjoin(cfg, "jail.conf")) + if f2b_local: + _out_file(pjoin(cfg, "fail2ban.local")) + if j_conf and j_conf != "jail.conf": + _out_file(pjoin(cfg, j_conf)) # link stock actions and filters: if use_stock_cfg and STOCK: @@ -1296,6 +1305,121 @@ class Fail2banServerTest(Fail2banClientServerBase): mp = _read_file(mpfn) self.assertEqual(mp, '') + @unittest.F2B.skip_if_cfg_missing(filter="sendmail-auth") + @with_foreground_server_thread(startextra={ + # create log-file (avoid "not found" errors): + 'create_before_start': ('%(tmp)s/test.log',), + 'use_stock': True, + # fail2ban.local: + 'f2b_local': ( + '[DEFAULT]', + 'dbmaxmatches = 1' + ), + # jail.local config: + 'jails': ( + # default: + '''test_action = dummy[actionstart_on_demand=1, init="start: %(__name__)s", target="%(tmp)s/test.txt", + actionban='; + echo ""; printf "=====\\n%%b\\n=====\\n\\n" "" >> ']''', + # jail sendmail-auth: + '[sendmail-auth]', + 'backend = polling', + 'usedns = no', + 'logpath = %(tmp)s/test.log', + 'action = %(test_action)s', + 'filter = sendmail-auth[logtype=short]', + 'datepattern = ^Epoch', + 'maxretry = 3', + 'maxmatches = 2', + 'enabled = true', + # jail sendmail-reject: + '[sendmail-reject]', + 'backend = polling', + 'usedns = no', + 'logpath = %(tmp)s/test.log', + 'action = %(test_action)s', + 'filter = sendmail-reject[logtype=short]', + 'datepattern = ^Epoch', + 'maxretry = 3', + 'enabled = true', + ) + }) + def testServerJails_Sendmail(self, tmp, startparams): + cfg = pjoin(tmp, "config") + lgfn = '%(tmp)s/test.log' % {'tmp': tmp} + tofn = '%(tmp)s/test.txt' % {'tmp': tmp} + + smaut_msg = ( + str(int(MyTime.time())) + ' smtp1 sm-mta[5133]: s1000000000001: [192.0.2.1]: possible SMTP attack: command=AUTH, count=1', + str(int(MyTime.time())) + ' smtp1 sm-mta[5133]: s1000000000002: [192.0.2.1]: possible SMTP attack: command=AUTH, count=2', + str(int(MyTime.time())) + ' smtp1 sm-mta[5133]: s1000000000003: [192.0.2.1]: possible SMTP attack: command=AUTH, count=3', + ) + smrej_msg = ( + str(int(MyTime.time())) + ' smtp1 sm-mta[21134]: s2000000000001: ruleset=check_rcpt, arg1=<123@example.com>, relay=xxx.dynamic.example.com [192.0.2.2], reject=550 5.7.1 <123@example.com>... Relaying denied. Proper authentication required.', + str(int(MyTime.time())) + ' smtp1 sm-mta[21134]: s2000000000002: ruleset=check_rcpt, arg1=<345@example.com>, relay=xxx.dynamic.example.com [192.0.2.2], reject=550 5.7.1 <345@example.com>... Relaying denied. Proper authentication required.', + str(int(MyTime.time())) + ' smtp1 sm-mta[21134]: s3000000000003: ruleset=check_rcpt, arg1=<567@example.com>, relay=xxx.dynamic.example.com [192.0.2.2], reject=550 5.7.1 <567@example.com>... Relaying denied. Proper authentication required.', + ) + + self.pruneLog("[test-phase sendmail-auth]") + # write log: + _write_file(lgfn, "w+", *smaut_msg) + # wait and check it caused banned (and dump in the test-file): + self.assertLogged( + "[sendmail-auth] Ban 192.0.2.1", "1 ticket(s) in 'sendmail-auth'", all=True, wait=MID_WAITTIME) + _out_file(tofn) + td = _read_file(tofn) + # check matches (maxmatches = 2, so only 2 & 3 available): + m = smaut_msg[0] + self.assertNotIn(m, td) + for m in smaut_msg[1:]: + self.assertIn(m, td) + + self.pruneLog("[test-phase sendmail-reject]") + # write log: + _write_file(lgfn, "w+", *smrej_msg) + # wait and check it caused banned (and dump in the test-file): + self.assertLogged( + "[sendmail-reject] Ban 192.0.2.2", "1 ticket(s) in 'sendmail-reject'", all=True, wait=MID_WAITTIME) + _out_file(tofn) + td = _read_file(tofn) + # check matches (no maxmatches, so all matched messages are available): + for m in smrej_msg: + self.assertIn(m, td) + + self.pruneLog("[test-phase restart sendmail-*]") + # restart jails (active ban-tickets should be restored): + self.execCmd(SUCCESS, startparams, + "reload", "--restart", "--all") + # wait a bit: + self.assertLogged( + "Reload finished.", + "[sendmail-auth] Restore Ban 192.0.2.1", "1 ticket(s) in 'sendmail-auth'", all=True, wait=MID_WAITTIME) + # check matches again - (dbmaxmatches = 1), so it should be only last match after restart: + td = _read_file(tofn) + m = smaut_msg[-1] + self.assertLogged(m) + self.assertIn(m, td) + for m in smaut_msg[0:-1]: + self.assertNotLogged(m) + self.assertNotIn(m, td) + # wait for restore of reject-jail: + self.assertLogged( + "[sendmail-reject] Restore Ban 192.0.2.2", "1 ticket(s) in 'sendmail-reject'", all=True, wait=MID_WAITTIME) + td = _read_file(tofn) + m = smrej_msg[-1] + self.assertLogged(m) + self.assertIn(m, td) + for m in smrej_msg[0:-1]: + self.assertNotLogged(m) + self.assertNotIn(m, td) + + self.pruneLog("[test-phase stop server]") + # stop server and wait for end: + self.stopAndWaitForServerEnd(SUCCESS) + + # just to debug actionstop: + self.assertFalse(exists(tofn)) + # test multiple start/stop of the server (threaded in foreground) -- if False: # pragma: no cover @with_foreground_server_thread()