diff options
27 files changed, 1614 insertions, 51 deletions
@@ -20,6 +20,9 @@ TODO: implementing of options resp. other tasks from PR #1346 * testSocket: sporadical bug repaired - wait for server thread starts a socket (listener) * testExecuteTimeoutWithNastyChildren: sporadical bug repaired - wait for pid file inside bash, kill tree in any case (gh-1155) +* purge database will be executed now (within observer). +* restoring currently banned ip after service restart fixed + (now < timeofban + bantime), ignore old log failures (already banned) ### New Features * IPv6 support: @@ -33,6 +36,9 @@ TODO: implementing of options resp. other tasks from PR #1346 - new conditional section functionality used in config resp. includes: - [Init?family=inet4] - IPv4 qualified hosts only - [Init?family=inet6] - IPv6 qualified hosts only +* Increment ban time (+ observer) functionality introduced. + Thanks Serg G. Brester (sebres) +* Database functionality extended with bad ips. ### Enhancements * huge increasing of fail2ban performance and especially test-cases performance (see gh-1109) @@ -195,6 +195,7 @@ fail2ban/server/jail.py fail2ban/server/jails.py fail2ban/server/jailthread.py fail2ban/server/mytime.py +fail2ban/server/observer.py fail2ban/server/server.py fail2ban/server/strptime.py fail2ban/server/ticket.py @@ -247,6 +248,7 @@ fail2ban/tests/files/config/apache-auth/digest_wrongrelm/.htpasswd fail2ban/tests/files/config/apache-auth/noentry/.htaccess fail2ban/tests/files/config/apache-auth/README fail2ban/tests/files/database_v1.db +fail2ban/tests/files/database_v2.db fail2ban/tests/files/filter.d/substition.conf fail2ban/tests/files/filter.d/testcase01.conf fail2ban/tests/files/filter.d/testcase-common.conf @@ -343,6 +345,7 @@ fail2ban/tests/files/testcase-wrong-char.log fail2ban/tests/filtertestcase.py fail2ban/tests/__init__.py fail2ban/tests/misctestcase.py +fail2ban/tests/observertestcase.py fail2ban/tests/samplestestcase.py fail2ban/tests/servertestcase.py fail2ban/tests/sockettestcase.py @@ -109,7 +109,7 @@ Russell Odom SATO Kentaro Sean DuBois Sebastian Arcus -Serg G. Brester +Serg G. Brester (sebres) Sireyessire silviogarbes Stefan Tatschner diff --git a/config/jail.conf b/config/jail.conf index b7c927e2..95b8e78b 100644 --- a/config/jail.conf +++ b/config/jail.conf @@ -44,6 +44,44 @@ before = paths-debian.conf # MISCELLANEOUS OPTIONS # +# "bantime.increment" allows to use database for searching of previously banned ip's to increase a +# default ban time using special formula, default it is banTime * 1, 2, 4, 8, 16, 32... +#bantime.increment = true + +# "bantime.rndtime" is the max number of seconds using for mixing with random time +# to prevent "clever" botnets calculate exact time IP can be unbanned again: +#bantime.rndtime = + +# "bantime.maxtime" is the max number of seconds using the ban time can reach (don't grows further) +#bantime.maxtime = + +# "bantime.factor" is a coefficient to calculate exponent growing of the formula or common multiplier, +# default value of factor is 1 and with default value of formula, the ban time +# grows by 1, 2, 4, 8, 16 ... +#bantime.factor = 1 + +# "bantime.formula" used by default to calculate next value of ban time, default value bellow, +# the same ban time growing will be reached by multipliers 1, 2, 4, 8, 16, 32... +#bantime.formula = ban.Time * (1<<(ban.Count if ban.Count<20 else 20)) * banFactor +# +# more aggressive example of formula has the same values only for factor "2.0 / 2.885385" : +#bantime.formula = ban.Time * math.exp(float(ban.Count+1)*banFactor)/math.exp(1*banFactor) + +# "bantime.multipliers" used to calculate next value of ban time instead of formula, coresponding +# previously ban count and given "bantime.factor" (for multipliers default is 1); +# following example grows ban time by 1, 2, 4, 8, 16 ... and if last ban count greater as multipliers count, +# always used last multiplier (64 in example), for factor '1' and original ban time 600 - 10.6 hours +#bantime.multipliers = 1 2 4 8 16 32 64 +# following example can be used for small initial ban time (bantime=60) - it grows more aggressive at begin, +# for bantime=60 the multipliers are minutes and equal: 1 min, 5 min, 30 min, 1 hour, 5 hour, 12 hour, 1 day, 2 day +#bantime.multipliers = 1 5 30 60 300 720 1440 2880 + +# "bantime.overalljails" (if true) specifies the search of IP in the database will be executed +# cross over all jails, if false (dafault), only current jail of the ban IP will be searched +#bantime.overalljails = false + +# -------------------- + # "ignoreip" can be an IP address, a CIDR mask or a DNS host. Fail2ban will not # ban a host which matches an address in this list. Several addresses can be # defined using space (and/or comma) separator. diff --git a/fail2ban/client/jailreader.py b/fail2ban/client/jailreader.py index 5f2e64b2..101cb167 100644 --- a/fail2ban/client/jailreader.py +++ b/fail2ban/client/jailreader.py @@ -106,6 +106,13 @@ class JailReader(ConfigReader): ["int", "maxretry", None], ["string", "findtime", None], ["string", "bantime", None], + ["bool", "bantime.increment", None], + ["string", "bantime.factor", None], + ["string", "bantime.formula", None], + ["string", "bantime.multipliers", None], + ["string", "bantime.maxtime", None], + ["string", "bantime.rndtime", None], + ["bool", "bantime.overalljails", None], ["string", "usedns", None], ["string", "failregex", None], ["string", "ignoreregex", None], @@ -225,6 +232,8 @@ class JailReader(ConfigReader): stream.append(["set", self.__name, "findtime", value]) elif opt == "bantime": stream.append(["set", self.__name, "bantime", value]) + elif opt.startswith("bantime."): + stream.append(["set", self.__name, opt, self.__opts[opt]]) elif opt == "usedns": stream.append(["set", self.__name, "usedns", value]) elif opt in ("failregex", "ignoreregex"): diff --git a/fail2ban/server/action.py b/fail2ban/server/action.py index f579c31e..dead08f6 100644 --- a/fail2ban/server/action.py +++ b/fail2ban/server/action.py @@ -569,8 +569,5 @@ class CommandAction(ActionBase): logSys.debug("Nothing to do") return True - _cmd_lock.acquire() - try: + with _cmd_lock: return Utils.executeCmd(realCmd, timeout, shell=True, output=False) - finally: - _cmd_lock.release() diff --git a/fail2ban/server/actions.py b/fail2ban/server/actions.py index 050c12e6..946cdbdd 100644 --- a/fail2ban/server/actions.py +++ b/fail2ban/server/actions.py @@ -39,6 +39,7 @@ except ImportError: OrderedDict = None from .banmanager import BanManager +from .observer import Observers from .jailthread import JailThread from .action import ActionBase, CommandAction, CallingMap from .mytime import MyTime @@ -299,11 +300,18 @@ class Actions(JailThread, Mapping): if ticket: aInfo = CallingMap() bTicket = BanManager.createBanTicket(ticket) + if ticket.getBanTime() is not None: + bTicket.setBanTime(ticket.getBanTime()) + bTicket.setBanCount(ticket.getBanCount()) + if ticket.getRestored(): + bTicket.setRestored(True) ip = bTicket.getIP() aInfo["ip"] = ip aInfo["failures"] = bTicket.getAttempt() aInfo["time"] = bTicket.getTime() aInfo["matches"] = "\n".join(bTicket.getMatches()) + btime = bTicket.getBanTime(self.__banManager.getBanTime()) + # retarded merge info via twice lambdas : once for merge, once for matches/failures: if self._jail.database is not None: mi4ip = lambda overalljails=False, self=self, \ mi={'ip':ip, 'ticket':bTicket}: self.__getBansMerged(mi, overalljails) @@ -311,8 +319,20 @@ class Actions(JailThread, Mapping): aInfo["ipjailmatches"] = lambda: "\n".join(mi4ip().getMatches()) aInfo["ipfailures"] = lambda: mi4ip(True).getAttempt() aInfo["ipjailfailures"] = lambda: mi4ip().getAttempt() + + if btime != -1: + bendtime = aInfo["time"] + btime + # check ban is not too old : + if bendtime < MyTime.time(): + logSys.info('[%s] Ignore %s, expired bantime', self._jail.name, ip) + return False + if self.__banManager.addBanTicket(bTicket): - logSys.notice("[%s] Ban %s" % (self._jail.name, aInfo["ip"])) + # 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.getRestored(): + Observers.Main.add('banFound', bTicket, self._jail, btime) + logSys.notice("[%s] %sBan %s", self._jail.name, ('' if not bTicket.getRestored() else 'Restore '), aInfo["ip"]) + # do actions : for name, action in self._actions.iteritems(): try: action.ban(aInfo.copy()) @@ -324,8 +344,7 @@ class Actions(JailThread, Mapping): exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) return True else: - logSys.notice("[%s] %s already banned" % (self._jail.name, - aInfo["ip"])) + logSys.notice("[%s] %s already banned" % (self._jail.name, aInfo["ip"])) return False def __checkUnBan(self): diff --git a/fail2ban/server/database.py b/fail2ban/server/database.py index 46d40051..c9ce74d3 100644 --- a/fail2ban/server/database.py +++ b/fail2ban/server/database.py @@ -127,7 +127,7 @@ class Fail2BanDb(object): filename purgeage """ - __version__ = 2 + __version__ = 4 # Note all _TABLE_* strings must end in ';' for py26 compatibility _TABLE_fail2banDb = "CREATE TABLE fail2banDb(version INTEGER);" _TABLE_jails = "CREATE TABLE jails(" \ @@ -154,6 +154,8 @@ 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) " \ ");" \ @@ -161,8 +163,21 @@ class Fail2BanDb(object): "CREATE INDEX bans_jail_ip ON bans(jail, ip);" \ "CREATE INDEX bans_ip ON bans(ip);" \ + _TABLE_bips = "CREATE TABLE 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 bips_timeofban ON bips(timeofban);" \ + "CREATE INDEX bips_ip ON bips(ip);" \ + - def __init__(self, filename, purgeAge=24*60*60): + def __init__(self, filename, purgeAge=24*60*60, outDatedFactor=3): self.maxEntries = 50 try: self._lock = RLock() @@ -171,6 +186,7 @@ class Fail2BanDb(object): detect_types=sqlite3.PARSE_DECLTYPES) self._dbFilename = filename self._purgeAge = purgeAge + self._outDatedFactor = outDatedFactor; self._bansMergedCache = {} @@ -253,6 +269,8 @@ class Fail2BanDb(object): cur.executescript(Fail2BanDb._TABLE_logs) # Bans cur.executescript(Fail2BanDb._TABLE_bans) + # BIPs (bad ips) + cur.executescript(Fail2BanDb._TABLE_bips) cur.execute("SELECT version FROM fail2banDb LIMIT 1") return cur.fetchone()[0] @@ -281,6 +299,20 @@ class Fail2BanDb(object): "UPDATE fail2banDb SET version = 2;" "COMMIT;" % Fail2BanDb._TABLE_logs) + if version < 3: + cur.executescript("BEGIN TRANSACTION;" + "CREATE TEMPORARY TABLE bans_temp AS SELECT jail, ip, timeofban, 600 as bantime, 1 as bancount, data FROM bans;" + "DROP TABLE bans;" + "%s;" + "INSERT INTO bans SELECT * from bans_temp;" + "DROP TABLE bans_temp;" + "COMMIT;" % Fail2BanDb._TABLE_bans) + if version < 4: + cur.executescript("BEGIN TRANSACTION;" + "%s;" + "UPDATE fail2banDb SET version = 4;" + "COMMIT;" % Fail2BanDb._TABLE_bips) + cur.execute("SELECT version FROM fail2banDb LIMIT 1") return cur.fetchone()[0] @@ -441,9 +473,13 @@ class Fail2BanDb(object): pass #TODO: Implement data parts once arbitrary match keys completed cur.execute( - "INSERT INTO bans(jail, ip, timeofban, data) VALUES(?, ?, ?, ?)", - (jail.name, ip, int(round(ticket.getTime())), + "INSERT INTO bans(jail, ip, timeofban, bantime, bancount, data) VALUES(?, ?, ?, ?, ?, ?)", + (jail.name, ip, int(round(ticket.getTime())), ticket.getBanTime(jail.actions.getBanTime()), ticket.getBanCount(), ticket.getData())) + 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(), + {"matches": ticket.getMatches(), "failures": ticket.getAttempt()})) @commitandrollback def delBan(self, cur, jail, ip): @@ -458,6 +494,9 @@ class Fail2BanDb(object): """ queryArgs = (jail.name, str(ip)); cur.execute( + "DELETE FROM bips WHERE jail = ? AND ip = ?", + queryArgs) + cur.execute( "DELETE FROM bans WHERE jail = ? AND ip = ?", queryArgs); @@ -577,6 +616,93 @@ class Fail2BanDb(object): 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" + cur = self._db.cursor() + return cur.execute(query, queryArgs) + + @commitandrollback + 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, bantime, bancount, data FROM bips WHERE jail=?" + queryArgs.append(jail.name) + else: + 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 is not None: + query += " AND timeofban > ?" + queryArgs.append(fromtime - forbantime) + if ip is None: + query += " GROUP BY ip ORDER BY ip, timeofban DESC" + cur = self._db.cursor() + return cur.execute(query, queryArgs) + + def getCurrentBans(self, jail = None, ip = None, forbantime=None, fromtime=None): + tickets = [] + ticket = None + + results = list(self._getCurrentBans(jail=jail, ip=ip, forbantime=forbantime, fromtime=fromtime)) + + if results: + matches = [] + failures = 0 + for banip, timeofban, bantime, bancount, data in results: + #TODO: Implement data parts once arbitrary match keys completed + ticket = FailTicket(banip, timeofban, matches) + ticket.setAttempt(failures) + ticket.setBanTime(bantime) + ticket.setBanCount(bancount) + matches = [] + failures = 0 + matches.extend(data['matches']) + failures += data['failures'] + ticket.setAttempt(failures) + tickets.append(ticket) + + return tickets if ip is None else ticket + + 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. """ @@ -584,7 +710,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 ee4b049d..1255cf21 100644 --- a/fail2ban/server/failmanager.py +++ b/fail2ban/server/failmanager.py @@ -75,7 +75,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() @@ -102,6 +102,9 @@ class FailManager: if len(matches) > self.maxEntries: fData.setMatches(matches[-self.maxEntries:]) except KeyError: + # not found - already banned - prevent to add failure if comes from observer: + if observed: + return # if already FailTicket - add it direct, otherwise create (using copy all ticket data): if isinstance(ticket, FailTicket): fData = ticket; diff --git a/fail2ban/server/filter.py b/fail2ban/server/filter.py index 318d8e49..53bf3bb7 100644 --- a/fail2ban/server/filter.py +++ b/fail2ban/server/filter.py @@ -32,6 +32,7 @@ import sys 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 @@ -434,6 +435,9 @@ class Filter(JailThread): ) tick = FailTicket(ip, unixTime, lines, data=fail) self.failManager.addFailure(tick) + # 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) ## # Returns true if the line should be ignored. diff --git a/fail2ban/server/jail.py b/fail2ban/server/jail.py index 6345d300..d6f872a2 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 +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) @@ -191,8 +196,8 @@ class Jail(object): Used by filter to add a failure for banning. """ self.__queue.put(ticket) - if self.database is not None: - self.database.addBan(self, 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. @@ -204,6 +209,75 @@ class Jail(object): except Queue.Empty: return False + 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': + if isinstance(value, str): + be[opt] = value.lower() in ("yes", "true", "ok", "1") + if be[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 restoreCurrentBans(self): + """Restore any previous valid bans from the database. + """ + try: + if self.database is not None: + forbantime = None; + # use ban time as search time if we have not enabled a increasing: + if not self.getBanTimeExtra('increment'): + forbantime = self.actions.getBanTime() + for ticket in self.database.getCurrentBans(jail=self, forbantime=forbantime): + #logSys.debug('restored ticket: %s', ticket) + if not self.filter.inIgnoreIPList(ticket.getIP(), log_ignore=True): + # mark ticked was restored from database - does not put it again into db: + ticket.setRestored(True) + self.putFailTicket(ticket) + except Exception as e: # pragma: no cover + logSys.error('%s', e, exc_info=logSys.getEffectiveLevel()<=logging.DEBUG) + def start(self): """Start the jail, by starting filter and actions threads. @@ -212,12 +286,8 @@ class Jail(object): """ self.filter.start() self.actions.start() - # Restore any previous valid bans from the database - if self.database is not None: - for ticket in self.database.getBansMerged( - jail=self, bantime=self.actions.getBanTime()): - if not self.filter.inIgnoreIPList(ticket.getIP(), log_ignore=True): - self.__queue.put(ticket) + self.restoreCurrentBans() + logSys.info("Jail '%s' started" % self.name) def stop(self): diff --git a/fail2ban/server/observer.py b/fail2ban/server/observer.py new file mode 100644 index 00000000..52db03e8 --- /dev/null +++ b/fail2ban/server/observer.py @@ -0,0 +1,490 @@ +# 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='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, name): + 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 + """ + t = threading.Timer(starttime, self.add, event) + t.start() + + def pulse_notify(self): + """Notify wakeup (sets /and resets/ notify event) + """ + if not self._paused and self._notify: + self._notify.set() + #self._notify.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 = { + 'failureFound': self.failureFound, + 'banFound': self.banFound, + # 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 = __meth[ev[0]] + ## 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)) + #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): + if self.active and self._notify: + wtime = 5 + 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) + self.wait_empty(wtime) + n.clear() + self.active = False + self.wait_idle(0.5) + + @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.info("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(): + 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): + 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, + datetime.datetime.fromtimestamp(unixTime).strftime("%Y-%m-%d %H:%M:%S"), 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) + + # after observe we have increased count >= 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 + 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)) \ + : + logSys.debug('IP %s was already banned: %s #, %s', ip, banCount, timeOfBan); + ticket.setBanCount(banCount); + # 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, + datetime.datetime.fromtimestamp(timeOfBan).strftime("%Y-%m-%d %H:%M:%S"), + datetime.timedelta(seconds=int(orgBanTime)), datetime.timedelta(seconds=int(banTime)))); + else: + ticket.setRestored(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 + """ + oldbtime = btime + ip = ticket.getIP() + logSys.debug("[%s] Observer: ban found %s, %s", jail.name, ip, btime) + try: + # if not permanent, not restored and ban time was not set - check time should be increased: + if btime != -1 and not ticket.getRestored() 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 = (datetime.timedelta(seconds=int(btime)), + datetime.datetime.fromtimestamp(bendtime).strftime("%Y-%m-%d %H:%M:%S")) + # check ban is not too old : + if bendtime < MyTime.time(): + logSys.debug('Ignore old bantime %s', logtime[1]) + return False + else: + logtime = ('permanent', 'infinite') + # increment count: + ticket.incrBanCount() + # 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) + # add ticket to database, but only if was not restored (not already read from database): + if jail.database is not None and not ticket.getRestored(): + # 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) + +# 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 60eea1f3..54f00f6a 100644 --- a/fail2ban/server/server.py +++ b/fail2ban/server/server.py @@ -33,6 +33,7 @@ import signal import stat import sys +from .observer import Observers, ObserverThread from .jails import Jails from .filter import FileFilter, JournalFilter from .transmitter import Transmitter @@ -92,7 +93,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(0077) # Second daemonize before logging etc, because it will close all handles: @@ -141,6 +142,12 @@ class Server: except IOError, e: 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: @@ -154,6 +161,10 @@ class Server: os.remove(pidfile) except OSError, e: logSys.error("Unable to remove PID file: %s" % e) + # Stop observer and exit + if Observers.Main is not None: + Observers.Main.stop() + Observers.Main = None logSys.info("Exiting Fail2ban") def quit(self): @@ -184,10 +195,11 @@ class Server: self.quit = lambda: False def addJail(self, name, backend): + # Add jail hereafter: self.__jails.add(name, backend, self.__db) if self.__db is not None: self.__db.addJail(self.__jails[name]) - + def delJail(self, name): if self.__db is not None: self.__db.delJail(self.__jails[name]) @@ -375,6 +387,12 @@ class Server: def getBanTime(self, name): return self.__jails[name].actions.getBanTime() + + 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() @@ -496,7 +514,7 @@ class Server: try: handler.flush() handler.close() - except (ValueError, KeyError): # pragma: no cover + except (ValueError, KeyError): # pragma: no cover # Is known to be thrown after logging was shutdown once # with older Pythons -- seems to be safe to ignore there # At least it was still failing on 2.6.2-0ubuntu1 (jaunty) @@ -577,6 +595,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 65ed83c3..ae767cdd 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 @@ -36,6 +34,8 @@ logSys = getLogger(__name__) class Ticket: + RESTORED = 0x01 + def __init__(self, ip=None, time=None, matches=None, data={}, ticket=None): """Ticket constructor @@ -58,8 +58,9 @@ class Ticket: self._data['matches'] = matches or [] def __str__(self): - return "%s: ip=%s time=%s #attempts=%d matches=%r" % \ + 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): @@ -94,7 +95,7 @@ class Ticket: def setBanTime(self, value): self._banTime = value; - def getBanTime(self, defaultBT = None): + def getBanTime(self, defaultBT=None): return (self._banTime if not self._banTime is None else defaultBT); def setBanCount(self, value): @@ -106,7 +107,7 @@ class Ticket: def getBanCount(self): return self._banCount; - def isTimedOut(self, time, defaultBT = None): + def isTimedOut(self, time, defaultBT=None): bantime = (self._banTime if not self._banTime is None else defaultBT); # permanent if bantime == -1: @@ -126,6 +127,15 @@ class Ticket: def getMatches(self): return self._data.get('matches', []) + def setRestored(self, value): + if value: + self._flags = Ticket.RESTORED + else: + self._flags &= ~(Ticket.RESTORED) + + def getRestored(self): + return self._flags & Ticket.RESTORED + def setData(self, *args, **argv): # if overwrite - set data and filter None values: if len(args) == 1: diff --git a/fail2ban/server/transmitter.py b/fail2ban/server/transmitter.py index e4b9d81a..bdc6b42c 100644 --- a/fail2ban/server/transmitter.py +++ b/fail2ban/server/transmitter.py @@ -243,6 +243,11 @@ class Transmitter: value = command[2] self.__server.setBanTime(name, value) return self.__server.getBanTime(name) + elif command[1].startswith("bantime."): + value = command[2] + opt = command[1][len("bantime."):] + self.__server.setBanTimeExtra(name, opt, value) + return self.__server.getBanTimeExtra(name, opt) elif command[1] == "banip": value = command[2] return self.__server.setBanIP(name,value) @@ -335,6 +340,9 @@ class Transmitter: # Action elif command[1] == "bantime": return self.__server.getBanTime(name) + 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/tests/action_d/test_smtp.py b/fail2ban/tests/action_d/test_smtp.py index 5c8b1923..86e7a368 100644 --- a/fail2ban/tests/action_d/test_smtp.py +++ b/fail2ban/tests/action_d/test_smtp.py @@ -29,16 +29,20 @@ else: from ..dummyjail import DummyJail -from ..utils import CONFIG_DIR, asyncserver - +from ..utils import CONFIG_DIR, asyncserver, Utils class TestSMTPServer(smtpd.SMTPServer): + def __init__(self, *args): + smtpd.SMTPServer.__init__(self, *args) + self.ready = False + def process_message(self, peer, mailfrom, rcpttos, data): self.peer = peer self.mailfrom = mailfrom self.rcpttos = rcpttos self.data = data + self.ready = True class SMTPActionTest(unittest.TestCase): @@ -74,8 +78,13 @@ class SMTPActionTest(unittest.TestCase): self._active = False self._loop_thread.join() + def _exec_and_wait(self, doaction): + self.smtpd.ready = False + doaction() + Utils.wait_for(lambda: self.smtpd.ready, 3) + def testStart(self): - self.action.start() + self._exec_and_wait(self.action.start) self.assertEqual(self.smtpd.mailfrom, "fail2ban") self.assertEqual(self.smtpd.rcpttos, ["root"]) self.assertTrue( @@ -83,7 +92,7 @@ class SMTPActionTest(unittest.TestCase): in self.smtpd.data) def testStop(self): - self.action.stop() + self._exec_and_wait(self.action.stop) self.assertEqual(self.smtpd.mailfrom, "fail2ban") self.assertEqual(self.smtpd.rcpttos, ["root"]) self.assertTrue( @@ -99,7 +108,7 @@ class SMTPActionTest(unittest.TestCase): 'ipmatches': "Test fail 1\nTest Fail2\nTest Fail3\n", } - self.action.ban(aInfo) + self._exec_and_wait(lambda: self.action.ban(aInfo)) self.assertEqual(self.smtpd.mailfrom, "fail2ban") self.assertEqual(self.smtpd.rcpttos, ["root"]) subject = "Subject: [Fail2Ban] %s: banned %s" % ( @@ -109,26 +118,26 @@ class SMTPActionTest(unittest.TestCase): "%i attempts" % aInfo['failures'] in self.smtpd.data) self.action.matches = "matches" - self.action.ban(aInfo) + self._exec_and_wait(lambda: self.action.ban(aInfo)) self.assertIn(aInfo['matches'], self.smtpd.data) self.action.matches = "ipjailmatches" - self.action.ban(aInfo) + self._exec_and_wait(lambda: self.action.ban(aInfo)) self.assertIn(aInfo['ipjailmatches'], self.smtpd.data) self.action.matches = "ipmatches" - self.action.ban(aInfo) + self._exec_and_wait(lambda: self.action.ban(aInfo)) self.assertIn(aInfo['ipmatches'], self.smtpd.data) def testOptions(self): - self.action.start() + self._exec_and_wait(self.action.start) self.assertEqual(self.smtpd.mailfrom, "fail2ban") self.assertEqual(self.smtpd.rcpttos, ["root"]) self.action.fromname = "Test" self.action.fromaddr = "test@example.com" self.action.toaddr = "test@example.com, test2@example.com" - self.action.start() + self._exec_and_wait(self.action.start) self.assertEqual(self.smtpd.mailfrom, "test@example.com") self.assertTrue("From: %s <%s>" % (self.action.fromname, self.action.fromaddr) in self.smtpd.data) diff --git a/fail2ban/tests/actionstestcase.py b/fail2ban/tests/actionstestcase.py index 8969db36..279290d1 100644 --- a/fail2ban/tests/actionstestcase.py +++ b/fail2ban/tests/actionstestcase.py @@ -149,7 +149,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/banmanagertestcase.py b/fail2ban/tests/banmanagertestcase.py index f47dc848..859bf22f 100644 --- a/fail2ban/tests/banmanagertestcase.py +++ b/fail2ban/tests/banmanagertestcase.py @@ -84,6 +84,24 @@ 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: + for i in (1000, 2000, -1): + self.__banManager.addBanTicket(self.__ticket) + ticket.setBanTime(i) + self.assertFalse(self.__banManager.addBanTicket(ticket)) + self.assertEqual(str(self.__banManager.getTicketByIP(ticket.getIP())), + "BanTicket: ip=%s time=%s bantime=%s bancount=0 #attempts=0 matches=[]" % (ticket.getIP(), ticket.getTime(), i)) + ## after permanent, it should remain permanent ban time (-1): + self.__banManager.addBanTicket(self.__ticket) + ticket.setBanTime(-1) + self.assertFalse(self.__banManager.addBanTicket(ticket)) + ticket.setBanTime(1000) + self.assertFalse(self.__banManager.addBanTicket(ticket)) + self.assertEqual(str(self.__banManager.getTicketByIP(ticket.getIP())), + "BanTicket: ip=%s time=%s bantime=%s bancount=0 #attempts=0 matches=[]" % (ticket.getIP(), ticket.getTime(), -1)) def testUnban(self): btime = self.__banManager.getBanTime() diff --git a/fail2ban/tests/config/filter.d/common.conf b/fail2ban/tests/config/filter.d/common.conf index 83e92474..586f428a 120000..100644 --- a/fail2ban/tests/config/filter.d/common.conf +++ b/fail2ban/tests/config/filter.d/common.conf @@ -1 +1,64 @@ -../../../../config/filter.d/common.conf
\ No newline at end of file +# Generic configuration items (to be used as interpolations) in other +# filters or actions configurations +# + +[INCLUDES] + +# Load customizations if any available +after = common.local + + +[DEFAULT] + +# Daemon definition is to be specialized (if needed) in .conf file +_daemon = \S* + +# +# Shortcuts for easier comprehension of the failregex +# +# PID. +# EXAMPLES: [123] +__pid_re = (?:\[\d+\]) + +# Daemon name (with optional source_file:line or whatever) +# EXAMPLES: pam_rhosts_auth, [sshd], pop(pam_unix) +__daemon_re = [\[\(]?%(_daemon)s(?:\(\S+\))?[\]\)]?:? + +# extra daemon info +# EXAMPLE: [ID 800047 auth.info] +__daemon_extra_re = \[ID \d+ \S+\] + +# Combinations of daemon name and PID +# EXAMPLES: sshd[31607], pop(pam_unix)[4920] +__daemon_combs_re = (?:%(__pid_re)s?:\s+%(__daemon_re)s|%(__daemon_re)s%(__pid_re)s?:?) + +# Some messages have a kernel prefix with a timestamp +# EXAMPLES: kernel: [769570.846956] +__kernel_prefix = kernel: \[ *\d+\.\d+\] + +__hostname = \S+ + +# A MD5 hex +# EXAMPLES: 07:06:27:55:b0:e3:0c:3c:5a:28:2d:7c:7e:4c:77:5f +__md5hex = (?:[\da-f]{2}:){15}[\da-f]{2} + +# bsdverbose is where syslogd is started with -v or -vv and results in <4.3> or +# <auth.info> appearing before the host as per testcases/files/logs/bsd/*. +__bsd_syslog_verbose = <[^.]+\.[^.]+> + +__vserver = @vserver_\S+ + +__date_ambit = (?:\[\]) + +# Common line prefixes (beginnings) which could be used in filters +# +# [bsdverbose]? [hostname] [vserver tag] daemon_id spaces +# +# This can be optional (for instance if we match named native log files) +__prefix_line = %(__date_ambit)s?\s*(?:%(__bsd_syslog_verbose)s\s+)?(?:%(__hostname)s\s+)?(?:%(__kernel_prefix)s\s+)?(?:%(__vserver)s\s+)?(?:%(__daemon_combs_re)s\s+)?(?:%(__daemon_extra_re)s\s+)? + +# PAM authentication mechanism check for failures, e.g.: pam_unix, pam_sss, +# pam_ldap +__pam_auth = pam_unix + +# Author: Yaroslav Halchenko diff --git a/fail2ban/tests/databasetestcase.py b/fail2ban/tests/databasetestcase.py index d039c920..08f718fa 100644 --- a/fail2ban/tests/databasetestcase.py +++ b/fail2ban/tests/databasetestcase.py @@ -126,6 +126,33 @@ class DatabaseTest(LogCaptureTestCase): self.assertRaises(NotImplementedError, self.db.updateDb, Fail2BanDb.__version__ + 1) os.remove(self.db._dbBackupFilename) + def testUpdateDb2(self): + if Fail2BanDb is None or self.db.filename == ':memory:': # pragma: no cover + return + 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__) + # further update should fail: + self.assertRaises(NotImplementedError, self.db.updateDb, Fail2BanDb.__version__ + 1) + # clean: + os.remove(self.db._dbBackupFilename) + def testAddJail(self): if Fail2BanDb is None: # pragma: no cover return @@ -365,8 +392,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 19f97f4e..c7c139e3 100644 --- a/fail2ban/tests/dummyjail.py +++ b/fail2ban/tests/dummyjail.py @@ -28,6 +28,11 @@ 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 """ @@ -36,7 +41,7 @@ class DummyJail(Jail): self.queue = [] super(DummyJail, self).__init__(name='DummyJail', backend=backend) self.__db = None - self.__actions = Actions(self) + self.__actions = DummyActions(self) def __len__(self): with self.lock: diff --git a/fail2ban/tests/failmanagertestcase.py b/fail2ban/tests/failmanagertestcase.py index 6e7bf367..11caf927 100644 --- a/fail2ban/tests/failmanagertestcase.py +++ b/fail2ban/tests/failmanagertestcase.py @@ -149,10 +149,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) @@ -160,7 +160,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/observertestcase.py b/fail2ban/tests/observertestcase.py new file mode 100644 index 00000000..3e4bfd10 --- /dev/null +++ b/fail2ban/tests/observertestcase.py @@ -0,0 +1,624 @@ +# 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 +from ..server.failmanager import FailManager +from ..server.banmanager import BanManager +from ..server.observer import Observers, ObserverThread +from ..server.utils import Utils +from .utils import LogCaptureTestCase +from ..server.filter import Filter +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(unittest.TestCase): +#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 = "127.0.0.2" + # 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) + 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)], + [(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), + [] + ) + # search currently banned one ticket for ip: + restored_tickets = self.db.getCurrentBans(ip=ip) + 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) + 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) + self.assertEqual( + str(restored_tickets), + ('[FailTicket: ip=%s time=%s bantime=20 bancount=2 #attempts=0 matches=[]]' % (ip, stime + 15)) + ) + restored_tickets[0].setRestored(True) + self.assertTrue(restored_tickets[0].getRestored()) + # 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) + ticket.incrBanCount() + 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) + ticket.incrBanCount() + 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) + 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) + 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) + 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) + 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) + 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) + 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) + self.assertEqual(restored_tickets, []) + + # two separate jails : + jail1 = DummyJail(backend='polling') + jail1.database = self.db + self.db.addJail(jail1) + jail2 = DummyJail(backend='polling') + 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) + 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) + 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() + self.assertEqual(str(jail1.getFailTicket()), + '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() + 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') + # 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 = "127.0.0.2" + 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) + 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: + to = int(MyTime.time())+30 + while True: + ticket2 = jail.getFailTicket() + if ticket2: + break + time.sleep(Utils.DEFAULT_SLEEP_INTERVAL) + if MyTime.time() > to: # pragma: no cover + raise RuntimeError('unexpected timeout: wait 30 seconds instead of few ms.') + # check ticket and failure count: + self.assertFalse(not ticket2) + self.assertEqual(ticket2.getRetry(), failManager.getMaxRetry()) + + # wrap FailTicket to BanTicket: + failticket2 = ticket2 + ticket2 = BanManager.createBanTicket(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) + 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) + 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) + 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 6c0f46cf..9b5ede76 100644 --- a/fail2ban/tests/servertestcase.py +++ b/fail2ban/tests/servertestcase.py @@ -905,6 +905,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): @@ -992,9 +1001,10 @@ class LoggingTests(LogCaptureTestCase): badThread = _BadThread() badThread.start() badThread.join() - self.assertLogged("Unhandled exception") + 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) diff --git a/fail2ban/tests/utils.py b/fail2ban/tests/utils.py index 764536bf..269cdbcd 100644 --- a/fail2ban/tests/utils.py +++ b/fail2ban/tests/utils.py @@ -265,6 +265,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 @@ -290,7 +291,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)) @@ -331,6 +331,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)) |