diff --git a/fail2ban/server/action.py b/fail2ban/server/action.py index f26b6bc8..e748fa77 100644 --- a/fail2ban/server/action.py +++ b/fail2ban/server/action.py @@ -217,6 +217,7 @@ class ActionBase(object): "start", "stop", "ban", + "reban", "unban", ) for method in required: @@ -250,6 +251,17 @@ class ActionBase(object): """ pass + def reban(self, aInfo): # pragma: no cover - abstract + """Executed when a ban occurs. + + Parameters + ---------- + aInfo : dict + Dictionary which includes information in relation to + the ban. + """ + return self.ban(aInfo) + def unban(self, aInfo): # pragma: no cover - abstract """Executed when a ban expires. @@ -281,6 +293,7 @@ class CommandAction(ActionBase): ---------- actionban actioncheck + actionreban actionreload actionrepair actionstart @@ -301,6 +314,7 @@ class CommandAction(ActionBase): self.actionstart = '' ## Command executed when ticket gets banned. self.actionban = '' + self.actionreban = '' ## Command executed when ticket gets removed. self.actionunban = '' ## Command executed in order to check requirements. @@ -504,8 +518,8 @@ class CommandAction(ActionBase): ret = self._executeOperation('', 'starting', family=family, afterExec=_started) return ret - def ban(self, aInfo): - """Executes the "actionban" command. + def ban(self, aInfo, cmd=''): + """Executes the given command ("actionban" or "actionreban"). Replaces the tags in the action command with actions properties and ban information, and executes the resulting command. @@ -522,7 +536,7 @@ class CommandAction(ActionBase): if not self.__started.get(family): self._start(family, forceStart=True) # ban: - if not self._processCmd('', aInfo): + if not self._processCmd(cmd, aInfo): raise RuntimeError("Error banning %(ip)s" % aInfo) self.__started[family] = self.__started.get(family, 0) | 3; # started and contains items @@ -543,6 +557,21 @@ class CommandAction(ActionBase): if not self._processCmd('', aInfo): raise RuntimeError("Error unbanning %(ip)s" % aInfo) + def reban(self, aInfo): + """Executes the "actionreban" command if available, otherwise simply repeat "actionban". + + Replaces the tags in the action command with actions properties + and ban information, and executes the resulting command. + + Parameters + ---------- + aInfo : dict + Dictionary which includes information in relation to + the ban. + """ + # re-ban: + return self.ban(aInfo, '' if self.actionreban else '') + def flush(self): """Executes the "actionflush" command. @@ -812,6 +841,17 @@ class CommandAction(ActionBase): realCmd = Utils.buildShellCmd(realCmd, varsDict) return realCmd + @property + def banEpoch(self): + return getattr(self, '_banEpoch', 0) + def invalidateBanEpoch(self): + """Increments ban epoch of jail and this action, so already banned tickets would cause + a re-ban for all tickets with previous epoch.""" + if self._jail is not None: + self._banEpoch = self._jail.actions.banEpoch = self._jail.actions.banEpoch + 1 + else: + self._banEpoch = self.banEpoch + 1 + def _invariantCheck(self, family=None, beforeRepair=None, forceStart=True): """Executes a substituted `actioncheck` command. """ @@ -826,6 +866,8 @@ class CommandAction(ActionBase): return -1 self._logSys.error( "Invariant check failed. Trying to restore a sane environment") + # increment ban epoch of jail and this action (allows re-ban on already banned): + self.invalidateBanEpoch() # try to find repair command, if exists - exec it: repairCmd = self._getOperation('', family) if repairCmd: diff --git a/fail2ban/server/actions.py b/fail2ban/server/actions.py index ed93c971..91912eb0 100644 --- a/fail2ban/server/actions.py +++ b/fail2ban/server/actions.py @@ -81,6 +81,8 @@ class Actions(JailThread, Mapping): self._actions = OrderedDict() ## The ban manager. self.__banManager = BanManager() + self.banEpoch = 0 + self.__lastConsistencyCheckTM = 0 ## Precedence of ban (over unban), so max number of tickets banned (to call an unban check): self.banPrecedence = 10 ## Max count of outdated tickets to unban per each __checkUnBan operation: @@ -439,6 +441,7 @@ class Actions(JailThread, Mapping): cnt = 0 if not tickets: tickets = self.__getFailTickets(self.banPrecedence) + rebanacts = None for ticket in tickets: bTicket = BanManager.createBanTicket(ticket) ip = bTicket.getIP() @@ -461,6 +464,8 @@ class Actions(JailThread, Mapping): exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) # after all actions are processed set banned flag: bTicket.banned = True + if self.banEpoch: # be sure tickets always have the same ban epoch (default 0): + bTicket.banEpoch = self.banEpoch else: bTicket = reason['ticket'] # if already banned (otherwise still process some action) @@ -475,11 +480,61 @@ class Actions(JailThread, Mapping): else logging.NOTICE if diftm < 60 \ else logging.WARNING logSys.log(ll, "[%s] %s already banned", self._jail.name, ip) + # if long time after ban - do consistency check (something is wrong here): + if bTicket.banEpoch == self.banEpoch and diftm > 3: + # avoid too often checks: + if not rebanacts and MyTime.time() > self.__lastConsistencyCheckTM + 3: + for action in self._actions.itervalues(): + action.consistencyCheck() + self.__lastConsistencyCheckTM = MyTime.time() + # check epoch in order to reban it: + if bTicket.banEpoch < self.banEpoch: + if not rebanacts: rebanacts = dict( + (name, action) for name, action in self._actions.iteritems() + if action.banEpoch > bTicket.banEpoch) + cnt += self.__reBan(bTicket, actions=rebanacts) + else: + # pragma: no cover - unexpected: ticket is not banned for some reasons - reban using all actions: + cnt += self.__reBan(bTicket) if cnt: logSys.debug("Banned %s / %s, %s ticket(s) in %r", cnt, self.__banManager.getBanTotal(), self.__banManager.size(), self._jail.name) return cnt + def __reBan(self, ticket, actions=None, log=True): + """Repeat bans for the ticket. + + Executes the actions in order to reban the host given in the + ticket. + + Parameters + ---------- + ticket : Ticket + Ticket to reban + """ + actions = actions or self._actions + ip = ticket.getIP() + aInfo = self.__getActionInfo(ticket) + if log: + logSys.notice("[%s] Reban %s%s", self._jail.name, aInfo["ip"], (', action %r' % actions.keys()[0] if len(actions) == 1 else '')) + for name, action in actions.iteritems(): + try: + logSys.debug("[%s] action %r: reban %s", self._jail.name, name, ip) + if not aInfo.immutable: aInfo.reset() + action.reban(aInfo) + except Exception as e: + logSys.error( + "Failed to execute reban jail '%s' action '%s' " + "info '%r': %s", + self._jail.name, name, aInfo, e, + exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + return 0 + # after all actions are processed set banned flag: + ticket.banned = True + if self.banEpoch: # be sure tickets always have the same ban epoch (default 0): + ticket.banEpoch = self.banEpoch + return 1 + def __checkUnBan(self, maxCount=None): """Check for IP address to unban. @@ -522,7 +577,7 @@ class Actions(JailThread, Mapping): logSys.error("Failed to flush bans in jail '%s' action '%s': %s", self._jail.name, name, e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) - logSys.info("No flush occured, do consistency check") + logSys.info("No flush occurred, do consistency check") if hasattr(action, 'consistencyCheck'): def _beforeRepair(): if stop and not getattr(action, 'actionrepair_on_unban', None): # don't need repair on stop @@ -569,8 +624,6 @@ class Actions(JailThread, Mapping): logSys.notice("[%s] Unban %s", self._jail.name, aInfo["ip"]) for name, action in unbactions.iteritems(): try: - if ticket.restored and getattr(action, 'norestored', False): - continue logSys.debug("[%s] action %r: unban %s", self._jail.name, name, ip) if not aInfo.immutable: aInfo.reset() action.unban(aInfo) diff --git a/fail2ban/server/ticket.py b/fail2ban/server/ticket.py index 5a750d02..4f509ea9 100644 --- a/fail2ban/server/ticket.py +++ b/fail2ban/server/ticket.py @@ -206,6 +206,13 @@ class Ticket(object): # return single value of data: return self._data.get(key, default) + @property + def banEpoch(self): + return getattr(self, '_banEpoch', 0) + @banEpoch.setter + def banEpoch(self, value): + self._banEpoch = value + class FailTicket(Ticket): diff --git a/fail2ban/tests/actionstestcase.py b/fail2ban/tests/actionstestcase.py index c4dac77f..e55ef0ce 100644 --- a/fail2ban/tests/actionstestcase.py +++ b/fail2ban/tests/actionstestcase.py @@ -28,11 +28,10 @@ import time import os import tempfile -from ..server.actions import Actions from ..server.ticket import FailTicket from ..server.utils import Utils from .dummyjail import DummyJail -from .utils import LogCaptureTestCase, with_alt_time, MyTime +from .utils import LogCaptureTestCase, with_alt_time, with_tmpdir, MyTime TEST_FILES_DIR = os.path.join(os.path.dirname(__file__), "files") @@ -43,7 +42,7 @@ class ExecuteActions(LogCaptureTestCase): """Call before every test case.""" super(ExecuteActions, self).setUp() self.__jail = DummyJail() - self.__actions = Actions(self.__jail) + self.__actions = self.__jail.actions def tearDown(self): super(ExecuteActions, self).tearDown() @@ -52,8 +51,8 @@ class ExecuteActions(LogCaptureTestCase): self.__actions.add('ip') act = self.__actions['ip'] act.actionstart = 'echo ip start'+o.get('start', '') - act.actionban = 'echo ip ban ' - act.actionunban = 'echo ip unban ' + act.actionban = 'echo ip ban '+o.get('ban', '') + act.actionunban = 'echo ip unban '+o.get('unban', '') act.actioncheck = 'echo ip check'+o.get('check', '') act.actionflush = 'echo ip flush'+o.get('flush', '') act.actionstop = 'echo ip stop'+o.get('stop', '') @@ -239,7 +238,7 @@ class ExecuteActions(LogCaptureTestCase): "stdout: %r" % 'ip flush inet4', "stdout: %r" % 'ip flush inet6', 'Failed to flush bans', - 'No flush occured, do consistency check', + 'No flush occurred, do consistency check', 'Invariant check failed. Trying to restore a sane environment', "stdout: %r" % 'ip stop', # same for both families 'Failed to flush bans', @@ -259,7 +258,7 @@ class ExecuteActions(LogCaptureTestCase): self.pruneLog('[test-phase 3] failed flush in consistent env') self.__actions._Actions__flushBan() self.assertLogged('Failed to flush bans', - 'No flush occured, do consistency check', + 'No flush occurred, do consistency check', "stdout: %r" % 'ip flush inet6', "stdout: %r" % 'ip check inet6', all=True, wait=True) @@ -341,7 +340,7 @@ class ExecuteActions(LogCaptureTestCase): "stdout: %r" % 'ip flush inet4', "stdout: %r" % 'ip flush inet6', 'Failed to flush bans', - 'No flush occured, do consistency check', + 'No flush occurred, do consistency check', 'Invariant check failed. Trying to restore a sane environment', "stdout: %r" % 'ip stop inet6', 'Failed to flush bans in jail', @@ -368,7 +367,7 @@ class ExecuteActions(LogCaptureTestCase): act['actioncheck?family=inet6'] = act.actioncheck self.__actions._Actions__flushBan() self.assertLogged('Failed to flush bans', - 'No flush occured, do consistency check', + 'No flush occurred, do consistency check', "stdout: %r" % 'ip flush inet6', "stdout: %r" % 'ip check inet6', all=True, wait=True) @@ -396,3 +395,103 @@ class ExecuteActions(LogCaptureTestCase): "stdout: %r" % 'ip flush inet4', 'Unban tickets each individualy', all=True) + + @with_alt_time + @with_tmpdir + def testActionsRebanBrokenAfterRepair(self, tmp): + act = self.defaultAction({ + 'start':' ; touch ""', + 'check':' ; test -f ""', + 'flush':' ; echo -n "" > ""', + 'stop': ' ; rm -f ""', + 'ban': ' ; echo " " >> ""', + }) + act['FN'] = tmp+'/' + act.actionstart_on_demand = True + act.actionrepair = 'echo ip repair ; touch ""' + act.actionreban = 'echo ip reban ; echo " -- rebanned" >> ""' + self.pruneLog('[test-phase 0] initial ban') + self.assertEqual(self.__actions.addBannedIP(['192.0.2.1', '2001:db8::1']), 2) + self.assertLogged('Ban 192.0.2.1', 'Ban 2001:db8::1', + "stdout: %r" % 'ip start inet4', + "stdout: %r" % 'ip ban 192.0.2.1 inet4', + "stdout: %r" % 'ip start inet6', + "stdout: %r" % 'ip ban 2001:db8::1 inet6', + all=True) + + self.pruneLog('[test-phase 1] check ban') + self.dumpFile(tmp+'/inet4') + self.assertLogged('192.0.2.1 inet4') + self.assertNotLogged('2001:db8::1 inet6') + self.pruneLog() + self.dumpFile(tmp+'/inet6') + self.assertLogged('2001:db8::1 inet6') + self.assertNotLogged('192.0.2.1 inet4') + + # simulate 3 seconds past: + MyTime.setTime(MyTime.time() + 4) + # already banned produces events: + self.pruneLog('[test-phase 2] check already banned') + self.assertEqual(self.__actions.addBannedIP(['192.0.2.1', '2001:db8::1', '2001:db8::2']), 1) + self.assertLogged( + '192.0.2.1 already banned', '2001:db8::1 already banned', 'Ban 2001:db8::2', + "stdout: %r" % 'ip check inet4', # both checks occurred + "stdout: %r" % 'ip check inet6', + all=True) + self.dumpFile(tmp+'/inet4') + self.dumpFile(tmp+'/inet6') + # no reban should occur: + self.assertNotLogged('Reban 192.0.2.1', 'Reban 2001:db8::1', + "stdout: %r" % 'ip ban 192.0.2.1 inet4', + "stdout: %r" % 'ip reban 192.0.2.1 inet4', + "stdout: %r" % 'ip ban 2001:db8::1 inet6', + "stdout: %r" % 'ip reban 2001:db8::1 inet6', + '192.0.2.1 inet4 -- repaired', + '2001:db8::1 inet6 -- repaired', + all=True) + + # simulate 3 seconds past: + MyTime.setTime(MyTime.time() + 4) + # break env (remove both files, so check would fail): + os.remove(tmp+'/inet4') + os.remove(tmp+'/inet6') + # test again already banned (it shall cause reban now): + self.pruneLog('[test-phase 3a] check reban after sane env repaired') + self.assertEqual(self.__actions.addBannedIP(['192.0.2.1', '2001:db8::1']), 2) + self.assertLogged( + "Invariant check failed. Trying to restore a sane environment", + "stdout: %r" % 'ip repair inet4', # both repairs occurred + "stdout: %r" % 'ip repair inet6', + "Reban 192.0.2.1, action 'ip'", "Reban 2001:db8::1, action 'ip'", # both rebans also + "stdout: %r" % 'ip reban 192.0.2.1 inet4', + "stdout: %r" % 'ip reban 2001:db8::1 inet6', + all=True) + + # now last IP (2001:db8::2) - no repair, but still old epoch of ticket, so it gets rebanned: + self.pruneLog('[test-phase 3a] check reban by epoch mismatch (without repair)') + self.assertEqual(self.__actions.addBannedIP('2001:db8::2'), 1) + self.assertLogged( + "Reban 2001:db8::2, action 'ip'", + "stdout: %r" % 'ip reban 2001:db8::2 inet6', + all=True) + self.assertNotLogged( + "Invariant check failed. Trying to restore a sane environment", + "stdout: %r" % 'ip repair inet4', # both repairs occurred + "stdout: %r" % 'ip repair inet6', + "Reban 192.0.2.1, action 'ip'", "Reban 2001:db8::1, action 'ip'", # both rebans also + "stdout: %r" % 'ip reban 192.0.2.1 inet4', + "stdout: %r" % 'ip reban 2001:db8::1 inet6', + all=True) + + # and bans present in files: + self.pruneLog('[test-phase 4] check reban') + self.dumpFile(tmp+'/inet4') + self.assertLogged('192.0.2.1 inet4 -- rebanned') + self.assertNotLogged('2001:db8::1 inet6 -- rebanned') + self.pruneLog() + self.dumpFile(tmp+'/inet6') + self.assertLogged( + '2001:db8::1 inet6 -- rebanned', + '2001:db8::2 inet6 -- rebanned', all=True) + self.assertNotLogged('192.0.2.1 inet4 -- rebanned') + diff --git a/fail2ban/tests/fail2banclienttestcase.py b/fail2ban/tests/fail2banclienttestcase.py index ad3c7355..770e3ffb 100644 --- a/fail2ban/tests/fail2banclienttestcase.py +++ b/fail2ban/tests/fail2banclienttestcase.py @@ -113,16 +113,7 @@ fail2banclient.input_command = _test_input_command fail2bancmdline.PRODUCTION = \ fail2banserver.PRODUCTION = False - -def _out_file(fn, handle=logSys.debug): - """Helper which outputs content of the file at HEAVYDEBUG loglevels""" - if (handle != logSys.debug or logSys.getEffectiveLevel() <= logging.DEBUG): - handle('---- ' + fn + ' ----') - for line in fileinput.input(fn): - line = line.rstrip('\n') - handle(line) - handle('-'*30) - +_out_file = LogCaptureTestCase.dumpFile def _write_file(fn, mode, *lines): f = open(fn, mode) diff --git a/fail2ban/tests/servertestcase.py b/fail2ban/tests/servertestcase.py index f1121a57..a51c4f85 100644 --- a/fail2ban/tests/servertestcase.py +++ b/fail2ban/tests/servertestcase.py @@ -752,7 +752,7 @@ class Transmitter(TransmitterBase): self.assertSortedEqual( self.transm.proceed(["get", self.jailName, "actionmethods", action])[1], - ['ban', 'start', 'stop', 'testmethod', 'unban']) + ['ban', 'reban', 'start', 'stop', 'testmethod', 'unban']) self.assertEqual( self.transm.proceed(["set", self.jailName, "action", action, "testmethod", '{"text": "world!"}']), diff --git a/fail2ban/tests/utils.py b/fail2ban/tests/utils.py index d4129b2a..f5ffb978 100644 --- a/fail2ban/tests/utils.py +++ b/fail2ban/tests/utils.py @@ -22,6 +22,7 @@ __author__ = "Yaroslav Halchenko" __copyright__ = "Copyright (c) 2013 Yaroslav Halchenko" __license__ = "GPL" +import fileinput import itertools import logging import optparse @@ -741,11 +742,8 @@ class LogCaptureTestCase(unittest.TestCase): self._dirty |= 2 # records changed def setUp(self): - # For extended testing of what gets output into logging # system, we will redirect it to a string - logSys = getLogger("fail2ban") - # Keep old settings self._old_level = logSys.level self._old_handlers = logSys.handlers @@ -762,7 +760,6 @@ class LogCaptureTestCase(unittest.TestCase): """Call after every test case.""" # print "O: >>%s<<" % self._log.getvalue() self.pruneLog() - logSys = getLogger("fail2ban") logSys.handlers = self._old_handlers logSys.level = self._old_level super(LogCaptureTestCase, self).tearDown() @@ -845,5 +842,15 @@ class LogCaptureTestCase(unittest.TestCase): def getLog(self): return self._log.getvalue() + @staticmethod + def dumpFile(fn, handle=logSys.debug): + """Helper which outputs content of the file at HEAVYDEBUG loglevels""" + if (handle != logSys.debug or logSys.getEffectiveLevel() <= logging.DEBUG): + handle('---- ' + fn + ' ----') + for line in fileinput.input(fn): + line = line.rstrip('\n') + handle(line) + handle('-'*30) + pid_exists = Utils.pid_exists