diff options
Diffstat (limited to 'fail2ban')
35 files changed, 2154 insertions, 197 deletions
diff --git a/fail2ban/client/actionreader.py b/fail2ban/client/actionreader.py index 011a213d..88b0aca1 100644 --- a/fail2ban/client/actionreader.py +++ b/fail2ban/client/actionreader.py @@ -46,6 +46,7 @@ class ActionReader(DefinitionInitConfigReader): "actionrepair": ["string", None], "actionrepair_on_unban": ["bool", None], "actionban": ["string", None], + "actionprolong": ["string", None], "actionreban": ["string", None], "actionunban": ["string", None], "norestored": ["bool", None], diff --git a/fail2ban/client/beautifier.py b/fail2ban/client/beautifier.py index 4d9e549f..97cd38b2 100644 --- a/fail2ban/client/beautifier.py +++ b/fail2ban/client/beautifier.py @@ -180,6 +180,12 @@ class Beautifier: msg = "The jail %s action %s has the following " \ "methods:\n" % (inC[1], inC[3]) msg += ", ".join(response) + elif inC[2] == "banip" and inC[0] == "get": + if isinstance(response, list): + sep = " " if len(inC) <= 3 else inC[3] + if sep == "--with-time": + sep = "\n" + msg = sep.join(response) except Exception: logSys.warning("Beautifier error. Please report the error") logSys.error("Beautify %r with %r failed", response, self.__inputCmd, diff --git a/fail2ban/client/jailreader.py b/fail2ban/client/jailreader.py index 0a27c644..f3ccf7db 100644 --- a/fail2ban/client/jailreader.py +++ b/fail2ban/client/jailreader.py @@ -98,6 +98,13 @@ class JailReader(ConfigReader): "maxmatches": ["int", None], "findtime": ["string", None], "bantime": ["string", None], + "bantime.increment": ["bool", None], + "bantime.factor": ["string", None], + "bantime.formula": ["string", None], + "bantime.multipliers": ["string", None], + "bantime.maxtime": ["string", None], + "bantime.rndtime": ["string", None], + "bantime.overalljails": ["bool", None], "ignorecommand": ["string", None], "ignoreself": ["bool", None], "ignoreip": ["string", None], diff --git a/fail2ban/protocol.py b/fail2ban/protocol.py index 18b901e8..0a4c84ed 100644 --- a/fail2ban/protocol.py +++ b/fail2ban/protocol.py @@ -136,6 +136,7 @@ protocol = [ ["get <JAIL> bantime", "gets the time a host is banned for <JAIL>"], ["get <JAIL> datepattern", "gets the patern used to match date/times for <JAIL>"], ["get <JAIL> usedns", "gets the usedns setting for <JAIL>"], +["get <JAIL> banip [<SEP>|--with-time]", "gets the list of of banned IP addresses for <JAIL>. Optionally the separator character ('<SEP>', default is space) or the option '--with-time' (printing the times of ban) may be specified. The IPs are ordered by end of ban."], ["get <JAIL> maxretry", "gets the number of failures allowed for <JAIL>"], ["get <JAIL> maxmatches", "gets the max number of matches stored in memory per ticket in <JAIL>"], ["get <JAIL> maxlines", "gets the number of lines to buffer for <JAIL>"], diff --git a/fail2ban/server/action.py b/fail2ban/server/action.py index f0f1e6f5..99ab2250 100644 --- a/fail2ban/server/action.py +++ b/fail2ban/server/action.py @@ -265,6 +265,10 @@ class ActionBase(object): """ return self.ban(aInfo) + @property + def _prolongable(self): # pragma: no cover - abstract + return False + def unban(self, aInfo): # pragma: no cover - abstract """Executed when a ban expires. @@ -277,6 +281,11 @@ class ActionBase(object): pass +WRAP_CMD_PARAMS = { + 'timeout': 'str2seconds', + 'bantime': 'ignore', +} + class CommandAction(ActionBase): """A action which executes OS shell commands. @@ -349,7 +358,10 @@ class CommandAction(ActionBase): def __setattr__(self, name, value): if not name.startswith('_') and not self.__init and not callable(value): # special case for some parameters: - if name in ('timeout', 'bantime'): + wrp = WRAP_CMD_PARAMS.get(name) + if wrp == 'ignore': # ignore (filter) dynamic parameters + return + elif wrp == 'str2seconds': value = MyTime.str2seconds(value) # parameters changed - clear properties and substitution cache: self.__properties = None @@ -446,7 +458,18 @@ class CommandAction(ActionBase): ret = True # avoid double execution of same command for both families: if cmd and cmd not in self._operationExecuted(tag, lambda f: f != famoper): - ret = self.executeCmd(cmd, self.timeout) + realCmd = cmd + if self._jail: + # simulate action info with "empty" ticket: + aInfo = getattr(self._jail.actions, 'actionInfo', None) + if not aInfo: + aInfo = self._jail.actions._getActionInfo(None) + setattr(self._jail.actions, 'actionInfo', aInfo) + aInfo['time'] = MyTime.time() + aInfo['family'] = famoper + # replace dynamical tags, important - don't cache, no recursion and auto-escape here + realCmd = self.replaceDynamicTags(cmd, aInfo) + ret = self.executeCmd(realCmd, self.timeout) res &= ret if afterExec: afterExec(famoper, ret) self._operationExecuted(tag, famoper, cmd if ret else None) @@ -546,6 +569,26 @@ class CommandAction(ActionBase): raise RuntimeError("Error banning %(ip)s" % aInfo) self.__started[family] = self.__started.get(family, 0) | 3; # started and contains items + @property + def _prolongable(self): + return (hasattr(self, 'actionprolong') and self.actionprolong + and not str(self.actionprolong).isspace()) + + def prolong(self, aInfo): + """Executes the "actionprolong" command. + + 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. + """ + if not self._processCmd('<actionprolong>', aInfo): + raise RuntimeError("Error prolonging %(ip)s" % aInfo) + def unban(self, aInfo): """Executes the "actionunban" command. @@ -655,8 +698,10 @@ class CommandAction(ActionBase): ret &= False return ret - @staticmethod - def escapeTag(value): + ESCAPE_CRE = re.compile(r"""[\\#&;`|*?~<>^()\[\]{}$'"\n\r]""") + + @classmethod + def escapeTag(cls, value): """Escape characters which may be used for command injection. Parameters @@ -673,12 +718,15 @@ class CommandAction(ActionBase): ----- The following characters are escaped:: - \\#&;`|*?~<>^()[]{}$'" + \\#&;`|*?~<>^()[]{}$'"\n\r """ - for c in '\\#&;`|*?~<>^()[]{}$\'"': - if c in value: - value = value.replace(c, '\\' + c) + _map2c = {'\n': 'n', '\r': 'r'} + def substChar(m): + c = m.group() + return '\\' + _map2c.get(c, c) + + value = cls.ESCAPE_CRE.sub(substChar, value) return value @classmethod @@ -834,7 +882,7 @@ class CommandAction(ActionBase): tickData = aInfo.get("F-*") if not tickData: tickData = {} def substTag(m): - tag = mapTag2Opt(m.groups()[0]) + tag = mapTag2Opt(m.group(1)) try: value = uni_string(tickData[tag]) except KeyError: @@ -978,7 +1026,8 @@ class CommandAction(ActionBase): RuntimeError If command execution times out. """ - logSys.debug(realCmd) + if logSys.getEffectiveLevel() < logging.DEBUG: + logSys.log(9, realCmd) if not realCmd: logSys.debug("Nothing to do") return True diff --git a/fail2ban/server/actions.py b/fail2ban/server/actions.py index 7eff48f6..83c137ae 100644 --- a/fail2ban/server/actions.py +++ b/fail2ban/server/actions.py @@ -42,6 +42,7 @@ from .ipdns import IPAddr from .jailthread import JailThread from .action import ActionBase, CommandAction, CallingMap from .mytime import MyTime +from .observer import Observers from .utils import Utils from ..helpers import getLogger @@ -221,6 +222,16 @@ class Actions(JailThread, Mapping): return 1 if ids[0] in lst else 0 return map(lambda ip: 1 if ip in lst else 0, ids) + def getBanList(self, withTime=False): + """Returns the list of banned IP addresses. + + Returns + ------- + list + The list of banned IP addresses. + """ + return self.__banManager.getBanList(ordered=True, withTime=withTime) + def addBannedIP(self, ip): """Ban an IP or list of IPs.""" unixTime = MyTime.time() @@ -373,6 +384,8 @@ class Actions(JailThread, Mapping): "fid": lambda self: self.__ticket.getID(), "failures": lambda self: self.__ticket.getAttempt(), "time": lambda self: self.__ticket.getTime(), + "bantime": lambda self: self._getBanTime(), + "bancount": lambda self: self.__ticket.getBanCount(), "matches": lambda self: "\n".join(self.__ticket.getMatches()), # to bypass actions, that should not be executed for restored tickets "restored": lambda self: (1 if self.__ticket.restored else 0), @@ -399,6 +412,11 @@ class Actions(JailThread, Mapping): def copy(self): # pragma: no cover return self.__class__(self.__ticket, self.__jail, self.immutable, self.data.copy()) + def _getBanTime(self): + btime = self.__ticket.getBanTime() + if btime is None: btime = self.__jail.actions.getBanTime() + return int(btime) + def _mi4ip(self, overalljails=False): """Gets bans merged once, a helper for lambda(s), prevents stop of executing action by any exception inside. @@ -442,7 +460,9 @@ class Actions(JailThread, Mapping): return mi[idx] if mi[idx] is not None else self.__ticket - def __getActionInfo(self, ticket): + def _getActionInfo(self, ticket): + if not ticket: + ticket = BanTicket("", MyTime.time()) aInfo = Actions.ActionInfo(ticket, self._jail) return aInfo @@ -472,13 +492,19 @@ class Actions(JailThread, Mapping): tickets = self.__getFailTickets(self.banPrecedence) rebanacts = None for ticket in tickets: - bTicket = BanManager.createBanTicket(ticket) + + bTicket = BanTicket.wrap(ticket) + btime = ticket.getBanTime(self.__banManager.getBanTime()) ip = bTicket.getIP() - aInfo = self.__getActionInfo(bTicket) + aInfo = self._getActionInfo(bTicket) reason = {} if self.__banManager.addBanTicket(bTicket, reason=reason): cnt += 1 + # report ticket to observer, to check time should be increased and hereafter observer writes ban to database (asynchronous) + if Observers.Main is not None and not bTicket.restored: + Observers.Main.add('banFound', bTicket, self._jail, btime) logSys.notice("[%s] %sBan %s", self._jail.name, ('' if not bTicket.restored else 'Restore '), ip) + # do actions : for name, action in self._actions.iteritems(): try: if bTicket.restored and getattr(action, 'norestored', False): @@ -496,7 +522,10 @@ class Actions(JailThread, Mapping): if self.banEpoch: # be sure tickets always have the same ban epoch (default 0): bTicket.banEpoch = self.banEpoch else: - bTicket = reason['ticket'] + if reason.get('expired', 0): + logSys.info('[%s] Ignore %s, expired bantime', self._jail.name, ip) + continue + bTicket = reason.get('ticket', bTicket) # if already banned (otherwise still process some action) if bTicket.banned: # compare time of failure occurrence with time ticket was really banned: @@ -525,12 +554,8 @@ class Actions(JailThread, Mapping): 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) - # add ban to database: - if not bTicket.restored and self._jail.database is not None: - # ignore too old (repeated and ignored) tickets, - # [todo] replace it with inOperation later (once it gets back-ported): - if not reason and bTicket.getTime() >= MyTime.time() - 60: - self._jail.database.addBan(self._jail, bTicket) + # add ban to database moved to observer (should previously check not already banned + # and increase ticket time if "bantime.increment" set) if cnt: logSys.debug("Banned %s / %s, %s ticket(s) in %r", cnt, self.__banManager.getBanTotal(), self.__banManager.size(), self._jail.name) @@ -549,7 +574,7 @@ class Actions(JailThread, Mapping): """ actions = actions or self._actions ip = ticket.getIP() - aInfo = self.__getActionInfo(ticket) + 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(): @@ -570,6 +595,29 @@ class Actions(JailThread, Mapping): ticket.banEpoch = self.banEpoch return 1 + def _prolongBan(self, ticket): + # prevent to prolong ticket that was removed in-between, + # if it in ban list - ban time already prolonged (and it stays there): + if not self.__banManager._inBanList(ticket): return + # do actions : + aInfo = None + for name, action in self._actions.iteritems(): + try: + if ticket.restored and getattr(action, 'norestored', False): + continue + if not action._prolongable: + continue + if aInfo is None: + aInfo = self._getActionInfo(ticket) + if not aInfo.immutable: aInfo.reset() + action.prolong(aInfo) + except Exception as e: + logSys.error( + "Failed to execute ban jail '%s' action '%s' " + "info '%r': %s", + self._jail.name, name, aInfo, e, + exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + def __checkUnBan(self, maxCount=None): """Check for IP address to unban. @@ -654,7 +702,7 @@ class Actions(JailThread, Mapping): else: unbactions = actions ip = ticket.getIP() - aInfo = self.__getActionInfo(ticket) + aInfo = self._getActionInfo(ticket) if log: logSys.notice("[%s] Unban %s", self._jail.name, aInfo["ip"]) for name, action in unbactions.iteritems(): diff --git a/fail2ban/server/banmanager.py b/fail2ban/server/banmanager.py index 575d648b..9168d5b8 100644 --- a/fail2ban/server/banmanager.py +++ b/fail2ban/server/banmanager.py @@ -66,7 +66,7 @@ class BanManager: # @param value the time def setBanTime(self, value): - self.__banTime = int(value) + self.__banTime = int(value) ## # Get the ban time. @@ -75,7 +75,7 @@ class BanManager: # @return the time def getBanTime(self): - return self.__banTime + return self.__banTime ## # Set the total number of banned address. @@ -83,7 +83,7 @@ class BanManager: # @param value total number def setBanTotal(self, value): - self.__banTotal = value + self.__banTotal = value ## # Get the total number of banned address. @@ -91,15 +91,29 @@ class BanManager: # @return the total number def getBanTotal(self): - return self.__banTotal + return self.__banTotal ## # Returns a copy of the IP list. # # @return IP list - def getBanList(self): - return list(self.__banList.keys()) + def getBanList(self, ordered=False, withTime=False): + if not ordered: + return list(self.__banList.keys()) + with self.__lock: + lst = [] + for ticket in self.__banList.itervalues(): + eob = ticket.getEndOfBanTime(self.__banTime) + lst.append((ticket,eob)) + lst.sort(key=lambda t: t[1]) + t2s = MyTime.time2str + if withTime: + return ['%s \t%s + %d = %s' % ( + t[0].getID(), + t2s(t[0].getTime()), t[0].getBanTime(self.__banTime), t2s(t[1]) + ) for t in lst] + return [t[0].getID() for t in lst] ## # Returns a iterator to ban list (used in reload, so idle). @@ -108,7 +122,7 @@ class BanManager: def __iter__(self): # ensure iterator is safe - traverse over the list in snapshot created within lock (GIL): - return iter(list(self.__banList.values())) + return iter(list(self.__banList.values())) ## # Returns normalized value @@ -245,21 +259,6 @@ class BanManager: return [] ## - # Create a ban ticket. - # - # Create a BanTicket from a FailTicket. The timestamp of the BanTicket - # is the current time. This is a static method. - # @param ticket the FailTicket - # @return a BanTicket - - @staticmethod - def createBanTicket(ticket): - # we should always use correct time to calculate correct end time (ban time is variable now, - # + possible double banning by restore from database and from log file) - # so use as lastTime always time from ticket. - return BanTicket(ticket=ticket) - - ## # Add a ban ticket. # # Add a BanTicket instance into the ban list. @@ -268,6 +267,9 @@ class BanManager: def addBanTicket(self, ticket, reason={}): eob = ticket.getEndOfBanTime(self.__banTime) + if eob < MyTime.time(): + reason['expired'] = 1 + return False with self.__lock: # check already banned fid = ticket.getID() @@ -289,6 +291,7 @@ class BanManager: # not yet banned - add new one: self.__banList[fid] = ticket self.__banTotal += 1 + ticket.incrBanCount() # correct next unban time: if self._nextUnbanTime > eob: self._nextUnbanTime = eob diff --git a/fail2ban/server/database.py b/fail2ban/server/database.py index 5fd00fad..59eeb8fd 100644 --- a/fail2ban/server/database.py +++ b/fail2ban/server/database.py @@ -142,7 +142,7 @@ class Fail2BanDb(object): filename purgeage """ - __version__ = 2 + __version__ = 4 # Note all SCRIPTS strings must end in ';' for py26 compatibility _CREATE_SCRIPTS = ( ('fail2banDb', "CREATE TABLE IF NOT EXISTS fail2banDb(version INTEGER);") @@ -170,21 +170,36 @@ class Fail2BanDb(object): "jail TEXT NOT NULL, " \ "ip TEXT, " \ "timeofban INTEGER NOT NULL, " \ + "bantime INTEGER NOT NULL, " \ + "bancount INTEGER NOT NULL default 1, " \ "data JSON, " \ "FOREIGN KEY(jail) REFERENCES jails(name) " \ ");" \ "CREATE INDEX IF NOT EXISTS bans_jail_timeofban_ip ON bans(jail, timeofban);" \ "CREATE INDEX IF NOT EXISTS bans_jail_ip ON bans(jail, ip);" \ "CREATE INDEX IF NOT EXISTS bans_ip ON bans(ip);") + ,('bips', "CREATE TABLE IF NOT EXISTS bips(" \ + "ip TEXT NOT NULL, " \ + "jail TEXT NOT NULL, " \ + "timeofban INTEGER NOT NULL, " \ + "bantime INTEGER NOT NULL, " \ + "bancount INTEGER NOT NULL default 1, " \ + "data JSON, " \ + "PRIMARY KEY(ip, jail), " \ + "FOREIGN KEY(jail) REFERENCES jails(name) " \ + ");" \ + "CREATE INDEX IF NOT EXISTS bips_timeofban ON bips(timeofban);" \ + "CREATE INDEX IF NOT EXISTS bips_ip ON bips(ip);") ) _CREATE_TABS = dict(_CREATE_SCRIPTS) - def __init__(self, filename, purgeAge=24*60*60): + def __init__(self, filename, purgeAge=24*60*60, outDatedFactor=3): self.maxMatches = 10 self._lock = RLock() self._dbFilename = filename self._purgeAge = purgeAge + self._outDatedFactor = outDatedFactor; self._connectDB() def _connectDB(self, checkIntegrity=False): @@ -372,13 +387,32 @@ class Fail2BanDb(object): if version < 2 and self._tableExists(cur, "logs"): cur.executescript("BEGIN TRANSACTION;" - "CREATE TEMPORARY TABLE logs_temp AS SELECT * FROM logs;" - "DROP TABLE logs;" - "%s;" - "INSERT INTO logs SELECT * from logs_temp;" - "DROP TABLE logs_temp;" - "UPDATE fail2banDb SET version = 2;" - "COMMIT;" % Fail2BanDb._CREATE_TABS['logs']) + "CREATE TEMPORARY TABLE logs_temp AS SELECT * FROM logs;" + "DROP TABLE logs;" + "%s;" + "INSERT INTO logs SELECT * from logs_temp;" + "DROP TABLE logs_temp;" + "UPDATE fail2banDb SET version = 2;" + "COMMIT;" % Fail2BanDb._CREATE_TABS['logs']) + + if version < 3 and self._tableExists(cur, "bans"): + # set ban-time to -2 (note it means rather unknown, as persistent, will be fixed by restore): + cur.executescript("BEGIN TRANSACTION;" + "CREATE TEMPORARY TABLE bans_temp AS SELECT jail, ip, timeofban, -2 as bantime, 1 as bancount, data FROM bans;" + "DROP TABLE bans;" + "%s;\n" + "INSERT INTO bans SELECT * from bans_temp;" + "DROP TABLE bans_temp;" + "COMMIT;" % Fail2BanDb._CREATE_TABS['bans']) + if version < 4 and not self._tableExists(cur, "bips"): + cur.executescript("BEGIN TRANSACTION;" + "%s;\n" + "UPDATE fail2banDb SET version = 4;" + "COMMIT;" % Fail2BanDb._CREATE_TABS['bips']) + if self._tableExists(cur, "bans"): + cur.execute( + "INSERT OR REPLACE INTO bips(ip, jail, timeofban, bantime, bancount, data)" + " SELECT ip, jail, timeofban, bantime, bancount, data FROM bans order by timeofban") cur.execute("SELECT version FROM fail2banDb LIMIT 1") return cur.fetchone()[0] @@ -591,8 +625,13 @@ class Fail2BanDb(object): data = data.copy() del data['matches'] cur.execute( - "INSERT INTO bans(jail, ip, timeofban, data) VALUES(?, ?, ?, ?)", - (jail.name, ip, int(round(ticket.getTime())), data)) + "INSERT INTO bans(jail, ip, timeofban, bantime, bancount, data) VALUES(?, ?, ?, ?, ?, ?)", + (jail.name, ip, int(round(ticket.getTime())), ticket.getBanTime(jail.actions.getBanTime()), ticket.getBanCount(), + data)) + cur.execute( + "INSERT OR REPLACE INTO bips(ip, jail, timeofban, bantime, bancount, data) VALUES(?, ?, ?, ?, ?, ?)", + (ip, jail.name, int(round(ticket.getTime())), ticket.getBanTime(jail.actions.getBanTime()), ticket.getBanCount(), + data)) @commitandrollback def delBan(self, cur, jail, *args): @@ -605,16 +644,20 @@ class Fail2BanDb(object): args : list of IP IPs to be removed, if not given all tickets of jail will be removed. """ - query = "DELETE FROM bans WHERE jail = ?" + query1 = "DELETE FROM bips WHERE jail = ?" + query2 = "DELETE FROM bans WHERE jail = ?" queryArgs = [jail.name]; if not len(args): - cur.execute(query, queryArgs); + cur.execute(query1, queryArgs); + cur.execute(query2, queryArgs); return - query += " AND ip = ?" + query1 += " AND ip = ?" + query2 += " AND ip = ?" queryArgs.append(''); for ip in args: queryArgs[1] = str(ip); - cur.execute(query, queryArgs); + cur.execute(query1, queryArgs); + cur.execute(query2, queryArgs); @commitandrollback def _getBans(self, cur, jail=None, bantime=None, ip=None): @@ -732,18 +775,41 @@ class Fail2BanDb(object): self._bansMergedCache[cacheKey] = tickets if ip is None else ticket return tickets if ip is None else ticket + @commitandrollback + def getBan(self, cur, ip, jail=None, forbantime=None, overalljails=None, fromtime=None): + ip = str(ip) + if not overalljails: + query = "SELECT bancount, timeofban, bantime FROM bips" + else: + query = "SELECT sum(bancount), max(timeofban), sum(bantime) FROM bips" + query += " WHERE ip = ?" + queryArgs = [ip] + if not overalljails and jail is not None: + query += " AND jail=?" + queryArgs.append(jail.name) + if forbantime is not None: + query += " AND timeofban > ?" + queryArgs.append(MyTime.time() - forbantime) + if fromtime is not None: + query += " AND timeofban > ?" + queryArgs.append(fromtime) + if overalljails or jail is None: + query += " GROUP BY ip ORDER BY timeofban DESC LIMIT 1" + # repack iterator as long as in lock: + return list(cur.execute(query, queryArgs)) + def _getCurrentBans(self, cur, jail = None, ip = None, forbantime=None, fromtime=None): - if fromtime is None: - fromtime = MyTime.time() queryArgs = [] if jail is not None: - query = "SELECT ip, timeofban, data FROM bans WHERE jail=?" + query = "SELECT ip, timeofban, bantime, bancount, data FROM bips WHERE jail=?" queryArgs.append(jail.name) else: - query = "SELECT ip, max(timeofban), data FROM bans WHERE 1" + query = "SELECT ip, max(timeofban), bantime, bancount, data FROM bips WHERE 1" if ip is not None: query += " AND ip=?" queryArgs.append(ip) + query += " AND (timeofban + bantime > ? OR bantime <= -1)" + queryArgs.append(fromtime) if forbantime not in (None, -1): # not specified or persistent (all) query += " AND timeofban > ?" queryArgs.append(fromtime - forbantime) @@ -753,36 +819,95 @@ class Fail2BanDb(object): query += " ORDER BY timeofban DESC LIMIT 1" return cur.execute(query, queryArgs) - def getCurrentBans(self, jail = None, ip = None, forbantime=None, fromtime=None, maxmatches=None): - tickets = [] - ticket = None - + def getCurrentBans(self, jail=None, ip=None, forbantime=None, fromtime=None, + correctBanTime=True, maxmatches=None + ): + """Reads tickets (with merged info) currently affected from ban from the database. + + There are all the tickets corresponding parameters jail/ip, forbantime, + fromtime (normally now). + + If correctBanTime specified (default True) it will fix the restored ban-time + (and therefore endOfBan) of the ticket (normally it is ban-time of jail as maximum) + for all tickets with ban-time greater (or persistent). + """ + cur = self._db.cursor() try: - with self._lock: - cur = self._db.cursor() - results = list(self._getCurrentBans(self._db.cursor(), - jail=jail, ip=ip, forbantime=forbantime, fromtime=fromtime)) + if fromtime is None: + fromtime = MyTime.time() + tickets = [] + ticket = None + if correctBanTime is True: + correctBanTime = jail.getMaxBanTime() if jail is not None else None + # don't change if persistent allowed: + if correctBanTime == -1: correctBanTime = None - if results: - for banip, timeofban, data in results: - # logSys.debug('restore ticket %r, %r, %r', banip, timeofban, data) - ticket = FailTicket(banip, timeofban, data=data) - # filter matches if expected (current count > as maxmatches specified): - if maxmatches is None: - maxmatches = self.maxMatches - if maxmatches: - matches = ticket.getMatches() - if matches and len(matches) > maxmatches: - ticket.setMatches(matches[-maxmatches:]) - else: - ticket.setMatches(None) - # logSys.debug('restored ticket: %r', ticket) - if ip is not None: return ticket - tickets.append(ticket) + with self._lock: + bans = self._getCurrentBans(cur, jail=jail, ip=ip, + forbantime=forbantime, fromtime=fromtime + ) + for ticket in bans: + # can produce unpack error (database may return sporadical wrong-empty row): + try: + banip, timeofban, bantime, bancount, data = ticket + # additionally check for empty values: + if banip is None or banip == "": # pragma: no cover + raise ValueError('unexpected value %r' % (banip,)) + # if bantime unknown (after upgrade-db from earlier version), just use min known ban-time: + if bantime == -2: # todo: remove it in future version + bantime = jail.actions.getBanTime() if jail is not None else ( + correctBanTime if correctBanTime else 600) + elif correctBanTime and correctBanTime >= 0: + # if persistent ban (or greater as max), use current max-bantime of the jail: + if bantime == -1 or bantime > correctBanTime: + bantime = correctBanTime + # after correction check the end of ban again: + if bantime != -1 and timeofban + bantime <= fromtime: + # not persistent and too old - ignore it: + logSys.debug("ignore ticket (with new max ban-time %r): too old %r <= %r, ticket: %r", + bantime, timeofban + bantime, fromtime, ticket) + continue + except ValueError as e: # pragma: no cover + logSys.debug("get current bans: ignore row %r - %s", ticket, e) + continue + # logSys.debug('restore ticket %r, %r, %r', banip, timeofban, data) + ticket = FailTicket(banip, timeofban, data=data) + # filter matches if expected (current count > as maxmatches specified): + if maxmatches is None: + maxmatches = self.maxMatches + if maxmatches: + matches = ticket.getMatches() + if matches and len(matches) > maxmatches: + ticket.setMatches(matches[-maxmatches:]) + else: + ticket.setMatches(None) + # logSys.debug('restored ticket: %r', ticket) + ticket.setBanTime(bantime) + ticket.setBanCount(bancount) + if ip is not None: return ticket + tickets.append(ticket) finally: - cur.close() + cur.close() + return tickets + def _cleanjails(self, cur): + """Remove empty jails jails and log files from database. + """ + cur.execute( + "DELETE FROM jails WHERE enabled = 0 " + "AND NOT EXISTS(SELECT * FROM bans WHERE jail = jails.name) " + "AND NOT EXISTS(SELECT * FROM bips WHERE jail = jails.name)") + + def _purge_bips(self, cur): + """Purge old bad ips (jails and log files from database). + Currently it is timed out IP, whose time since last ban is several times out-dated (outDatedFactor is default 3). + Permanent banned ips will be never removed. + """ + cur.execute( + "DELETE FROM bips WHERE timeofban < ? and bantime != -1 and (timeofban + (bantime * ?)) < ?", + (int(MyTime.time()) - self._purgeAge, self._outDatedFactor, int(MyTime.time()) - self._purgeAge)) + @commitandrollback def purge(self, cur): """Purge old bans, jails and log files from database. @@ -791,7 +916,6 @@ class Fail2BanDb(object): cur.execute( "DELETE FROM bans WHERE timeofban < ?", (MyTime.time() - self._purgeAge, )) - cur.execute( - "DELETE FROM jails WHERE enabled = 0 " - "AND NOT EXISTS(SELECT * FROM bans WHERE jail = jails.name)") + self._purge_bips(cur) + self._cleanjails(cur) diff --git a/fail2ban/server/failmanager.py b/fail2ban/server/failmanager.py index 64576dbd..3c71d51a 100644 --- a/fail2ban/server/failmanager.py +++ b/fail2ban/server/failmanager.py @@ -27,7 +27,7 @@ __license__ = "GPL" from threading import Lock import logging -from .ticket import FailTicket +from .ticket import FailTicket, BanTicket from ..helpers import getLogger, BgService # Gets the instance of the logger. @@ -69,7 +69,7 @@ class FailManager: def getMaxTime(self): return self.__maxTime - def addFailure(self, ticket, count=1): + def addFailure(self, ticket, count=1, observed=False): attempts = 1 with self.__lock: fid = ticket.getID() @@ -96,11 +96,14 @@ class FailManager: else: fData.setMatches(None) except KeyError: + # not found - already banned - prevent to add failure if comes from observer: + if observed or isinstance(ticket, BanTicket): + return ticket.getRetry() # if already FailTicket - add it direct, otherwise create (using copy all ticket data): if isinstance(ticket, FailTicket): fData = ticket; else: - fData = FailTicket(ticket=ticket) + fData = FailTicket.wrap(ticket) if count > ticket.getAttempt(): fData.setRetry(count) self.__failList[fid] = fData diff --git a/fail2ban/server/failregex.py b/fail2ban/server/failregex.py index 5cf18f80..a9b144af 100644 --- a/fail2ban/server/failregex.py +++ b/fail2ban/server/failregex.py @@ -87,8 +87,8 @@ RH4TAG = { # default failure groups map for customizable expressions (with different group-id): R_MAP = { - "ID": "fid", - "PORT": "fport", + "id": "fid", + "port": "fport", } # map global flags like ((?i)xxx) or (?:(?i)xxx) to local flags (?i:xxx) if supported by RE-engine in this python version: @@ -99,15 +99,19 @@ except: R_GLOB2LOCFLAGS = () def mapTag2Opt(tag): - try: # if should be mapped: - return R_MAP[tag] - except KeyError: - return tag.lower() + tag = tag.lower() + return R_MAP.get(tag, tag) -# alternate names to be merged, e. g. alt_user_1 -> user ... +# complex names: +# ALT_ - alternate names to be merged, e. g. alt_user_1 -> user ... ALTNAME_PRE = 'alt_' -ALTNAME_CRE = re.compile(r'^' + ALTNAME_PRE + r'(.*)(?:_\d+)?$') +# TUPLE_ - names of parts to be combined to single value as tuple +TUPNAME_PRE = 'tuple_' + +COMPLNAME_PRE = (ALTNAME_PRE, TUPNAME_PRE) +COMPLNAME_CRE = re.compile(r'^(' + '|'.join(COMPLNAME_PRE) + r')(.*?)(?:_\d+)?$') + ## # Regular expression class. @@ -137,19 +141,27 @@ class Regex: try: self._regexObj = re.compile(regex, re.MULTILINE if multiline else 0) self._regex = regex - self._altValues = {} + self._altValues = [] + self._tupleValues = [] for k in filter( - lambda k: len(k) > len(ALTNAME_PRE) and k.startswith(ALTNAME_PRE), - self._regexObj.groupindex + lambda k: len(k) > len(COMPLNAME_PRE[0]), self._regexObj.groupindex ): - n = ALTNAME_CRE.match(k).group(1) - self._altValues[k] = n - self._altValues = list(self._altValues.items()) if len(self._altValues) else None + n = COMPLNAME_CRE.match(k) + if n: + g, n = n.group(1), mapTag2Opt(n.group(2)) + if g == ALTNAME_PRE: + self._altValues.append((k,n)) + else: + self._tupleValues.append((k,n)) + self._altValues.sort() + self._tupleValues.sort() + self._altValues = self._altValues if len(self._altValues) else None + self._tupleValues = self._tupleValues if len(self._tupleValues) else None except sre_constants.error as e: raise RegexException("Unable to compile regular expression '%s':\n%s" % (regex, e)) - # set fetch handler depending on presence of alternate tags: - self.getGroups = self._getGroupsWithAlt if self._altValues else self._getGroups + # set fetch handler depending on presence of alternate (or tuple) tags: + self.getGroups = self._getGroupsWithAlt if (self._altValues or self._tupleValues) else self._getGroups def __str__(self): return "%s(%r)" % (self.__class__.__name__, self._regex) @@ -294,12 +306,23 @@ class Regex: def _getGroupsWithAlt(self): fail = self._matchCache.groupdict() - # merge alternate values (e. g. 'alt_user_1' -> 'user' or 'alt_host' -> 'host'): #fail = fail.copy() - for k,n in self._altValues: - v = fail.get(k) - if v and not fail.get(n): - fail[n] = v + # merge alternate values (e. g. 'alt_user_1' -> 'user' or 'alt_host' -> 'host'): + if self._altValues: + for k,n in self._altValues: + v = fail.get(k) + if v and not fail.get(n): + fail[n] = v + # combine tuple values (e. g. 'id', 'tuple_id' ... 'tuple_id_N' -> 'id'): + if self._tupleValues: + for k,n in self._tupleValues: + v = fail.get(k) + t = fail.get(n) + if isinstance(t, tuple): + t += (v,) + else: + t = (t,v,) + fail[n] = t return fail def getGroups(self): # pragma: no cover - abstract function (replaced in __init__) diff --git a/fail2ban/server/filter.py b/fail2ban/server/filter.py index 041773ab..3657ea48 100644 --- a/fail2ban/server/filter.py +++ b/fail2ban/server/filter.py @@ -33,6 +33,7 @@ import time from .actions import Actions from .failmanager import FailManagerEmpty, FailManager from .ipdns import DNSUtils, IPAddr +from .observer import Observers from .ticket import FailTicket from .jailthread import JailThread from .datedetector import DateDetector, validateTimeZone @@ -714,13 +715,16 @@ class Filter(JailThread): if self._inIgnoreIPList(ip, tick): continue logSys.info( - "[%s] Found %s - %s", self.jailName, ip, datetime.datetime.fromtimestamp(unixTime).strftime("%Y-%m-%d %H:%M:%S") + "[%s] Found %s - %s", self.jailName, ip, MyTime.time2str(unixTime) ) attempts = self.failManager.addFailure(tick) # avoid RC on busy filter (too many failures) - if attempts for IP/ID reached maxretry, # we can speedup ban, so do it as soon as possible: if attempts >= self.failManager.getMaxRetry(): self.performBan(ip) + # report to observer - failure was found, for possibly increasing of it retry counter (asynchronous) + if Observers.Main is not None: + Observers.Main.add('failureFound', self.failManager, self.jail, tick) self.procLines += 1 # every 100 lines check need to perform service tasks: if self.procLines % 100 == 0: @@ -1167,7 +1171,7 @@ class FileFilter(Filter): fs = container.getFileSize() if logSys.getEffectiveLevel() <= logging.DEBUG: logSys.debug("Seek to find time %s (%s), file size %s", date, - datetime.datetime.fromtimestamp(date).strftime("%Y-%m-%d %H:%M:%S"), fs) + MyTime.time2str(date), fs) minp = container.getPos() maxp = fs tryPos = minp @@ -1246,7 +1250,7 @@ class FileFilter(Filter): container.setPos(foundPos) if logSys.getEffectiveLevel() <= logging.DEBUG: logSys.debug("Position %s from %s, found time %s (%s) within %s seeks", lastPos, fs, foundTime, - (datetime.datetime.fromtimestamp(foundTime).strftime("%Y-%m-%d %H:%M:%S") if foundTime is not None else ''), cntr) + (MyTime.time2str(foundTime) if foundTime is not None else ''), cntr) def status(self, flavor="basic"): """Status of Filter plus files being monitored. diff --git a/fail2ban/server/ipdns.py b/fail2ban/server/ipdns.py index 5f3e4571..d6dfbb9d 100644 --- a/fail2ban/server/ipdns.py +++ b/fail2ban/server/ipdns.py @@ -358,7 +358,7 @@ class IPAddr(object): return repr(self.ntoa) def __str__(self): - return self.ntoa + return self.ntoa if isinstance(self.ntoa, basestring) else str(self.ntoa) def __reduce__(self): """IPAddr pickle-handler, that simply wraps IPAddr to the str diff --git a/fail2ban/server/jail.py b/fail2ban/server/jail.py index 048aded9..673b6454 100644 --- a/fail2ban/server/jail.py +++ b/fail2ban/server/jail.py @@ -24,10 +24,13 @@ __copyright__ = "Copyright (c) 2004 Cyril Jaquier, 2011-2012 Lee Clemens, 2012 Y __license__ = "GPL" import logging +import math +import random import Queue from .actions import Actions -from ..helpers import getLogger, extractOptions, MyTime +from ..helpers import getLogger, _as_bool, extractOptions, MyTime +from .mytime import MyTime # Gets the instance of the logger. logSys = getLogger(__name__) @@ -75,6 +78,8 @@ class Jail(object): self.__name = name self.__queue = Queue.Queue() self.__filter = None + # Extra parameters for increase ban time + self._banExtra = {}; logSys.info("Creating new jail '%s'" % self.name) if backend is not None: self._setBackend(backend) @@ -203,6 +208,8 @@ class Jail(object): Used by filter to add a failure for banning. """ self.__queue.put(ticket) + # add ban to database moved to observer (should previously check not already banned + # and increase ticket time if "bantime.increment" set) def getFailTicket(self): """Get a fail ticket from the jail. @@ -215,16 +222,80 @@ class Jail(object): except Queue.Empty: return False - def restoreCurrentBans(self): + def setBanTimeExtra(self, opt, value): + # merge previous extra with new option: + be = self._banExtra; + if value == '': + value = None + if value is not None: + be[opt] = value; + elif opt in be: + del be[opt] + logSys.info('Set banTime.%s = %s', opt, value) + if opt == 'increment': + be[opt] = _as_bool(value) + if be.get(opt) and self.database is None: + logSys.warning("ban time increment is not available as long jail database is not set") + if opt in ['maxtime', 'rndtime']: + if not value is None: + be[opt] = MyTime.str2seconds(value) + # prepare formula lambda: + if opt in ['formula', 'factor', 'maxtime', 'rndtime', 'multipliers'] or be.get('evformula', None) is None: + # split multifiers to an array begins with 0 (or empty if not set): + if opt == 'multipliers': + be['evmultipliers'] = [int(i) for i in (value.split(' ') if value is not None and value != '' else [])] + # if we have multifiers - use it in lambda, otherwise compile and use formula within lambda + multipliers = be.get('evmultipliers', []) + banFactor = eval(be.get('factor', "1")) + if len(multipliers): + evformula = lambda ban, banFactor=banFactor: ( + ban.Time * banFactor * multipliers[ban.Count if ban.Count < len(multipliers) else -1] + ) + else: + formula = be.get('formula', 'ban.Time * (1<<(ban.Count if ban.Count<20 else 20)) * banFactor') + formula = compile(formula, '~inline-conf-expr~', 'eval') + evformula = lambda ban, banFactor=banFactor, formula=formula: max(ban.Time, eval(formula)) + # extend lambda with max time : + if not be.get('maxtime', None) is None: + maxtime = be['maxtime'] + evformula = lambda ban, evformula=evformula: min(evformula(ban), maxtime) + # mix lambda with random time (to prevent bot-nets to calculate exact time IP can be unbanned): + if not be.get('rndtime', None) is None: + rndtime = be['rndtime'] + evformula = lambda ban, evformula=evformula: (evformula(ban) + random.random() * rndtime) + # set to extra dict: + be['evformula'] = evformula + #logSys.info('banTimeExtra : %s' % json.dumps(be)) + + def getBanTimeExtra(self, opt=None): + if opt is not None: + return self._banExtra.get(opt, None) + return self._banExtra + + def getMaxBanTime(self): + """Returns max possible ban-time of jail. + """ + return self._banExtra.get("maxtime", -1) \ + if self._banExtra.get('increment') else self.actions.getBanTime() + + def restoreCurrentBans(self, correctBanTime=True): """Restore any previous valid bans from the database. """ try: if self.database is not None: - forbantime = self.actions.getBanTime() - for ticket in self.database.getCurrentBans(jail=self, - forbantime=forbantime, maxmatches=self.filter.failManager.maxMatches): - #logSys.debug('restored ticket: %s', ticket) - if not self.filter.inIgnoreIPList(ticket.getIP(), log_ignore=True): + if self._banExtra.get('increment'): + forbantime = None; + if correctBanTime: + correctBanTime = self.getMaxBanTime() + else: + # use ban time as search time if we have not enabled a increasing: + forbantime = self.actions.getBanTime() + for ticket in self.database.getCurrentBans(jail=self, forbantime=forbantime, + correctBanTime=correctBanTime, maxmatches=self.filter.failManager.maxMatches + ): + try: + #logSys.debug('restored ticket: %s', ticket) + if self.filter.inIgnoreIPList(ticket.getIP(), log_ignore=True): continue # mark ticked was restored from database - does not put it again into db: ticket.restored = True # correct start time / ban time (by the same end of ban): @@ -235,11 +306,13 @@ class Jail(object): # ignore obsolete tickets: if btm != -1 and btm <= 0: continue - ticket.setTime(MyTime.time()) - ticket.setBanTime(btm) self.putFailTicket(ticket) + except Exception as e: # pragma: no cover + logSys.error('Restore ticket failed: %s', e, + exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) except Exception as e: # pragma: no cover - logSys.error('%s', e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + logSys.error('Restore bans failed: %s', e, + exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) def start(self): """Start the jail, by starting filter and actions threads. diff --git a/fail2ban/server/mytime.py b/fail2ban/server/mytime.py index b6770721..315d8a30 100644 --- a/fail2ban/server/mytime.py +++ b/fail2ban/server/mytime.py @@ -113,6 +113,19 @@ class MyTime: return time.localtime(x) else: return time.localtime(MyTime.myTime) + + @staticmethod + def time2str(unixTime, format="%Y-%m-%d %H:%M:%S"): + """Convert time to a string representing as date and time using given format. + Default format is ISO 8601, YYYY-MM-DD HH:MM:SS without microseconds. + + @return ISO-capable string representation of given unixTime + """ + # consider end of 9999th year (in GMT+23 to avoid year overflow in other TZ) + dt = datetime.datetime.fromtimestamp( + unixTime).replace(microsecond=0 + ) if unixTime < 253402214400 else datetime.datetime(9999, 12, 31, 23, 59, 59) + return dt.strftime(format) ## precreate/precompile primitives used in str2seconds: diff --git a/fail2ban/server/observer.py b/fail2ban/server/observer.py new file mode 100644 index 00000000..b585706f --- /dev/null +++ b/fail2ban/server/observer.py @@ -0,0 +1,535 @@ +# emacs: -*- mode: python; py-indent-offset: 4; indent-tabs-mode: t -*- +# vi: set ft=python sts=4 ts=4 sw=4 noet : + +# This file is part of Fail2Ban. +# +# Fail2Ban is free software; you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation; either version 2 of the License, or +# (at your option) any later version. +# +# Fail2Ban is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with Fail2Ban; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. + +# Author: Serg G. Brester (sebres) +# +# This module was written as part of ban time increment feature. + +__author__ = "Serg G. Brester (sebres)" +__copyright__ = "Copyright (c) 2014 Serg G. Brester" +__license__ = "GPL" + +import threading +from .jailthread import JailThread +from .failmanager import FailManagerEmpty +import os, logging, time, datetime, math, json, random +import sys +from ..helpers import getLogger +from .mytime import MyTime +from .utils import Utils + +# Gets the instance of the logger. +logSys = getLogger(__name__) + +class ObserverThread(JailThread): + """Handles observing a database, managing bad ips and ban increment. + + Parameters + ---------- + + Attributes + ---------- + daemon + ident + name + status + active : bool + Control the state of the thread. + idle : bool + Control the idle state of the thread. + sleeptime : int + The time the thread sleeps for in the loop. + """ + + # observer is event driven and it sleep organized incremental, so sleep intervals can be shortly: + DEFAULT_SLEEP_INTERVAL = Utils.DEFAULT_SLEEP_INTERVAL / 10 + + def __init__(self): + # init thread + super(ObserverThread, self).__init__(name='f2b/observer') + # before started - idle: + self.idle = True + ## Event queue + self._queue_lock = threading.RLock() + self._queue = [] + ## Event, be notified if anything added to event queue + self._notify = threading.Event() + ## Sleep for max 60 seconds, it possible to specify infinite to always sleep up to notifying via event, + ## but so we can later do some service "events" occurred infrequently directly in main loop of observer (not using queue) + self.sleeptime = 60 + # + self._timers = {} + self._paused = False + self.__db = None + self.__db_purge_interval = 60*60 + # observer is a not main thread: + self.daemon = True + + def __getitem__(self, i): + try: + return self._queue[i] + except KeyError: + raise KeyError("Invalid event index : %s" % i) + + def __delitem__(self, i): + try: + del self._queue[i] + except KeyError: + raise KeyError("Invalid event index: %s" % i) + + def __iter__(self): + return iter(self._queue) + + def __len__(self): + return len(self._queue) + + def __eq__(self, other): # Required for Threading + return False + + def __hash__(self): # Required for Threading + return id(self) + + def add_named_timer(self, name, starttime, *event): + """Add a named timer event to queue will start (and wake) in 'starttime' seconds + + Previous timer event with same name will be canceled and trigger self into + queue after new 'starttime' value + """ + t = self._timers.get(name, None) + if t is not None: + t.cancel() + t = threading.Timer(starttime, self.add, event) + self._timers[name] = t + t.start() + + def add_timer(self, starttime, *event): + """Add a timer event to queue will start (and wake) in 'starttime' seconds + """ + # in testing we should wait (looping) for the possible time drifts: + if MyTime.myTime is not None and starttime: + # test time after short sleep: + t = threading.Timer(Utils.DEFAULT_SLEEP_INTERVAL, self._delayedEvent, + (MyTime.time() + starttime, time.time() + starttime, event) + ) + t.start() + return + # add timer event: + t = threading.Timer(starttime, self.add, event) + t.start() + + def _delayedEvent(self, endMyTime, endTime, event): + if MyTime.time() >= endMyTime or time.time() >= endTime: + self.add_timer(0, *event) + return + # repeat after short sleep: + t = threading.Timer(Utils.DEFAULT_SLEEP_INTERVAL, self._delayedEvent, + (endMyTime, endTime, event) + ) + t.start() + + def pulse_notify(self): + """Notify wakeup (sets /and resets/ notify event) + """ + if not self._paused: + n = self._notify + if n: + n.set() + #n.clear() + + def add(self, *event): + """Add a event to queue and notify thread to wake up. + """ + ## lock and add new event to queue: + with self._queue_lock: + self._queue.append(event) + self.pulse_notify() + + def add_wn(self, *event): + """Add a event to queue withouth notifying thread to wake up. + """ + ## lock and add new event to queue: + with self._queue_lock: + self._queue.append(event) + + def call_lambda(self, l, *args): + l(*args) + + def run(self): + """Main loop for Threading. + + This function is the main loop of the thread. + + Returns + ------- + bool + True when the thread exits nicely. + """ + logSys.info("Observer start...") + ## first time create named timer to purge database each hour (clean old entries) ... + self.add_named_timer('DB_PURGE', self.__db_purge_interval, 'db_purge') + ## Mapping of all possible event types of observer: + __meth = { + # universal lambda: + 'call': self.call_lambda, + # system and service events: + 'db_set': self.db_set, + 'db_purge': self.db_purge, + # service events of observer self: + 'is_alive' : self.isAlive, + 'is_active': self.isActive, + 'start': self.start, + 'stop': self.stop, + 'nop': lambda:(), + 'shutdown': lambda:() + } + try: + ## check it self with sending is_alive event + self.add('is_alive') + ## if we should stop - break a main loop + while self.active: + self.idle = False + ## check events available and execute all events from queue + while not self._paused: + ## lock, check and pop one from begin of queue: + try: + ev = None + with self._queue_lock: + if len(self._queue): + ev = self._queue.pop(0) + if ev is None: + break + ## retrieve method by name + meth = ev[0] + if not callable(ev[0]): meth = __meth.get(meth) or getattr(self, meth) + ## execute it with rest of event as variable arguments + meth(*ev[1:]) + except Exception as e: + #logSys.error('%s', e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + logSys.error('%s', e, exc_info=True) + ## going sleep, wait for events (in queue) + n = self._notify + if n: + self.idle = True + n.wait(self.sleeptime) + ## wake up - reset signal now (we don't need it so long as we reed from queue) + n.clear() + if self._paused: + continue + else: + ## notify event deleted (shutdown) - just sleep a litle bit (waiting for shutdown events, prevent high cpu usage) + time.sleep(ObserverThread.DEFAULT_SLEEP_INTERVAL) + ## stop by shutdown and empty queue : + if not self.is_full: + break + ## end of main loop - exit + logSys.info("Observer stopped, %s events remaining.", len(self._queue)) + self._notify = None + #print("Observer stopped, %s events remaining." % len(self._queue)) + except Exception as e: + logSys.error('Observer stopped after error: %s', e, exc_info=True) + #print("Observer stopped with error: %s" % str(e)) + # clear all events - exit, for possible calls of wait_empty: + with self._queue_lock: + self._queue = [] + self.idle = True + return True + + def isAlive(self): + #logSys.debug("Observer alive...") + return True + + def isActive(self, fromStr=None): + # logSys.info("Observer alive, %s%s", + # 'active' if self.active else 'inactive', + # '' if fromStr is None else (", called from '%s'" % fromStr)) + return self.active + + def start(self): + with self._queue_lock: + if not self.active: + super(ObserverThread, self).start() + + def stop(self, wtime=5, forceQuit=True): + if self.active and self._notify: + logSys.info("Observer stop ... try to end queue %s seconds", wtime) + #print("Observer stop ....") + # just add shutdown job to make possible wait later until full (events remaining) + with self._queue_lock: + self.add_wn('shutdown') + #don't pulse - just set, because we will delete it hereafter (sometimes not wakeup) + n = self._notify + self._notify.set() + #self.pulse_notify() + self._notify = None + # wait max wtime seconds until full (events remaining) + if self.wait_empty(wtime) or forceQuit: + n.clear() + self.active = False; # leave outer (active) loop + self._paused = True; # leave inner (queue) loop + self.__db = None + else: + self._notify = n + return self.wait_idle(min(wtime, 0.5)) and not self.is_full + return True + + @property + def is_full(self): + with self._queue_lock: + return True if len(self._queue) else False + + def wait_empty(self, sleeptime=None): + """Wait observer is running and returns if observer has no more events (queue is empty) + """ + time.sleep(ObserverThread.DEFAULT_SLEEP_INTERVAL) + if sleeptime is not None: + e = MyTime.time() + sleeptime + # block queue with not operation to be sure all really jobs are executed if nop goes from queue : + if self._notify is not None: + self.add_wn('nop') + if self.is_full and self.idle: + self.pulse_notify() + while self.is_full: + if sleeptime is not None and MyTime.time() > e: + break + time.sleep(ObserverThread.DEFAULT_SLEEP_INTERVAL) + # wait idle to be sure the last queue element is processed (because pop event before processing it) : + self.wait_idle(0.001) + return not self.is_full + + + def wait_idle(self, sleeptime=None): + """Wait observer is running and returns if observer idle (observer sleeps) + """ + time.sleep(ObserverThread.DEFAULT_SLEEP_INTERVAL) + if self.idle: + return True + if sleeptime is not None: + e = MyTime.time() + sleeptime + while not self.idle: + if sleeptime is not None and MyTime.time() > e: + break + time.sleep(ObserverThread.DEFAULT_SLEEP_INTERVAL) + return self.idle + + @property + def paused(self): + return self._paused; + + @paused.setter + def paused(self, pause): + if self._paused == pause: + return + self._paused = pause + # wake after pause ended + self.pulse_notify() + + + @property + def status(self): + """Status of observer to be implemented. [TODO] + """ + return ('', '') + + ## ----------------------------------------- + ## [Async] database service functionality ... + ## ----------------------------------------- + + def db_set(self, db): + self.__db = db + + def db_purge(self): + logSys.debug("Purge database event occurred") + if self.__db is not None: + self.__db.purge() + # trigger timer again ... + self.add_named_timer('DB_PURGE', self.__db_purge_interval, 'db_purge') + + ## ----------------------------------------- + ## [Async] ban time increment functionality ... + ## ----------------------------------------- + + def failureFound(self, failManager, jail, ticket): + """ Notify observer a failure for ip was found + + Observer will check ip was known (bad) and possibly increase an retry count + """ + # check jail active : + if not jail.isAlive() or not jail.getBanTimeExtra("increment"): + return + ip = ticket.getIP() + unixTime = ticket.getTime() + logSys.debug("[%s] Observer: failure found %s", jail.name, ip) + # increase retry count for known (bad) ip, corresponding banCount of it (one try will count than 2, 3, 5, 9 ...) : + banCount = 0 + retryCount = 1 + timeOfBan = None + try: + maxRetry = failManager.getMaxRetry() + db = jail.database + if db is not None: + for banCount, timeOfBan, lastBanTime in db.getBan(ip, jail): + banCount = max(banCount, ticket.getBanCount()) + retryCount = ((1 << (banCount if banCount < 20 else 20))/2 + 1) + # if lastBanTime == -1 or timeOfBan + lastBanTime * 2 > MyTime.time(): + # retryCount = maxRetry + break + retryCount = min(retryCount, maxRetry) + # check this ticket already known (line was already processed and in the database and will be restored from there): + if timeOfBan is not None and unixTime <= timeOfBan: + logSys.debug("[%s] Ignore failure %s before last ban %s < %s, restored", + jail.name, ip, unixTime, timeOfBan) + return + # for not increased failures observer should not add it to fail manager, because was already added by filter self + if retryCount <= 1: + return + # retry counter was increased - add it again: + logSys.info("[%s] Found %s, bad - %s, %s # -> %s%s", jail.name, ip, + MyTime.time2str(unixTime), banCount, retryCount, + (', Ban' if retryCount >= maxRetry else '')) + # retryCount-1, because a ticket was already once incremented by filter self + retryCount = failManager.addFailure(ticket, retryCount - 1, True) + ticket.setBanCount(banCount) + # after observe we have increased attempt count, compare it >= maxretry ... + if retryCount >= maxRetry: + # perform the banning of the IP now (again) + # [todo]: this code part will be used multiple times - optimize it later. + try: # pragma: no branch - exception is the only way out + while True: + ticket = failManager.toBan(ip) + jail.putFailTicket(ticket) + except FailManagerEmpty: + failManager.cleanup(MyTime.time()) + + except Exception as e: + logSys.error('%s', e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + + + class BanTimeIncr: + def __init__(self, banTime, banCount): + self.Time = banTime + self.Count = banCount + + def calcBanTime(self, jail, banTime, banCount): + be = jail.getBanTimeExtra() + return be['evformula'](self.BanTimeIncr(banTime, banCount)) + + def incrBanTime(self, jail, banTime, ticket): + """Check for IP address to increment ban time (if was already banned). + + Returns + ------- + float + new ban time. + """ + # check jail active : + if not jail.isAlive() or not jail.database: + return banTime + be = jail.getBanTimeExtra() + ip = ticket.getIP() + orgBanTime = banTime + # check ip was already banned (increment time of ban): + try: + if banTime > 0 and be.get('increment', False): + # search IP in database and increase time if found: + for banCount, timeOfBan, lastBanTime in \ + jail.database.getBan(ip, jail, overalljails=be.get('overalljails', False)) \ + : + # increment count in ticket (if still not increased from banmanager, test-cases?): + if banCount >= ticket.getBanCount(): + ticket.setBanCount(banCount+1) + logSys.debug('IP %s was already banned: %s #, %s', ip, banCount, timeOfBan); + # calculate new ban time + if banCount > 0: + banTime = be['evformula'](self.BanTimeIncr(banTime, banCount)) + ticket.setBanTime(banTime) + # check current ticket time to prevent increasing for twice read tickets (restored from log file besides database after restart) + if ticket.getTime() > timeOfBan: + logSys.info('[%s] IP %s is bad: %s # last %s - incr %s to %s' % (jail.name, ip, banCount, + MyTime.time2str(timeOfBan), + MyTime.seconds2str(orgBanTime), MyTime.seconds2str(banTime))) + else: + ticket.restored = True + break + except Exception as e: + logSys.error('%s', e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + return banTime + + def banFound(self, ticket, jail, btime): + """ Notify observer a ban occured for ip + + Observer will check ip was known (bad) and possibly increase/prolong a ban time + Secondary we will actualize the bans and bips (bad ip) in database + """ + if ticket.restored: # pragma: no cover (normally not resored tickets only) + return + try: + oldbtime = btime + ip = ticket.getIP() + logSys.debug("[%s] Observer: ban found %s, %s", jail.name, ip, btime) + # if not permanent and ban time was not set - check time should be increased: + if btime != -1 and ticket.getBanTime() is None: + btime = self.incrBanTime(jail, btime, ticket) + # if we should prolong ban time: + if btime == -1 or btime > oldbtime: + ticket.setBanTime(btime) + # if not permanent + if btime != -1: + bendtime = ticket.getTime() + btime + logtime = (MyTime.seconds2str(btime), MyTime.time2str(bendtime)) + # check ban is not too old : + if bendtime < MyTime.time(): + logSys.debug('Ignore old bantime %s', logtime[1]) + return False + else: + logtime = ('permanent', 'infinite') + # if ban time was prolonged - log again with new ban time: + if btime != oldbtime: + logSys.notice("[%s] Increase Ban %s (%d # %s -> %s)", jail.name, + ip, ticket.getBanCount(), *logtime) + # delayed prolonging ticket via actions that expected this (not later than 10 sec): + logSys.log(5, "[%s] Observer: prolong %s in %s", jail.name, ip, (btime, oldbtime)) + self.add_timer(min(10, max(0, btime - oldbtime - 5)), self.prolongBan, ticket, jail) + # add ticket to database, but only if was not restored (not already read from database): + if jail.database is not None and not ticket.restored: + # add to database always only after ban time was calculated an not yet already banned: + jail.database.addBan(jail, ticket) + except Exception as e: + logSys.error('%s', e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + + def prolongBan(self, ticket, jail): + """ Notify observer a ban occured for ip + + Observer will check ip was known (bad) and possibly increase/prolong a ban time + Secondary we will actualize the bans and bips (bad ip) in database + """ + try: + btime = ticket.getBanTime() + ip = ticket.getIP() + logSys.debug("[%s] Observer: prolong %s, %s", jail.name, ip, btime) + # prolong ticket via actions that expected this: + jail.actions._prolongBan(ticket) + except Exception as e: + logSys.error('%s', e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + +# Global observer initial created in server (could be later rewriten via singleton) +class _Observers: + def __init__(self): + self.Main = None + +Observers = _Observers() diff --git a/fail2ban/server/server.py b/fail2ban/server/server.py index 02937a5a..38831a00 100644 --- a/fail2ban/server/server.py +++ b/fail2ban/server/server.py @@ -32,6 +32,7 @@ import signal import stat import sys +from .observer import Observers, ObserverThread from .jails import Jails from .filter import DNSUtils, FileFilter, JournalFilter from .transmitter import Transmitter @@ -111,7 +112,7 @@ class Server: self.__prev_signals[s] = signal.getsignal(s) signal.signal(s, new) - def start(self, sock, pidfile, force=False, conf={}): + def start(self, sock, pidfile, force=False, observer=True, conf={}): # First set the mask to only allow access to owner os.umask(0o077) # Second daemonize before logging etc, because it will close all handles: @@ -165,6 +166,12 @@ class Server: except (OSError, IOError) as e: # pragma: no cover logSys.error("Unable to create PID file: %s", e) + # Create observers and start it: + if observer: + if Observers.Main is None: + Observers.Main = ObserverThread() + Observers.Main.start() + # Start the communication logSys.debug("Starting communication") try: @@ -205,21 +212,33 @@ class Server: for s, sh in self.__prev_signals.iteritems(): signal.signal(s, sh) + # Give observer a small chance to complete its work before exit + obsMain = Observers.Main + if obsMain is not None: + if obsMain.stop(forceQuit=False): + obsMain = None + Observers.Main = None + # Now stop all the jails self.stopAllJail() + # Stop observer ultimately + if obsMain is not None: + obsMain.stop() + # Explicit close database (server can leave in a thread, # so delayed GC can prevent commiting changes) if self.__db: self.__db.close() self.__db = None - # Stop async + # Stop async and exit if self.__asyncServer is not None: self.__asyncServer.stop() self.__asyncServer = None logSys.info("Exiting Fail2ban") + def addJail(self, name, backend): addflg = True if self.__reload_state.get(name) and self.__jails.exists(name): @@ -556,6 +575,27 @@ class Server: def getBanTime(self, name): return self.__jails[name].actions.getBanTime() + + def getBanList(self, name, withTime=False): + """Returns the list of banned IP addresses for a jail. + + Parameters + ---------- + name : str + The name of a jail. + + Returns + ------- + list + The list of banned IP addresses. + """ + return self.__jails[name].actions.getBanList(withTime) + + def setBanTimeExtra(self, name, opt, value): + self.__jails[name].setBanTimeExtra(opt, value) + + def getBanTimeExtra(self, name, opt): + return self.__jails[name].getBanTimeExtra(opt) def isStarted(self): return self.__asyncServer is not None and self.__asyncServer.isActive() @@ -805,6 +845,8 @@ class Server: logSys.error( "Unable to import fail2ban database module as sqlite " "is not available.") + if Observers.Main is not None: + Observers.Main.db_set(self.__db) def getDatabase(self): return self.__db diff --git a/fail2ban/server/ticket.py b/fail2ban/server/ticket.py index 8feeac9a..f99b6462 100644 --- a/fail2ban/server/ticket.py +++ b/fail2ban/server/ticket.py @@ -24,8 +24,6 @@ __author__ = "Cyril Jaquier" __copyright__ = "Copyright (c) 2004 Cyril Jaquier" __license__ = "GPL" -import sys - from ..helpers import getLogger from .ipdns import IPAddr from .mytime import MyTime @@ -35,6 +33,7 @@ logSys = getLogger(__name__) class Ticket(object): + __slots__ = ('_ip', '_flags', '_banCount', '_banTime', '_time', '_data', '_retry', '_lastReset') MAX_TIME = 0X7FFFFFFFFFFF ;# 4461763-th year @@ -61,35 +60,44 @@ class Ticket(object): self._data[k] = v if ticket: # ticket available - copy whole information from ticket: - self.__dict__.update(i for i in ticket.__dict__.iteritems() if i[0] in self.__dict__) + self.update(ticket) + #self.__dict__.update(i for i in ticket.__dict__.iteritems() if i[0] in self.__dict__) def __str__(self): - return "%s: ip=%s time=%s #attempts=%d matches=%r" % \ - (self.__class__.__name__.split('.')[-1], self.__ip, self._time, - self._data['failures'], self._data.get('matches', [])) + return "%s: ip=%s time=%s bantime=%s bancount=%s #attempts=%d matches=%r" % \ + (self.__class__.__name__.split('.')[-1], self._ip, self._time, + self._banTime, self._banCount, + self._data['failures'], self._data.get('matches', [])) def __repr__(self): return str(self) def __eq__(self, other): try: - return self.__ip == other.__ip and \ + return self._ip == other._ip and \ round(self._time, 2) == round(other._time, 2) and \ self._data == other._data except AttributeError: return False + def update(self, ticket): + for n in ticket.__slots__: + v = getattr(ticket, n, None) + if v is not None: + setattr(self, n, v) + + def setIP(self, value): # guarantee using IPAddr instead of unicode, str for the IP if isinstance(value, basestring): value = IPAddr(value) - self.__ip = value + self._ip = value def getID(self): - return self._data.get('fid', self.__ip) + return self._data.get('fid', self._ip) def getIP(self): - return self.__ip + return self._ip def setTime(self, value): self._time = value @@ -98,16 +106,17 @@ class Ticket(object): return self._time def setBanTime(self, value): - self._banTime = value; + self._banTime = value def getBanTime(self, defaultBT=None): return (self._banTime if self._banTime is not None else defaultBT) - def setBanCount(self, value): - self._banCount = value; + def setBanCount(self, value, always=False): + if always or value > self._banCount: + self._banCount = value - def incrBanCount(self, value = 1): - self._banCount += value; + def incrBanCount(self, value=1): + self._banCount += value def getBanCount(self): return self._banCount; @@ -267,10 +276,19 @@ class FailTicket(Ticket): else: self._data['matches'] = matches + @staticmethod + def wrap(o): + o.__class__ = FailTicket + return o + ## # Ban Ticket. # # This class extends the Ticket class. It is mainly used by the BanManager. -class BanTicket(Ticket): - pass +class BanTicket(FailTicket): + + @staticmethod + def wrap(o): + o.__class__ = BanTicket + return o diff --git a/fail2ban/server/transmitter.py b/fail2ban/server/transmitter.py index 3927aac3..6de60f94 100644 --- a/fail2ban/server/transmitter.py +++ b/fail2ban/server/transmitter.py @@ -353,6 +353,12 @@ class Transmitter: value = command[2:] if self.__quiet: return return self.__server.addAttemptIP(name, *value) + elif command[1].startswith("bantime."): + value = command[2] + opt = command[1][len("bantime."):] + self.__server.setBanTimeExtra(name, opt, value) + if self.__quiet: return + return self.__server.getBanTimeExtra(name, opt) elif command[1] == "banip": value = command[2:] return self.__server.setBanIP(name,value) @@ -475,6 +481,12 @@ class Transmitter: # Action elif command[1] == "bantime": return self.__server.getBanTime(name) + elif command[1] == "banip": + return self.__server.getBanList(name, + withTime=len(command) > 2 and command[2] == "--with-time") + elif command[1].startswith("bantime."): + opt = command[1][len("bantime."):] + return self.__server.getBanTimeExtra(name, opt) elif command[1] == "actions": return self.__server.getActions(name).keys() elif command[1] == "action": diff --git a/fail2ban/server/utils.py b/fail2ban/server/utils.py index 4e64ca0b..294d147f 100644 --- a/fail2ban/server/utils.py +++ b/fail2ban/server/utils.py @@ -355,7 +355,7 @@ class Utils(): return e.errno == errno.EPERM else: return True - else: # pragma : no cover (no windows currently supported) + else: # pragma: no cover (no windows currently supported) @staticmethod def pid_exists(pid): import ctypes diff --git a/fail2ban/tests/actionstestcase.py b/fail2ban/tests/actionstestcase.py index 532fe6ed..7b85ff94 100644 --- a/fail2ban/tests/actionstestcase.py +++ b/fail2ban/tests/actionstestcase.py @@ -159,7 +159,7 @@ class ExecuteActions(LogCaptureTestCase): "action2", os.path.join(TEST_FILES_DIR, "action.d/action_modifyainfo.py"), {}) - self.__jail.putFailTicket(FailTicket("1.2.3.4", 0)) + self.__jail.putFailTicket(FailTicket("1.2.3.4")) self.__actions._Actions__checkBan() # Will fail if modification of aInfo from first action propagates # to second action, as both delete same key diff --git a/fail2ban/tests/actiontestcase.py b/fail2ban/tests/actiontestcase.py index 125706af..d45c3171 100644 --- a/fail2ban/tests/actiontestcase.py +++ b/fail2ban/tests/actiontestcase.py @@ -207,15 +207,15 @@ class CommandActionTest(LogCaptureTestCase): self.assertEqual( self.__action.replaceTag("<matches>", {'matches': "some >char< should \\< be[ escap}ed&\n"}), - "some \\>char\\< should \\\\\\< be\\[ escap\\}ed\\&\n") + "some \\>char\\< should \\\\\\< be\\[ escap\\}ed\\&\\n") self.assertEqual( self.__action.replaceTag("<ipmatches>", {'ipmatches': "some >char< should \\< be[ escap}ed&\n"}), - "some \\>char\\< should \\\\\\< be\\[ escap\\}ed\\&\n") + "some \\>char\\< should \\\\\\< be\\[ escap\\}ed\\&\\n") self.assertEqual( self.__action.replaceTag("<ipjailmatches>", - {'ipjailmatches': "some >char< should \\< be[ escap}ed&\n"}), - "some \\>char\\< should \\\\\\< be\\[ escap\\}ed\\&\n") + {'ipjailmatches': "some >char< should \\< be[ escap}ed&\r\n"}), + "some \\>char\\< should \\\\\\< be\\[ escap\\}ed\\&\\r\\n") # Recursive aInfo["ABC"] = "<xyz>" diff --git a/fail2ban/tests/banmanagertestcase.py b/fail2ban/tests/banmanagertestcase.py index 6f2e1732..ec8e6f9f 100644 --- a/fail2ban/tests/banmanagertestcase.py +++ b/fail2ban/tests/banmanagertestcase.py @@ -26,6 +26,8 @@ __license__ = "GPL" import unittest +from .utils import setUpMyTime, tearDownMyTime + from ..server.banmanager import BanManager from ..server.ipdns import DNSUtils from ..server.ticket import BanTicket @@ -34,12 +36,14 @@ class AddFailure(unittest.TestCase): def setUp(self): """Call before every test case.""" super(AddFailure, self).setUp() + setUpMyTime() self.__ticket = BanTicket('193.168.0.128', 1167605999.0) self.__banManager = BanManager() def tearDown(self): """Call after every test case.""" super(AddFailure, self).tearDown() + tearDownMyTime() def testAdd(self): self.assertTrue(self.__banManager.addBanTicket(self.__ticket)) @@ -94,6 +98,25 @@ class AddFailure(unittest.TestCase): self.assertTrue(self.__banManager.addBanTicket(self.__ticket)) ticket = BanTicket('111.111.1.111', 1167605999.0) self.assertFalse(self.__banManager._inBanList(ticket)) + + def testBanTimeIncr(self): + ticket = BanTicket(self.__ticket.getIP(), self.__ticket.getTime()) + ## increase twice and at end permanent, check time/count increase: + c = 0 + for i in (1000, 2000, -1): + self.__banManager.addBanTicket(self.__ticket); c += 1 + ticket.setBanTime(i) + self.assertFalse(self.__banManager.addBanTicket(ticket)); # no incr of c (already banned) + self.assertEqual(str(self.__banManager.getTicketByID(ticket.getIP())), + "BanTicket: ip=%s time=%s bantime=%s bancount=%s #attempts=0 matches=[]" % (ticket.getIP(), ticket.getTime(), i, c)) + ## after permanent, it should remain permanent ban time (-1): + self.__banManager.addBanTicket(self.__ticket); c += 1 + ticket.setBanTime(-1) + self.assertFalse(self.__banManager.addBanTicket(ticket)); # no incr of c (already banned) + ticket.setBanTime(1000) + self.assertFalse(self.__banManager.addBanTicket(ticket)); # no incr of c (already banned) + self.assertEqual(str(self.__banManager.getTicketByID(ticket.getIP())), + "BanTicket: ip=%s time=%s bantime=%s bancount=%s #attempts=0 matches=[]" % (ticket.getIP(), ticket.getTime(), -1, c)) def testUnban(self): btime = self.__banManager.getBanTime() @@ -132,12 +155,28 @@ class AddFailure(unittest.TestCase): finally: self.__banManager.setBanTime(btime) + def testBanList(self): + tickets = [ + BanTicket('192.0.2.1', 1167605999.0), + BanTicket('192.0.2.2', 1167605999.0), + ] + tickets[1].setBanTime(-1) + for t in tickets: + self.__banManager.addBanTicket(t) + self.assertSortedEqual(self.__banManager.getBanList(ordered=True, withTime=True), + [ + '192.0.2.1 \t2006-12-31 23:59:59 + 600 = 2007-01-01 00:09:59', + '192.0.2.2 \t2006-12-31 23:59:59 + -1 = 9999-12-31 23:59:59' + ] + ) + class StatusExtendedCymruInfo(unittest.TestCase): def setUp(self): """Call before every test case.""" super(StatusExtendedCymruInfo, self).setUp() unittest.F2B.SkipIfNoNetwork() + setUpMyTime() self.__ban_ip = iter(DNSUtils.dnsToIp("resolver1.opendns.com")).next() self.__asn = "36692" self.__country = "US" @@ -149,6 +188,7 @@ class StatusExtendedCymruInfo(unittest.TestCase): def tearDown(self): """Call after every test case.""" super(StatusExtendedCymruInfo, self).tearDown() + tearDownMyTime() available = True, None diff --git a/fail2ban/tests/databasetestcase.py b/fail2ban/tests/databasetestcase.py index d06927b1..a8e2ceae 100644 --- a/fail2ban/tests/databasetestcase.py +++ b/fail2ban/tests/databasetestcase.py @@ -164,10 +164,47 @@ class DatabaseTest(LogCaptureTestCase): self.assertEqual(self.db.updateDb(Fail2BanDb.__version__), Fail2BanDb.__version__) self.assertRaises(NotImplementedError, self.db.updateDb, Fail2BanDb.__version__ + 1) + # check current bans (should find exactly 1 ticket after upgrade): + tickets = self.db.getCurrentBans(fromtime=1388009242, correctBanTime=123456) + self.assertEqual(len(tickets), 1) + self.assertEqual(tickets[0].getBanTime(), 123456); # ban-time was unknown (normally updated from jail) finally: if self.db and self.db._dbFilename != ":memory:": os.remove(self.db._dbBackupFilename) + def testUpdateDb2(self): + self.db = None + if self.dbFilename is None: # pragma: no cover + _, self.dbFilename = tempfile.mkstemp(".db", "fail2ban_") + shutil.copyfile( + os.path.join(TEST_FILES_DIR, 'database_v2.db'), self.dbFilename) + self.db = Fail2BanDb(self.dbFilename) + self.assertEqual(self.db.getJailNames(), set(['pam-generic'])) + self.assertEqual(self.db.getLogPaths(), set(['/var/log/auth.log'])) + bans = self.db.getBans() + self.assertEqual(len(bans), 2) + # compare first ticket completely: + ticket = FailTicket("1.2.3.7", 1417595494, [ + u'Dec 3 09:31:08 f2btest test:auth[27658]: pam_unix(test:auth): authentication failure; logname= uid=0 euid=0 tty=test ruser= rhost=1.2.3.7', + u'Dec 3 09:31:32 f2btest test:auth[27671]: pam_unix(test:auth): authentication failure; logname= uid=0 euid=0 tty=test ruser= rhost=1.2.3.7', + u'Dec 3 09:31:34 f2btest test:auth[27673]: pam_unix(test:auth): authentication failure; logname= uid=0 euid=0 tty=test ruser= rhost=1.2.3.7' + ]) + ticket.setAttempt(3) + self.assertEqual(bans[0], ticket) + # second ban found also: + self.assertEqual(bans[1].getIP(), "1.2.3.8") + # updated ? + self.assertEqual(self.db.updateDb(Fail2BanDb.__version__), Fail2BanDb.__version__) + # check current bans (should find 2 tickets after upgrade): + self.jail = DummyJail(name='pam-generic') + tickets = self.db.getCurrentBans(jail=self.jail, fromtime=1417595494) + self.assertEqual(len(tickets), 2) + self.assertEqual(tickets[0].getBanTime(), 600) + # further update should fail: + self.assertRaises(NotImplementedError, self.db.updateDb, Fail2BanDb.__version__ + 1) + # clean: + os.remove(self.db._dbBackupFilename) + def testAddJail(self): self.jail = DummyJail() self.db.addJail(self.jail) @@ -400,7 +437,7 @@ class DatabaseTest(LogCaptureTestCase): def testGetBansMerged(self): self.testAddJail() - jail2 = DummyJail() + jail2 = DummyJail(name='DummyJail-2') self.db.addJail(jail2) ticket = FailTicket("127.0.0.1", MyTime.time() - 40, ["abc\n"]) @@ -482,10 +519,25 @@ class DatabaseTest(LogCaptureTestCase): tickets = self.db.getCurrentBans(jail=self.jail, forbantime=15, fromtime=MyTime.time() + MyTime.str2seconds("1year")) self.assertEqual(len(tickets), 0) - # persistent bantime (-1), so never expired: + # persistent bantime (-1), so never expired (but no persistent tickets): tickets = self.db.getCurrentBans(jail=self.jail, forbantime=-1, fromtime=MyTime.time() + MyTime.str2seconds("1year")) - self.assertEqual(len(tickets), 2) + self.assertEqual(len(tickets), 0) + # add persistent one: + ticket.setBanTime(-1) + self.db.addBan(self.jail, ticket) + # persistent bantime (-1), so never expired (but jail has other max bantime now): + tickets = self.db.getCurrentBans(jail=self.jail, forbantime=-1, + fromtime=MyTime.time() + MyTime.str2seconds("1year")) + # no tickets should be found (max ban time = 600): + self.assertEqual(len(tickets), 0) + self.assertLogged("ignore ticket (with new max ban-time %r)" % self.jail.getMaxBanTime()) + # change jail to persistent ban and try again (1 persistent ticket): + self.jail.actions.setBanTime(-1) + tickets = self.db.getCurrentBans(jail=self.jail, forbantime=-1, + fromtime=MyTime.time() + MyTime.str2seconds("1year")) + self.assertEqual(len(tickets), 1) + self.assertEqual(tickets[0].getBanTime(), -1); # current jail ban time. def testActionWithDB(self): # test action together with database functionality @@ -497,8 +549,9 @@ class DatabaseTest(LogCaptureTestCase): "action_checkainfo", os.path.join(TEST_FILES_DIR, "action.d/action_checkainfo.py"), {}) - ticket = FailTicket("1.2.3.4", MyTime.time(), ['test', 'test']) + ticket = FailTicket("1.2.3.4") ticket.setAttempt(5) + ticket.setMatches(['test', 'test']) self.jail.putFailTicket(ticket) actions._Actions__checkBan() self.assertLogged("ban ainfo %s, %s, %s, %s" % (True, True, True, True)) diff --git a/fail2ban/tests/dummyjail.py b/fail2ban/tests/dummyjail.py index eaa4a564..fdeced8f 100644 --- a/fail2ban/tests/dummyjail.py +++ b/fail2ban/tests/dummyjail.py @@ -28,14 +28,19 @@ from ..server.jail import Jail from ..server.actions import Actions +class DummyActions(Actions): + def checkBan(self): + return self._Actions__checkBan() + + class DummyJail(Jail): """A simple 'jail' to suck in all the tickets generated by Filter's """ - def __init__(self, backend=None): + def __init__(self, name='DummyJail', backend=None): self.lock = Lock() self.queue = [] - super(DummyJail, self).__init__(name='DummyJail', backend=backend) - self.__actions = Actions(self) + super(DummyJail, self).__init__(name=name, backend=backend) + self.__actions = DummyActions(self) def __len__(self): with self.lock: @@ -65,10 +70,6 @@ class DummyJail(Jail): return False @property - def name(self): - return "DummyJail" + ("" if self.database else " #%s with %d tickets" % (id(self), len(self))) - - @property def idle(self): return False; diff --git a/fail2ban/tests/fail2banclienttestcase.py b/fail2ban/tests/fail2banclienttestcase.py index 54e6f722..d7213010 100644 --- a/fail2ban/tests/fail2banclienttestcase.py +++ b/fail2ban/tests/fail2banclienttestcase.py @@ -44,7 +44,7 @@ from ..server import server from ..server.mytime import MyTime from ..server.utils import Utils from .utils import LogCaptureTestCase, logSys as DefLogSys, with_tmpdir, shutil, logging, \ - STOCK, CONFIG_DIR as STOCK_CONF_DIR + STOCK, CONFIG_DIR as STOCK_CONF_DIR, TEST_NOW, tearDownMyTime from ..helpers import getLogger @@ -78,6 +78,35 @@ fail2banclient.output = \ fail2banserver.output = \ protocol.output = _test_output +def _time_shift(shift): + # jump to the future (+shift minutes): + logSys.debug("===>>> time shift + %s min", shift) + MyTime.setTime(MyTime.time() + shift*60) + + +Observers = server.Observers + +def _observer_wait_idle(): + """Helper to wait observer becomes idle""" + if Observers.Main is not None: + Observers.Main.wait_empty(MID_WAITTIME) + Observers.Main.wait_idle(MID_WAITTIME / 5) + +def _observer_wait_before_incrban(cond, timeout=MID_WAITTIME): + """Helper to block observer before increase bantime until some condition gets true""" + if Observers.Main is not None: + # switch ban handler: + _obs_banFound = Observers.Main.banFound + def _banFound(*args, **kwargs): + # restore original handler: + Observers.Main.banFound = _obs_banFound + # wait for: + logSys.debug(' [Observer::banFound] *** observer blocked for test') + Utils.wait_for(cond, timeout) + logSys.debug(' [Observer::banFound] +++ observer runs again') + # original banFound: + _obs_banFound(*args, **kwargs) + Observers.Main.banFound = _banFound # # Mocking .exit so we could test its correct operation. @@ -314,6 +343,7 @@ def with_foreground_server_thread(startextra={}): # to wait for end of server, default accept any exit code, because multi-threaded, # thus server can exit in-between... def _stopAndWaitForServerEnd(code=(SUCCESS, FAILED)): + tearDownMyTime() # if seems to be down - try to catch end phase (wait a bit for end:True to recognize down state): if not phase.get('end', None) and not os.path.exists(pjoin(tmp, "f2b.pid")): Utils.wait_for(lambda: phase.get('end', None) is not None, MID_WAITTIME) @@ -353,6 +383,7 @@ def with_foreground_server_thread(startextra={}): # so don't kill (same process) - if success, just wait for end of worker: if phase.get('end', None): th.join() + tearDownMyTime() return wrapper return _deco_wrapper @@ -379,6 +410,7 @@ class Fail2banClientServerBase(LogCaptureTestCase): server.DEF_LOGTARGET = SRV_DEF_LOGTARGET server.DEF_LOGLEVEL = SRV_DEF_LOGLEVEL LogCaptureTestCase.tearDown(self) + tearDownMyTime() @staticmethod def _test_exit(code=0): @@ -446,14 +478,14 @@ class Fail2banClientServerBase(LogCaptureTestCase): @with_foreground_server_thread(startextra={'f2b_local':( "[Thread]", - "stacksize = 32" + "stacksize = 128" "", )}) def testStartForeground(self, tmp, startparams): # check thread options were set: self.pruneLog() self.execCmd(SUCCESS, startparams, "get", "thread") - self.assertLogged("{'stacksize': 32}") + self.assertLogged("{'stacksize': 128}") # several commands to server: self.execCmd(SUCCESS, startparams, "ping") self.execCmd(FAILED, startparams, "~~unknown~cmd~failed~~") @@ -1041,6 +1073,8 @@ class Fail2banServerTest(Fail2banClientServerBase): "[test-jail2] Found 192.0.2.3", "[test-jail2] Ban 192.0.2.3", all=True) + # if observer available wait for it becomes idle (write all tickets to db): + _observer_wait_idle() # test banned command: self.assertSortedEqual(self.execCmdDirect(startparams, 'banned'), (0, [ @@ -1110,6 +1144,17 @@ class Fail2banServerTest(Fail2banClientServerBase): "stdout: '[test-jail2] test-action3: ++ ban 192.0.2.22", "stdout: '[test-jail2] test-action3: ++ ban 192.0.2.22 ", all=True, wait=MID_WAITTIME) + # get banned ips: + _observer_wait_idle() + self.pruneLog("[test-phase 2d.1]") + self.execCmd(SUCCESS, startparams, "get", "test-jail2", "banip", "\n") + self.assertLogged( + "192.0.2.4", "192.0.2.8", "192.0.2.21", "192.0.2.22", all=True, wait=MID_WAITTIME) + self.pruneLog("[test-phase 2d.2]") + self.execCmd(SUCCESS, startparams, "get", "test-jail1", "banip") + self.assertLogged( + "192.0.2.1", "192.0.2.2", "192.0.2.3", "192.0.2.4", "192.0.2.8", all=True, wait=MID_WAITTIME) + # restart jail with unban all: self.pruneLog("[test-phase 2e]") self.execCmd(SUCCESS, startparams, @@ -1327,7 +1372,7 @@ class Fail2banServerTest(Fail2banClientServerBase): 'failregex = ^ failure "<F-ID>[^"]+</F-ID>" - <ADDR>', 'maxretry = 1', # ban by first failure 'enabled = true', - ) + ) }) def testServerActions_NginxBlockMap(self, tmp, startparams): cfg = pjoin(tmp, "config") @@ -1504,6 +1549,152 @@ class Fail2banServerTest(Fail2banClientServerBase): # just to debug actionstop: self.assertFalse(exists(tofn)) + @with_foreground_server_thread() + def testServerObserver(self, tmp, startparams): + cfg = pjoin(tmp, "config") + test1log = pjoin(tmp, "test1.log") + + os.mkdir(pjoin(cfg, "action.d")) + def _write_action_cfg(actname="test-action1", prolong=True): + fn = pjoin(cfg, "action.d", "%s.conf" % actname) + _write_file(fn, "w", + "[DEFAULT]", + "", + "[Definition]", + "actionban = printf %%s \"[%(name)s] %(actname)s: ++ ban <ip> -c <bancount> -t <bantime> : <F-MSG>\"", \ + "actionprolong = printf %%s \"[%(name)s] %(actname)s: ++ prolong <ip> -c <bancount> -t <bantime> : <F-MSG>\"" \ + if prolong else "", + "actionunban = printf %%b '[%(name)s] %(actname)s: -- unban <ip>'", + ) + if unittest.F2B.log_level <= logging.DEBUG: # pragma: no cover + _out_file(fn) + + def _write_jail_cfg(backend="polling"): + _write_file(pjoin(cfg, "jail.conf"), "w", + "[INCLUDES]", "", + "[DEFAULT]", "", + "usedns = no", + "maxretry = 3", + "findtime = 1m", + "bantime = 5m", + "bantime.increment = true", + "datepattern = {^LN-BEG}EPOCH", + "", + "[test-jail1]", "backend = " + backend, "filter =", + "action = test-action1[name='%(__name__)s']", + " test-action2[name='%(__name__)s']", + "logpath = " + test1log, + r"failregex = ^\s*failure <F-ERRCODE>401|403</F-ERRCODE> from <HOST>:\s*<F-MSG>.*</F-MSG>$", + "enabled = true", + "", + ) + if unittest.F2B.log_level <= logging.DEBUG: # pragma: no cover + _out_file(pjoin(cfg, "jail.conf")) + + # create test config: + _write_action_cfg(actname="test-action1", prolong=False) + _write_action_cfg(actname="test-action2", prolong=True) + _write_jail_cfg() + + _write_file(test1log, "w") + # initial start: + self.pruneLog("[test-phase 0) time-0]") + self.execCmd(SUCCESS, startparams, "reload") + # generate bad ip: + _write_file(test1log, "w+", *( + (str(int(MyTime.time())) + " failure 401 from 192.0.2.11: I'm bad \"hacker\" `` $(echo test)",) * 3 + )) + # wait for ban: + _observer_wait_idle() + self.assertLogged( + "stdout: '[test-jail1] test-action1: ++ ban 192.0.2.11 -c 1 -t 300 : ", + "stdout: '[test-jail1] test-action2: ++ ban 192.0.2.11 -c 1 -t 300 : ", + all=True, wait=MID_WAITTIME) + # wait for observer idle (write all tickets to db): + _observer_wait_idle() + + self.pruneLog("[test-phase 1) time+10m]") + # jump to the future (+10 minutes): + _time_shift(10) + _observer_wait_idle() + self.assertLogged( + "stdout: '[test-jail1] test-action1: -- unban 192.0.2.11", + "stdout: '[test-jail1] test-action2: -- unban 192.0.2.11", + "0 ticket(s) in 'test-jail1'", + all=True, wait=MID_WAITTIME) + _observer_wait_idle() + + self.pruneLog("[test-phase 2) time+10m]") + # following tests are time-related - observer can prolong ticket (increase ban-time) + # before banning, so block it here before banFound called, prolong case later: + wakeObs = False + _observer_wait_before_incrban(lambda: wakeObs) + # write again (IP already bad): + _write_file(test1log, "w+", *( + (str(int(MyTime.time())) + " failure 401 from 192.0.2.11: I'm very bad \"hacker\" `` $(echo test)",) * 2 + )) + # wait for ban: + self.assertLogged( + "stdout: '[test-jail1] test-action1: ++ ban 192.0.2.11 -c 2 -t 300 : ", + "stdout: '[test-jail1] test-action2: ++ ban 192.0.2.11 -c 2 -t 300 : ", + all=True, wait=MID_WAITTIME) + # get banned ips with time: + self.pruneLog("[test-phase 2) time+10m - get-ips]") + self.execCmd(SUCCESS, startparams, "get", "test-jail1", "banip", "--with-time") + self.assertLogged( + "192.0.2.11", "+ 300 =", all=True, wait=MID_WAITTIME) + # unblock observer here and wait it is done: + wakeObs = True + _observer_wait_idle() + + self.pruneLog("[test-phase 2) time+11m]") + # jump to the future (+1 minute): + _time_shift(1) + # wait for observer idle (write all tickets to db): + _observer_wait_idle() + # wait for prolong: + self.assertLogged( + "stdout: '[test-jail1] test-action2: ++ prolong 192.0.2.11 -c 2 -t 600 : ", + all=True, wait=MID_WAITTIME) + + # get banned ips with time: + _observer_wait_idle() + self.pruneLog("[test-phase 2) time+11m - get-ips]") + self.execCmd(SUCCESS, startparams, "get", "test-jail1", "banip", "--with-time") + self.assertLogged( + "192.0.2.11", "+ 600 =", all=True, wait=MID_WAITTIME) + + # test stop with busy observer: + self.pruneLog("[test-phase end) stop on busy observer]") + tearDownMyTime() + a = {'state': 0} + obsMain = Observers.Main + def _long_action(): + logSys.info('++ observer enters busy state ...') + a['state'] = 1 + Utils.wait_for(lambda: a['state'] == 2, MAX_WAITTIME) + obsMain.db_purge(); # does nothing (db is already None) + logSys.info('-- observer leaves busy state.') + obsMain.add('call', _long_action) + obsMain.add('call', lambda: None) + # wait observer enter busy state: + Utils.wait_for(lambda: a['state'] == 1, MAX_WAITTIME) + # overwrite default wait time (normally 5 seconds): + obsMain_stop = obsMain.stop + def _stop(wtime=(0.01 if unittest.F2B.fast else 0.1), forceQuit=True): + return obsMain_stop(wtime, forceQuit) + obsMain.stop = _stop + # stop server and wait for end: + self.stopAndWaitForServerEnd(SUCCESS) + # check observer and db state: + self.assertNotLogged('observer leaves busy state') + self.assertFalse(obsMain.idle) + self.assertEqual(obsMain._ObserverThread__db, None) + # server is exited without wait for observer, stop it now: + a['state'] = 2 + self.assertLogged('observer leaves busy state', wait=True) + obsMain.join() + # test multiple start/stop of the server (threaded in foreground) -- if False: # pragma: no cover @with_foreground_server_thread() @@ -1514,3 +1705,4 @@ class Fail2banServerTest(Fail2banClientServerBase): def testServerStartStop(self): for i in xrange(2000): self._testServerStartStop() + diff --git a/fail2ban/tests/fail2banregextestcase.py b/fail2ban/tests/fail2banregextestcase.py index e6ef2707..db2d7562 100644 --- a/fail2ban/tests/fail2banregextestcase.py +++ b/fail2ban/tests/fail2banregextestcase.py @@ -355,6 +355,23 @@ class Fail2banRegexTest(LogCaptureTestCase): self.assertTrue(_test_exec('-o', 'id', STR_00, RE_00_ID)) self.assertLogged('kevin') self.pruneLog() + # multiple id combined to a tuple (id, tuple_id): + self.assertTrue(_test_exec('-o', 'id', + '1591983743.667 192.0.2.1 192.0.2.2', + r'^\s*<F-ID/> <F-TUPLE_ID>\S+</F-TUPLE_ID>')) + self.assertLogged(str(('192.0.2.1', '192.0.2.2'))) + self.pruneLog() + # multiple id combined to a tuple, id first - (id, tuple_id_1, tuple_id_2): + self.assertTrue(_test_exec('-o', 'id', + '1591983743.667 left 192.0.2.3 right', + r'^\s*<F-TUPLE_ID_1>\S+</F-TUPLE_ID_1> <F-ID/> <F-TUPLE_ID_2>\S+</F-TUPLE_ID_2>')) + self.pruneLog() + # id had higher precedence as ip-address: + self.assertTrue(_test_exec('-o', 'id', + '1591983743.667 left [192.0.2.4]:12345 right', + r'^\s*<F-TUPLE_ID_1>\S+</F-TUPLE_ID_1> <F-ID><ADDR>:<F-PORT/></F-ID> <F-TUPLE_ID_2>\S+</F-TUPLE_ID_2>')) + self.assertLogged(str(('[192.0.2.4]:12345', 'left', 'right'))) + self.pruneLog() # row with id : self.assertTrue(_test_exec('-o', 'row', STR_00, RE_00_ID)) self.assertLogged("['kevin'", "'ip4': '192.0.2.0'", "'fid': 'kevin'", all=True) diff --git a/fail2ban/tests/failmanagertestcase.py b/fail2ban/tests/failmanagertestcase.py index c3592407..a5425286 100644 --- a/fail2ban/tests/failmanagertestcase.py +++ b/fail2ban/tests/failmanagertestcase.py @@ -159,10 +159,10 @@ class AddFailure(unittest.TestCase): ticket_repr = repr(ticket) self.assertEqual( ticket_str, - 'FailTicket: ip=193.168.0.128 time=1167605999.0 #attempts=5 matches=[]') + 'FailTicket: ip=193.168.0.128 time=1167605999.0 bantime=None bancount=0 #attempts=5 matches=[]') self.assertEqual( ticket_repr, - 'FailTicket: ip=193.168.0.128 time=1167605999.0 #attempts=5 matches=[]') + 'FailTicket: ip=193.168.0.128 time=1167605999.0 bantime=None bancount=0 #attempts=5 matches=[]') self.assertFalse(not ticket) # and some get/set-ers otherwise not tested ticket.setTime(1000002000.0) @@ -170,7 +170,7 @@ class AddFailure(unittest.TestCase): # and str() adjusted correspondingly self.assertEqual( str(ticket), - 'FailTicket: ip=193.168.0.128 time=1000002000.0 #attempts=5 matches=[]') + 'FailTicket: ip=193.168.0.128 time=1000002000.0 bantime=None bancount=0 #attempts=5 matches=[]') def testbanNOK(self): self._addDefItems() diff --git a/fail2ban/tests/files/database_v1.db b/fail2ban/tests/files/database_v1.db Binary files differindex 20822671..fa2d7bb2 100644 --- a/fail2ban/tests/files/database_v1.db +++ b/fail2ban/tests/files/database_v1.db diff --git a/fail2ban/tests/files/database_v2.db b/fail2ban/tests/files/database_v2.db Binary files differnew file mode 100644 index 00000000..8954c8b5 --- /dev/null +++ b/fail2ban/tests/files/database_v2.db diff --git a/fail2ban/tests/filtertestcase.py b/fail2ban/tests/filtertestcase.py index a9641eee..a89b8364 100644 --- a/fail2ban/tests/filtertestcase.py +++ b/fail2ban/tests/filtertestcase.py @@ -92,7 +92,7 @@ class _tmSerial(): @staticmethod def _tm(time): # ## strftime it too slow for large time serializer : - # return datetime.datetime.fromtimestamp(time).strftime("%Y-%m-%d %H:%M:%S") + # return MyTime.time2str(time) c = _tmSerial sec = (time % 60) if c._last_s == time - sec: @@ -312,7 +312,7 @@ class BasicFilter(unittest.TestCase): unittest.F2B.SkipIfFast() ## test function "_tm" works correct (returns the same as slow strftime): for i in xrange(1417512352, (1417512352 // 3600 + 3) * 3600): - tm = datetime.datetime.fromtimestamp(i).strftime("%Y-%m-%d %H:%M:%S") + tm = MyTime.time2str(i) if _tm(i) != tm: # pragma: no cover - never reachable self.assertEqual((_tm(i), i), (tm, i)) diff --git a/fail2ban/tests/observertestcase.py b/fail2ban/tests/observertestcase.py new file mode 100644 index 00000000..e379ccd1 --- /dev/null +++ b/fail2ban/tests/observertestcase.py @@ -0,0 +1,627 @@ +# emacs: -*- mode: python; py-indent-offset: 4; indent-tabs-mode: t -*- +# vi: set ft=python sts=4 ts=4 sw=4 noet : + +# This file is part of Fail2Ban. +# +# Fail2Ban is free software; you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation; either version 2 of the License, or +# (at your option) any later version. +# +# Fail2Ban is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with Fail2Ban; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. + +# Author: Serg G. Brester (sebres) +# + +__author__ = "Serg G. Brester (sebres)" +__copyright__ = "Copyright (c) 2014 Serg G. Brester" +__license__ = "GPL" + +import os +import sys +import unittest +import tempfile +import time + +from ..server.mytime import MyTime +from ..server.ticket import FailTicket, BanTicket +from ..server.failmanager import FailManager +from ..server.observer import Observers, ObserverThread +from ..server.utils import Utils +from .utils import LogCaptureTestCase +from .dummyjail import DummyJail + +from .databasetestcase import getFail2BanDb, Fail2BanDb + + +class BanTimeIncr(LogCaptureTestCase): + + def setUp(self): + """Call before every test case.""" + super(BanTimeIncr, self).setUp() + self.__jail = DummyJail() + self.__jail.calcBanTime = self.calcBanTime + self.Observer = ObserverThread() + + def tearDown(self): + super(BanTimeIncr, self).tearDown() + + def calcBanTime(self, banTime, banCount): + return self.Observer.calcBanTime(self.__jail, banTime, banCount) + + def testDefault(self, multipliers = None): + a = self.__jail; + a.setBanTimeExtra('increment', 'true') + self.assertEqual(a.getBanTimeExtra('increment'), True) + a.setBanTimeExtra('maxtime', '1d') + self.assertEqual(a.getBanTimeExtra('maxtime'), 24*60*60) + a.setBanTimeExtra('rndtime', None) + a.setBanTimeExtra('factor', None) + # tests formulat or multipliers: + a.setBanTimeExtra('multipliers', multipliers) + # test algorithm and max time 24 hours : + self.assertEqual( + [a.calcBanTime(600, i) for i in xrange(1, 11)], + [1200, 2400, 4800, 9600, 19200, 38400, 76800, 86400, 86400, 86400] + ) + # with extra large max time (30 days): + a.setBanTimeExtra('maxtime', '30d') + # using formula the ban time grows always, but using multipliers the growing will stops with last one: + arr = [1200, 2400, 4800, 9600, 19200, 38400, 76800, 153600, 307200, 614400] + if multipliers is not None: + multcnt = len(multipliers.split(' ')) + if multcnt < 11: + arr = arr[0:multcnt-1] + ([arr[multcnt-2]] * (11-multcnt)) + self.assertEqual( + [a.calcBanTime(600, i) for i in xrange(1, 11)], + arr + ) + a.setBanTimeExtra('maxtime', '1d') + # change factor : + a.setBanTimeExtra('factor', '2'); + self.assertEqual( + [a.calcBanTime(600, i) for i in xrange(1, 11)], + [2400, 4800, 9600, 19200, 38400, 76800, 86400, 86400, 86400, 86400] + ) + # factor is float : + a.setBanTimeExtra('factor', '1.33'); + self.assertEqual( + [int(a.calcBanTime(600, i)) for i in xrange(1, 11)], + [1596, 3192, 6384, 12768, 25536, 51072, 86400, 86400, 86400, 86400] + ) + a.setBanTimeExtra('factor', None); + # change max time : + a.setBanTimeExtra('maxtime', '12h') + self.assertEqual( + [a.calcBanTime(600, i) for i in xrange(1, 11)], + [1200, 2400, 4800, 9600, 19200, 38400, 43200, 43200, 43200, 43200] + ) + a.setBanTimeExtra('maxtime', '24h') + ## test randomization - not possibe all 10 times we have random = 0: + a.setBanTimeExtra('rndtime', '5m') + self.assertTrue( + False in [1200 in [a.calcBanTime(600, 1) for i in xrange(10)] for c in xrange(10)] + ) + a.setBanTimeExtra('rndtime', None) + self.assertFalse( + False in [1200 in [a.calcBanTime(600, 1) for i in xrange(10)] for c in xrange(10)] + ) + # restore default: + a.setBanTimeExtra('multipliers', None) + a.setBanTimeExtra('factor', None); + a.setBanTimeExtra('maxtime', '24h') + a.setBanTimeExtra('rndtime', None) + + def testMultipliers(self): + # this multipliers has the same values as default formula, we test stop growing after count 9: + self.testDefault('1 2 4 8 16 32 64 128 256') + # this multipliers has exactly the same values as default formula, test endless growing (stops by count 31 only): + self.testDefault(' '.join([str(1<<i) for i in xrange(31)])) + + def testFormula(self): + a = self.__jail; + a.setBanTimeExtra('maxtime', '24h') + a.setBanTimeExtra('rndtime', None) + ## use another formula: + a.setBanTimeExtra('formula', 'ban.Time * math.exp(float(ban.Count+1)*banFactor)/math.exp(1*banFactor)') + a.setBanTimeExtra('factor', '2.0 / 2.885385') + a.setBanTimeExtra('multipliers', None) + # test algorithm and max time 24 hours : + self.assertEqual( + [int(a.calcBanTime(600, i)) for i in xrange(1, 11)], + [1200, 2400, 4800, 9600, 19200, 38400, 76800, 86400, 86400, 86400] + ) + # with extra large max time (30 days): + a.setBanTimeExtra('maxtime', '30d') + self.assertEqual( + [int(a.calcBanTime(600, i)) for i in xrange(1, 11)], + [1200, 2400, 4800, 9600, 19200, 38400, 76800, 153601, 307203, 614407] + ) + a.setBanTimeExtra('maxtime', '24h') + # change factor : + a.setBanTimeExtra('factor', '1'); + self.assertEqual( + [int(a.calcBanTime(600, i)) for i in xrange(1, 11)], + [1630, 4433, 12051, 32758, 86400, 86400, 86400, 86400, 86400, 86400] + ) + a.setBanTimeExtra('factor', '2.0 / 2.885385') + # change max time : + a.setBanTimeExtra('maxtime', '12h') + self.assertEqual( + [int(a.calcBanTime(600, i)) for i in xrange(1, 11)], + [1200, 2400, 4800, 9600, 19200, 38400, 43200, 43200, 43200, 43200] + ) + a.setBanTimeExtra('maxtime', '24h') + ## test randomization - not possibe all 10 times we have random = 0: + a.setBanTimeExtra('rndtime', '5m') + self.assertTrue( + False in [1200 in [int(a.calcBanTime(600, 1)) for i in xrange(10)] for c in xrange(10)] + ) + a.setBanTimeExtra('rndtime', None) + self.assertFalse( + False in [1200 in [int(a.calcBanTime(600, 1)) for i in xrange(10)] for c in xrange(10)] + ) + # restore default: + a.setBanTimeExtra('factor', None); + a.setBanTimeExtra('multipliers', None) + a.setBanTimeExtra('factor', None); + a.setBanTimeExtra('maxtime', '24h') + a.setBanTimeExtra('rndtime', None) + + +class BanTimeIncrDB(LogCaptureTestCase): + + def setUp(self): + """Call before every test case.""" + super(BanTimeIncrDB, self).setUp() + if Fail2BanDb is None and sys.version_info >= (2,7): # pragma: no cover + raise unittest.SkipTest( + "Unable to import fail2ban database module as sqlite is not " + "available.") + elif Fail2BanDb is None: + return + _, self.dbFilename = tempfile.mkstemp(".db", "fail2ban_") + self.db = getFail2BanDb(self.dbFilename) + self.jail = DummyJail() + self.jail.database = self.db + self.Observer = ObserverThread() + Observers.Main = self.Observer + + def tearDown(self): + """Call after every test case.""" + if Fail2BanDb is None: # pragma: no cover + return + # Cleanup + self.Observer.stop() + Observers.Main = None + os.remove(self.dbFilename) + super(BanTimeIncrDB, self).tearDown() + + def incrBanTime(self, ticket, banTime=None): + jail = self.jail; + if banTime is None: + banTime = ticket.getBanTime(jail.actions.getBanTime()) + ticket.setBanTime(None) + incrTime = self.Observer.incrBanTime(jail, banTime, ticket) + #print("!!!!!!!!! banTime: %s, %s, incr: %s " % (banTime, ticket.getBanCount(), incrTime)) + return incrTime + + + def testBanTimeIncr(self): + if Fail2BanDb is None: # pragma: no cover + return + jail = self.jail + self.db.addJail(jail) + # we tests with initial ban time = 10 seconds: + jail.actions.setBanTime(10) + jail.setBanTimeExtra('increment', 'true') + jail.setBanTimeExtra('multipliers', '1 2 4 8 16 32 64 128 256 512 1024 2048') + ip = "192.0.2.1" + # used as start and fromtime (like now but time independence, cause test case can run slow): + stime = int(MyTime.time()) + ticket = FailTicket(ip, stime, []) + # test ticket not yet found + self.assertEqual( + [self.incrBanTime(ticket, 10) for i in xrange(3)], + [10, 10, 10] + ) + # add a ticket banned + ticket.incrBanCount() + self.db.addBan(jail, ticket) + # get a ticket already banned in this jail: + self.assertEqual( + [(banCount, timeOfBan, lastBanTime) for banCount, timeOfBan, lastBanTime in self.db.getBan(ip, jail, None, False)], + [(1, stime, 10)] + ) + # incr time and ban a ticket again : + ticket.setTime(stime + 15) + self.assertEqual(self.incrBanTime(ticket, 10), 20) + self.db.addBan(jail, ticket) + # get a ticket already banned in this jail: + self.assertEqual( + [(banCount, timeOfBan, lastBanTime) for banCount, timeOfBan, lastBanTime in self.db.getBan(ip, jail, None, False)], + [(2, stime + 15, 20)] + ) + # get a ticket already banned in all jails: + self.assertEqual( + [(banCount, timeOfBan, lastBanTime) for banCount, timeOfBan, lastBanTime in self.db.getBan(ip, '', None, True)], + [(2, stime + 15, 20)] + ) + # check other optional parameters of getBan: + self.assertEqual( + [(banCount, timeOfBan, lastBanTime) for banCount, timeOfBan, lastBanTime in self.db.getBan(ip, forbantime=stime, fromtime=stime)], + [(2, stime + 15, 20)] + ) + # search currently banned and 1 day later (nothing should be found): + self.assertEqual( + self.db.getCurrentBans(forbantime=-24*60*60, fromtime=stime, correctBanTime=False), + [] + ) + # search currently banned one ticket for ip: + restored_tickets = self.db.getCurrentBans(ip=ip, correctBanTime=False) + self.assertEqual( + str(restored_tickets), + ('FailTicket: ip=%s time=%s bantime=20 bancount=2 #attempts=0 matches=[]' % (ip, stime + 15)) + ) + # search currently banned anywhere: + restored_tickets = self.db.getCurrentBans(fromtime=stime, correctBanTime=False) + self.assertEqual( + str(restored_tickets), + ('[FailTicket: ip=%s time=%s bantime=20 bancount=2 #attempts=0 matches=[]]' % (ip, stime + 15)) + ) + # search currently banned: + restored_tickets = self.db.getCurrentBans(jail=jail, fromtime=stime, correctBanTime=False) + self.assertEqual( + str(restored_tickets), + ('[FailTicket: ip=%s time=%s bantime=20 bancount=2 #attempts=0 matches=[]]' % (ip, stime + 15)) + ) + # increase ban multiple times: + lastBanTime = 20 + for i in xrange(10): + ticket.setTime(stime + lastBanTime + 5) + banTime = self.incrBanTime(ticket, 10) + self.assertEqual(banTime, lastBanTime * 2) + self.db.addBan(jail, ticket) + lastBanTime = banTime + # increase again, but the last multiplier reached (time not increased): + ticket.setTime(stime + lastBanTime + 5) + banTime = self.incrBanTime(ticket, 10) + self.assertNotEqual(banTime, lastBanTime * 2) + self.assertEqual(banTime, lastBanTime) + self.db.addBan(jail, ticket) + lastBanTime = banTime + # add two tickets from yesterday: one unbanned (bantime already out-dated): + ticket2 = FailTicket(ip+'2', stime-24*60*60, []) + ticket2.setBanTime(12*60*60) + ticket2.incrBanCount() + self.db.addBan(jail, ticket2) + # and one from yesterday also, but still currently banned : + ticket2 = FailTicket(ip+'1', stime-24*60*60, []) + ticket2.setBanTime(36*60*60) + ticket2.incrBanCount() + self.db.addBan(jail, ticket2) + # search currently banned: + restored_tickets = self.db.getCurrentBans(fromtime=stime, correctBanTime=False) + self.assertEqual(len(restored_tickets), 2) + self.assertEqual( + str(restored_tickets[0]), + 'FailTicket: ip=%s time=%s bantime=%s bancount=13 #attempts=0 matches=[]' % (ip, stime + lastBanTime + 5, lastBanTime) + ) + self.assertEqual( + str(restored_tickets[1]), + 'FailTicket: ip=%s time=%s bantime=%s bancount=1 #attempts=0 matches=[]' % (ip+'1', stime-24*60*60, 36*60*60) + ) + # search out-dated (give another fromtime now is -18 hours): + restored_tickets = self.db.getCurrentBans(fromtime=stime-18*60*60, correctBanTime=False) + self.assertEqual(len(restored_tickets), 3) + self.assertEqual( + str(restored_tickets[2]), + 'FailTicket: ip=%s time=%s bantime=%s bancount=1 #attempts=0 matches=[]' % (ip+'2', stime-24*60*60, 12*60*60) + ) + # should be still banned + self.assertFalse(restored_tickets[1].isTimedOut(stime)) + self.assertFalse(restored_tickets[1].isTimedOut(stime)) + # the last should be timed out now + self.assertTrue(restored_tickets[2].isTimedOut(stime)) + self.assertFalse(restored_tickets[2].isTimedOut(stime-18*60*60)) + + # test permanent, create timed out: + ticket=FailTicket(ip+'3', stime-36*60*60, []) + self.assertTrue(ticket.isTimedOut(stime, 600)) + # not timed out - permanent jail: + self.assertFalse(ticket.isTimedOut(stime, -1)) + # not timed out - permanent ticket: + ticket.setBanTime(-1) + self.assertFalse(ticket.isTimedOut(stime, 600)) + self.assertFalse(ticket.isTimedOut(stime, -1)) + # timed out - permanent jail but ticket time (not really used behavior) + ticket.setBanTime(600) + self.assertTrue(ticket.isTimedOut(stime, -1)) + + # get currently banned pis with permanent one: + ticket.setBanTime(-1) + ticket.incrBanCount() + self.db.addBan(jail, ticket) + restored_tickets = self.db.getCurrentBans(fromtime=stime, correctBanTime=False) + self.assertEqual(len(restored_tickets), 3) + self.assertEqual( + str(restored_tickets[2]), + 'FailTicket: ip=%s time=%s bantime=%s bancount=1 #attempts=0 matches=[]' % (ip+'3', stime-36*60*60, -1) + ) + # purge (nothing should be changed): + self.db.purge() + restored_tickets = self.db.getCurrentBans(fromtime=stime, correctBanTime=False) + self.assertEqual(len(restored_tickets), 3) + # set short time and purge again: + ticket.setBanTime(600) + ticket.incrBanCount() + self.db.addBan(jail, ticket) + self.db.purge() + # this old ticket should be removed now: + restored_tickets = self.db.getCurrentBans(fromtime=stime, correctBanTime=False) + self.assertEqual(len(restored_tickets), 2) + self.assertEqual(restored_tickets[0].getIP(), ip) + + # purge remove 1st ip + self.db._purgeAge = -48*60*60 + self.db.purge() + restored_tickets = self.db.getCurrentBans(fromtime=stime, correctBanTime=False) + self.assertEqual(len(restored_tickets), 1) + self.assertEqual(restored_tickets[0].getIP(), ip+'1') + + # this should purge all bans, bips and logs - nothing should be found now + self.db._purgeAge = -240*60*60 + self.db.purge() + restored_tickets = self.db.getCurrentBans(fromtime=stime, correctBanTime=False) + self.assertEqual(restored_tickets, []) + + # two separate jails : + jail1 = DummyJail(backend='polling') + jail1.filter.ignoreSelf = False + jail1.setBanTimeExtra('increment', 'true') + jail1.database = self.db + self.db.addJail(jail1) + jail2 = DummyJail(name='DummyJail-2', backend='polling') + jail2.filter.ignoreSelf = False + jail2.database = self.db + self.db.addJail(jail2) + ticket1 = FailTicket(ip, stime, []) + ticket1.setBanTime(6000) + ticket1.incrBanCount() + self.db.addBan(jail1, ticket1) + ticket2 = FailTicket(ip, stime-6000, []) + ticket2.setBanTime(12000) + ticket2.setBanCount(1) + ticket2.incrBanCount() + self.db.addBan(jail2, ticket2) + restored_tickets = self.db.getCurrentBans(jail=jail1, fromtime=stime, correctBanTime=False) + self.assertEqual(len(restored_tickets), 1) + self.assertEqual( + str(restored_tickets[0]), + 'FailTicket: ip=%s time=%s bantime=%s bancount=1 #attempts=0 matches=[]' % (ip, stime, 6000) + ) + restored_tickets = self.db.getCurrentBans(jail=jail2, fromtime=stime, correctBanTime=False) + self.assertEqual(len(restored_tickets), 1) + self.assertEqual( + str(restored_tickets[0]), + 'FailTicket: ip=%s time=%s bantime=%s bancount=2 #attempts=0 matches=[]' % (ip, stime-6000, 12000) + ) + # get last ban values for this ip separately for each jail: + for row in self.db.getBan(ip, jail1): + self.assertEqual(row, (1, stime, 6000)) + break + for row in self.db.getBan(ip, jail2): + self.assertEqual(row, (2, stime-6000, 12000)) + break + # get max values for this ip (over all jails): + for row in self.db.getBan(ip, overalljails=True): + self.assertEqual(row, (3, stime, 18000)) + break + # test restoring bans from database: + jail1.restoreCurrentBans(correctBanTime=False) + ticket = jail1.getFailTicket() + self.assertTrue(ticket.restored) + self.assertEqual(str(ticket), + 'FailTicket: ip=%s time=%s bantime=%s bancount=1 #attempts=0 matches=[]' % (ip, stime, 6000) + ) + # jail2 does not restore any bans (because all ban tickets should be already expired: stime-6000): + jail2.restoreCurrentBans(correctBanTime=False) + self.assertEqual(jail2.getFailTicket(), False) + # test again, but now normally (with maximum ban-time of restored ticket = allowed 10m = 600): + jail1.setBanTimeExtra('maxtime', '10m') + jail1.restoreCurrentBans() + ticket = jail1.getFailTicket() + self.assertTrue(ticket.restored) + # ticket restored, but it has new time = 600 (current ban-time of jail, as maximum): + self.assertEqual(str(ticket), + 'FailTicket: ip=%s time=%s bantime=%s bancount=1 #attempts=0 matches=[]' % (ip, stime, 600) + ) + # jail2 does not restore any bans (because all ban tickets should be already expired: stime-6000): + jail2.restoreCurrentBans() + self.assertEqual(jail2.getFailTicket(), False) + + def testObserver(self): + if Fail2BanDb is None: # pragma: no cover + return + jail = self.jail + self.db.addJail(jail) + # we tests with initial ban time = 10 seconds: + jail.actions.setBanTime(10) + jail.setBanTimeExtra('increment', 'true') + # observer / database features: + obs = Observers.Main + obs.start() + obs.db_set(self.db) + # wait for start ready + obs.add('nop') + obs.wait_empty(5) + # purge database right now, but using timer, to test it also: + self.db._purgeAge = -240*60*60 + obs.add_named_timer('DB_PURGE', 0.001, 'db_purge') + self.assertLogged("Purge database event occurred", wait=True); # wait for purge timer + # wait for timer ready + obs.wait_idle(0.025) + # wait for ready + obs.add('nop') + obs.wait_empty(5) + + stime = int(MyTime.time()) + # completelly empty ? + tickets = self.db.getBans() + self.assertEqual(tickets, []) + + # add failure: + ip = "192.0.2.1" + ticket = FailTicket(ip, stime-120, []) + failManager = FailManager() + failManager.setMaxRetry(3) + for i in xrange(3): + failManager.addFailure(ticket) + obs.add('failureFound', failManager, jail, ticket) + obs.wait_empty(5) + self.assertEqual(ticket.getBanCount(), 0) + # check still not ban : + self.assertTrue(not jail.getFailTicket()) + # add manually 4th times banned (added to bips - make ip bad): + ticket.setBanCount(4) + self.db.addBan(self.jail, ticket) + restored_tickets = self.db.getCurrentBans(jail=jail, fromtime=stime-120, correctBanTime=False) + self.assertEqual(len(restored_tickets), 1) + # check again, new ticket, new failmanager: + ticket = FailTicket(ip, stime, []) + failManager = FailManager() + failManager.setMaxRetry(3) + # add once only - but bad - should be banned: + failManager.addFailure(ticket) + obs.add('failureFound', failManager, self.jail, ticket) + obs.wait_empty(5) + # wait until ticket transfered from failmanager into jail: + ticket2 = Utils.wait_for(jail.getFailTicket, 10) + # check ticket and failure count: + self.assertTrue(ticket2) + self.assertEqual(ticket2.getRetry(), failManager.getMaxRetry()) + + # wrap FailTicket to BanTicket: + failticket2 = ticket2 + ticket2 = BanTicket.wrap(failticket2) + self.assertEqual(ticket2, failticket2) + # add this ticket to ban (use observer only without ban manager): + obs.add('banFound', ticket2, jail, 10) + obs.wait_empty(5) + # increased? + self.assertEqual(ticket2.getBanTime(), 160) + self.assertEqual(ticket2.getBanCount(), 5) + + # check prolonged in database also : + restored_tickets = self.db.getCurrentBans(jail=jail, fromtime=stime, correctBanTime=False) + self.assertEqual(len(restored_tickets), 1) + self.assertEqual(restored_tickets[0].getBanTime(), 160) + self.assertEqual(restored_tickets[0].getBanCount(), 5) + + # now using jail/actions: + ticket = FailTicket(ip, stime-60, ['test-expired-ban-time']) + jail.putFailTicket(ticket) + self.assertFalse(jail.actions.checkBan()) + + ticket = FailTicket(ip, MyTime.time(), ['test-actions']) + jail.putFailTicket(ticket) + self.assertTrue(jail.actions.checkBan()) + + obs.wait_empty(5) + restored_tickets = self.db.getCurrentBans(jail=jail, fromtime=stime, correctBanTime=False) + self.assertEqual(len(restored_tickets), 1) + self.assertEqual(restored_tickets[0].getBanTime(), 320) + self.assertEqual(restored_tickets[0].getBanCount(), 6) + + # and permanent: + ticket = FailTicket(ip+'1', MyTime.time(), ['test-permanent']) + ticket.setBanTime(-1) + jail.putFailTicket(ticket) + self.assertTrue(jail.actions.checkBan()) + + obs.wait_empty(5) + ticket = FailTicket(ip+'1', MyTime.time(), ['test-permanent']) + ticket.setBanTime(600) + jail.putFailTicket(ticket) + self.assertFalse(jail.actions.checkBan()) + + obs.wait_empty(5) + restored_tickets = self.db.getCurrentBans(jail=jail, fromtime=stime, correctBanTime=False) + self.assertEqual(len(restored_tickets), 2) + self.assertEqual(restored_tickets[1].getBanTime(), -1) + self.assertEqual(restored_tickets[1].getBanCount(), 1) + + # stop observer + obs.stop() + +class ObserverTest(LogCaptureTestCase): + + def setUp(self): + """Call before every test case.""" + super(ObserverTest, self).setUp() + + def tearDown(self): + """Call after every test case.""" + super(ObserverTest, self).tearDown() + + def testObserverBanTimeIncr(self): + obs = ObserverThread() + obs.start() + # wait for idle + obs.wait_idle(1) + # observer will replace test set: + o = set(['test']) + obs.add('call', o.clear) + obs.add('call', o.add, 'test2') + # wait for observer ready: + obs.wait_empty(1) + self.assertFalse(obs.is_full) + self.assertEqual(o, set(['test2'])) + # observer makes pause + obs.paused = True + # observer will replace test set, but first after pause ends: + obs.add('call', o.clear) + obs.add('call', o.add, 'test3') + obs.wait_empty(10 * Utils.DEFAULT_SLEEP_TIME) + self.assertTrue(obs.is_full) + self.assertEqual(o, set(['test2'])) + obs.paused = False + # wait running: + obs.wait_empty(1) + self.assertEqual(o, set(['test3'])) + + self.assertTrue(obs.isActive()) + self.assertTrue(obs.isAlive()) + obs.stop() + obs = None + + class _BadObserver(ObserverThread): + def run(self): + raise RuntimeError('run bad thread exception') + + def testObserverBadRun(self): + obs = ObserverTest._BadObserver() + # don't wait for empty by stop + obs.wait_empty = lambda v:() + # save previous hook, prevent write stderr and check hereafter __excepthook__ was executed + prev_exchook = sys.__excepthook__ + x = [] + sys.__excepthook__ = lambda *args: x.append(args) + try: + obs.start() + obs.stop() + obs.join() + self.assertTrue( Utils.wait_for( lambda: len(x) and self._is_logged("Unhandled exception"), 3) ) + finally: + sys.__excepthook__ = prev_exchook + self.assertLogged("Unhandled exception") + self.assertEqual(len(x), 1) + self.assertEqual(x[0][0], RuntimeError) + self.assertEqual(str(x[0][1]), 'run bad thread exception') diff --git a/fail2ban/tests/servertestcase.py b/fail2ban/tests/servertestcase.py index 6cf45f53..7a0685eb 100644 --- a/fail2ban/tests/servertestcase.py +++ b/fail2ban/tests/servertestcase.py @@ -41,7 +41,7 @@ from ..server.jailthread import JailThread from ..server.ticket import BanTicket from ..server.utils import Utils from .dummyjail import DummyJail -from .utils import LogCaptureTestCase +from .utils import LogCaptureTestCase, with_alt_time, MyTime from ..helpers import getLogger, extractOptions, PREFER_ENC from .. import version @@ -394,6 +394,50 @@ class Transmitter(TransmitterBase): self.assertLogged("Ban 192.0.2.2", wait=True) self.assertNotLogged("Ban 192.0.2.1") + @with_alt_time + def testJailBanList(self): + jail = "TestJailBanList" + self.server.addJail(jail, FAST_BACKEND) + self.server.startJail(jail) + + # Helper to process set banip/set unbanip commands and compare the list of + # banned IP addresses with outList. + def _getBanListTest(jail, banip=None, unbanip=None, args=(), outList=[]): + # Ban IP address + if banip is not None: + self.assertEqual( + self.transm.proceed(["set", jail, "banip", banip]), + (0, 1)) + self.assertLogged("Ban %s" % banip, wait=True) # Give chance to ban + # Unban IP address + if unbanip is not None: + self.assertEqual( + self.transm.proceed(["set", jail, "unbanip", unbanip]), + (0, 1)) + self.assertLogged("Unban %s" % unbanip, wait=True) # Give chance to unban + # Compare the list of banned IP addresses with outList + self.assertSortedEqual( + self.transm.proceed(["get", jail, "banip"]+list(args)), + (0, outList), nestedOnly=False) + MyTime.setTime(MyTime.time() + 1) + + _getBanListTest(jail, + outList=[]) + _getBanListTest(jail, banip="127.0.0.1", args=('--with-time',), + outList=["127.0.0.1 \t2005-08-14 12:00:01 + 600 = 2005-08-14 12:10:01"]) + _getBanListTest(jail, banip="192.168.0.1", args=('--with-time',), + outList=[ + "127.0.0.1 \t2005-08-14 12:00:01 + 600 = 2005-08-14 12:10:01", + "192.168.0.1 \t2005-08-14 12:00:02 + 600 = 2005-08-14 12:10:02"]) + _getBanListTest(jail, banip="192.168.1.10", + outList=["127.0.0.1", "192.168.0.1", "192.168.1.10"]) + _getBanListTest(jail, unbanip="127.0.0.1", + outList=["192.168.0.1", "192.168.1.10"]) + _getBanListTest(jail, unbanip="192.168.1.10", + outList=["192.168.0.1"]) + _getBanListTest(jail, unbanip="192.168.0.1", + outList=[]) + def testJailMaxMatches(self): self.setGetTest("maxmatches", "5", 5, jail=self.jailName) self.setGetTest("maxmatches", "2", 2, jail=self.jailName) @@ -1006,6 +1050,15 @@ class TransmitterLogging(TransmitterBase): self.assertEqual(self.transm.proceed(["set", "logtarget", "STDERR"]), (0, "STDERR")) self.assertEqual(self.transm.proceed(["flushlogs"]), (0, "flushed")) + def testBanTimeIncr(self): + self.setGetTest("bantime.increment", "true", True, jail=self.jailName) + self.setGetTest("bantime.rndtime", "30min", 30*60, jail=self.jailName) + self.setGetTest("bantime.maxtime", "1000 days", 1000*24*60*60, jail=self.jailName) + self.setGetTest("bantime.factor", "2", "2", jail=self.jailName) + self.setGetTest("bantime.formula", "ban.Time * math.exp(float(ban.Count+1)*banFactor)/math.exp(1*banFactor)", jail=self.jailName) + self.setGetTest("bantime.multipliers", "1 5 30 60 300 720 1440 2880", "1 5 30 60 300 720 1440 2880", jail=self.jailName) + self.setGetTest("bantime.overalljails", "true", "true", jail=self.jailName) + class JailTests(unittest.TestCase): @@ -1173,8 +1226,20 @@ class ServerConfigReaderTests(LogCaptureTestCase): logSys.debug(l) return True + def _testActionInfos(self): + if not hasattr(self, '__aInfos'): + dmyjail = DummyJail() + self.__aInfos = {} + for t, ip in (('ipv4', '192.0.2.1'), ('ipv6', '2001:DB8::')): + ticket = BanTicket(ip) + ticket.setBanTime(600) + self.__aInfos[t] = _actions.Actions.ActionInfo(ticket, dmyjail) + return self.__aInfos + def _testExecActions(self, server): jails = server._Server__jails + + aInfos = self._testActionInfos() for jail in jails: # print(jail, jails[jail]) for a in jails[jail].actions: @@ -1191,16 +1256,16 @@ class ServerConfigReaderTests(LogCaptureTestCase): action.start() # test ban ip4 : logSys.debug('# === ban-ipv4 ==='); self.pruneLog() - action.ban({'ip': IPAddr('192.0.2.1'), 'family': 'inet4'}) + action.ban(aInfos['ipv4']) # test unban ip4 : logSys.debug('# === unban ipv4 ==='); self.pruneLog() - action.unban({'ip': IPAddr('192.0.2.1'), 'family': 'inet4'}) + action.unban(aInfos['ipv4']) # test ban ip6 : logSys.debug('# === ban ipv6 ==='); self.pruneLog() - action.ban({'ip': IPAddr('2001:DB8::'), 'family': 'inet6'}) + action.ban(aInfos['ipv6']) # test unban ip6 : logSys.debug('# === unban ipv6 ==='); self.pruneLog() - action.unban({'ip': IPAddr('2001:DB8::'), 'family': 'inet6'}) + action.unban(aInfos['ipv6']) # test stop : logSys.debug('# === stop ==='); self.pruneLog() action.stop() @@ -1396,9 +1461,10 @@ class ServerConfigReaderTests(LogCaptureTestCase): ), }), # dummy -- - ('j-dummy', 'dummy[name=%(__name__)s, init="==", target="/tmp/fail2ban.dummy"]', { + ('j-dummy', '''dummy[name=%(__name__)s, init="=='<family>/<ip>'==bt:<bantime>==bc:<bancount>==", target="/tmp/fail2ban.dummy"]''', { 'ip4': ('family: inet4',), 'ip6': ('family: inet6',), 'start': ( + '''`printf %b "=='/'==bt:600==bc:0==\\n"''', ## empty family (independent in this action, same for both), no ip on start, initial bantime and bancount '`echo "[j-dummy] dummy /tmp/fail2ban.dummy -- started"`', ), 'flush': ( @@ -1990,10 +2056,7 @@ class ServerConfigReaderTests(LogCaptureTestCase): jails = server._Server__jails - tickets = { - 'ip4': BanTicket('192.0.2.1'), - 'ip6': BanTicket('2001:DB8::'), - } + aInfos = self._testActionInfos() for jail, act, tests in testJailsActions: # print(jail, jails[jail]) for a in jails[jail].actions: @@ -2011,32 +2074,28 @@ class ServerConfigReaderTests(LogCaptureTestCase): self.assertLogged(*tests['start'], all=True) elif tests.get('ip4-start') and tests.get('ip6-start'): self.assertNotLogged(*tests['ip4-start']+tests['ip6-start'], all=True) - ainfo = { - 'ip4': _actions.Actions.ActionInfo(tickets['ip4'], jails[jail]), - 'ip6': _actions.Actions.ActionInfo(tickets['ip6'], jails[jail]), - } # test ban ip4 : self.pruneLog('# === ban-ipv4 ===') - action.ban(ainfo['ip4']) + action.ban(aInfos['ipv4']) if tests.get('ip4-start'): self.assertLogged(*tests.get('*-start', ())+tests['ip4-start'], all=True) if tests.get('ip6-start'): self.assertNotLogged(*tests['ip6-start'], all=True) self.assertLogged(*tests.get('ip4-check',())+tests['ip4-ban'], all=True) self.assertNotLogged(*tests['ip6'], all=True) # test unban ip4 : self.pruneLog('# === unban ipv4 ===') - action.unban(ainfo['ip4']) + action.unban(aInfos['ipv4']) self.assertLogged(*tests.get('ip4-check',())+tests['ip4-unban'], all=True) self.assertNotLogged(*tests['ip6'], all=True) # test ban ip6 : self.pruneLog('# === ban ipv6 ===') - action.ban(ainfo['ip6']) + action.ban(aInfos['ipv6']) if tests.get('ip6-start'): self.assertLogged(*tests.get('*-start', ())+tests['ip6-start'], all=True) if tests.get('ip4-start'): self.assertNotLogged(*tests['ip4-start'], all=True) self.assertLogged(*tests.get('ip6-check',())+tests['ip6-ban'], all=True) self.assertNotLogged(*tests['ip4'], all=True) # test unban ip6 : self.pruneLog('# === unban ipv6 ===') - action.unban(ainfo['ip6']) + action.unban(aInfos['ipv6']) self.assertLogged(*tests.get('ip6-check',())+tests['ip6-unban'], all=True) self.assertNotLogged(*tests['ip4'], all=True) # test flush for actions should supported this: diff --git a/fail2ban/tests/sockettestcase.py b/fail2ban/tests/sockettestcase.py index 2d414e5c..e3a07998 100644 --- a/fail2ban/tests/sockettestcase.py +++ b/fail2ban/tests/sockettestcase.py @@ -54,6 +54,7 @@ class Socket(LogCaptureTestCase): def setUp(self): """Call before every test case.""" + LogCaptureTestCase.setUp(self) super(Socket, self).setUp() self.server = AsyncServer(self) sock_fd, sock_name = tempfile.mkstemp('fail2ban.sock', 'f2b-socket') diff --git a/fail2ban/tests/utils.py b/fail2ban/tests/utils.py index e2c4bccc..e674ee9b 100644 --- a/fail2ban/tests/utils.py +++ b/fail2ban/tests/utils.py @@ -388,6 +388,7 @@ def gatherTests(regexps=None, opts=None): from . import sockettestcase from . import misctestcase from . import databasetestcase + from . import observertestcase from . import samplestestcase from . import fail2banclienttestcase from . import fail2banregextestcase @@ -418,7 +419,6 @@ def gatherTests(regexps=None, opts=None): tests = FilteredTestSuite() # Server - #tests.addTest(unittest.makeSuite(servertestcase.StartStop)) tests.addTest(unittest.makeSuite(servertestcase.Transmitter)) tests.addTest(unittest.makeSuite(servertestcase.JailTests)) tests.addTest(unittest.makeSuite(servertestcase.RegexTests)) @@ -458,6 +458,10 @@ def gatherTests(regexps=None, opts=None): tests.addTest(unittest.makeSuite(misctestcase.MyTimeTest)) # Database tests.addTest(unittest.makeSuite(databasetestcase.DatabaseTest)) + # Observer + tests.addTest(unittest.makeSuite(observertestcase.ObserverTest)) + tests.addTest(unittest.makeSuite(observertestcase.BanTimeIncr)) + tests.addTest(unittest.makeSuite(observertestcase.BanTimeIncrDB)) # Filter tests.addTest(unittest.makeSuite(filtertestcase.IgnoreIP)) @@ -764,10 +768,11 @@ class LogCaptureTestCase(unittest.TestCase): # Let's log everything into a string self._log = LogCaptureTestCase._MemHandler(unittest.F2B.log_lazy) logSys.handlers = [self._log] - if self._old_level <= logging.DEBUG: + # lowest log level to capture messages (expected in tests) is Lev.9 + if self._old_level <= logging.DEBUG: # pragma: no cover logSys.handlers += self._old_handlers - else: # lowest log level to capture messages - logSys.setLevel(logging.DEBUG) + if self._old_level > logging.DEBUG-1: + logSys.setLevel(logging.DEBUG-1) super(LogCaptureTestCase, self).setUp() def tearDown(self): diff --git a/fail2ban/version.py b/fail2ban/version.py index 8f7cca64..ca799fcd 100644 --- a/fail2ban/version.py +++ b/fail2ban/version.py @@ -24,7 +24,7 @@ __author__ = "Cyril Jaquier, Yaroslav Halchenko, Steven Hiscocks, Daniel Black" __copyright__ = "Copyright (c) 2004 Cyril Jaquier, 2005-2016 Yaroslav Halchenko, 2013-2014 Steven Hiscocks, Daniel Black" __license__ = "GPL-v2+" -version = "0.10.6" +version = "0.11.2" def normVersion(): """ Returns fail2ban version in normalized machine-readable format""" |